2025-11-24 08:38:53.232766 | Job console starting...
2025-11-24 08:38:53.434873 | Updating repositories
2025-11-24 08:38:54.174738 | Preparing job workspace
2025-11-24 08:39:03.299581 | Running Ansible setup...
2025-11-24 08:39:06.285280 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-11-24 08:39:06.839291 | 
2025-11-24 08:39:06.839410 | PLAY [localhost]
2025-11-24 08:39:06.848873 | 
2025-11-24 08:39:06.848963 | TASK [Gathering Facts]
2025-11-24 08:39:07.727308 | localhost | ok
2025-11-24 08:39:07.743711 | 
2025-11-24 08:39:07.743838 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-11-24 08:39:08.092745 | localhost -> localhost | changed
2025-11-24 08:39:08.100195 | 
2025-11-24 08:39:08.100341 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-11-24 08:39:08.876276 | localhost -> localhost | changed
2025-11-24 08:39:08.884615 | 
2025-11-24 08:39:08.884708 | TASK [Setup log path fact]
2025-11-24 08:39:08.901667 | localhost | ok
2025-11-24 08:39:08.913286 | 
2025-11-24 08:39:08.913375 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-24 08:39:08.941270 | localhost | ok
2025-11-24 08:39:08.948776 | 
2025-11-24 08:39:08.948858 | TASK [emit-job-header : Print job information]
2025-11-24 08:39:08.977920 | # Job Information
2025-11-24 08:39:08.978136 | Ansible Version: 2.15.12
2025-11-24 08:39:08.978175 | Job: cifmw-molecule-run_hook
2025-11-24 08:39:08.978199 | Pipeline: github-check
2025-11-24 08:39:08.978219 | Executor: ibm-bm4-ze.softwarefactory-project.io
2025-11-24 08:39:08.978267 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3451
2025-11-24 08:39:08.978288 | Log URL (when completed): https://logserver.rdoproject.org/a3c/rdoproject.org/a3ca31d396aa48b48ef0e4b1b9a7c8ad/
2025-11-24 08:39:08.978309 | Event ID: 2dae9040-c910-11f0-818a-433f9d14d6bc
2025-11-24 08:39:08.982506 | 
2025-11-24 08:39:08.982581 | LOOP [emit-job-header : Print node information]
2025-11-24 08:39:09.072371 | localhost | ok:
2025-11-24 08:39:09.072521 | localhost | # Node Information
2025-11-24 08:39:09.072551 | localhost | Inventory Hostname: controller
2025-11-24 08:39:09.072576 | localhost | Hostname: np0005533222
2025-11-24 08:39:09.072597 | localhost | Username: zuul
2025-11-24 08:39:09.072617 | localhost | Distro: CentOS 9
2025-11-24 08:39:09.072635 | localhost | Provider: ibm-bm4-nodepool
2025-11-24 08:39:09.072653 | localhost | Region: regionOne
2025-11-24 08:39:09.072671 | localhost | Label: cloud-centos-9-stream-tripleo-ibm
2025-11-24 08:39:09.072692 | localhost | Product Name: OpenStack Compute
2025-11-24 08:39:09.072710 | localhost | Interface IP: 192.168.26.82
2025-11-24 08:39:09.097887 | 
2025-11-24 08:39:09.098006 | PLAY [all]
2025-11-24 08:39:09.105101 | 
2025-11-24 08:39:09.105185 | TASK [Gather network facts]
2025-11-24 08:39:09.469422 | controller | ok
2025-11-24 08:39:09.483567 | 
2025-11-24 08:39:09.483633 | TASK [include_role : start-zuul-console]
2025-11-24 08:39:09.501750 | controller | ok
2025-11-24 08:39:09.513176 | 
2025-11-24 08:39:09.513261 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-11-24 08:39:09.804266 | controller | ok
2025-11-24 08:39:09.813108 | 
2025-11-24 08:39:09.813170 | TASK [include_role : add-build-sshkey]
2025-11-24 08:39:09.830789 | controller | ok
2025-11-24 08:39:09.843703 | 
2025-11-24 08:39:09.843768 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-24 08:39:10.049515 | controller -> localhost | ok
2025-11-24 08:39:10.055067 | 
2025-11-24 08:39:10.055200 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-24 08:39:10.074465 | controller | ok
2025-11-24 08:39:10.086895 | controller | included: /var/lib/zuul/builds/a3ca31d396aa48b48ef0e4b1b9a7c8ad/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-24 08:39:10.092501 | 
2025-11-24 08:39:10.092563 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-24 08:39:10.572638 | controller -> localhost | Generating public/private rsa key pair.
2025-11-24 08:39:10.572809 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/a3ca31d396aa48b48ef0e4b1b9a7c8ad/work/a3ca31d396aa48b48ef0e4b1b9a7c8ad_id_rsa.
2025-11-24 08:39:10.572842 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/a3ca31d396aa48b48ef0e4b1b9a7c8ad/work/a3ca31d396aa48b48ef0e4b1b9a7c8ad_id_rsa.pub.
2025-11-24 08:39:10.572867 | controller -> localhost | The key fingerprint is:
2025-11-24 08:39:10.572888 | controller -> localhost | SHA256:upImaIIyxMf1Ex3EloGIKzgfontof0onoZEfxTiNyPE zuul-build-sshkey
2025-11-24 08:39:10.572932 | controller -> localhost | The key's randomart image is:
2025-11-24 08:39:10.572962 | controller -> localhost | +---[RSA 3072]----+
2025-11-24 08:39:10.572984 | controller -> localhost | | .  . . +oo      |
2025-11-24 08:39:10.573003 | controller -> localhost | |. +.=. . =       |
2025-11-24 08:39:10.573021 | controller -> localhost | |.o E.+  o .      |
2025-11-24 08:39:10.573041 | controller -> localhost | |+.o.o. . .       |
2025-11-24 08:39:10.573059 | controller -> localhost | |o*o+. . S        |
2025-11-24 08:39:10.573076 | controller -> localhost | |.o=oo  +         |
2025-11-24 08:39:10.573092 | controller -> localhost | |o=.+ o. .        |
2025-11-24 08:39:10.573111 | controller -> localhost | |Oo+ *. .         |
2025-11-24 08:39:10.573128 | controller -> localhost | |=o.=o..          |
2025-11-24 08:39:10.573144 | controller -> localhost | +----[SHA256]-----+
2025-11-24 08:39:10.573184 | controller -> localhost | ok: Runtime: 0:00:00.114298
2025-11-24 08:39:10.578543 | 
2025-11-24 08:39:10.578607 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-24 08:39:10.596643 | controller | ok
2025-11-24 08:39:10.606300 | controller | included: /var/lib/zuul/builds/a3ca31d396aa48b48ef0e4b1b9a7c8ad/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-24 08:39:10.614530 | 
2025-11-24 08:39:10.614596 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-24 08:39:10.628059 | controller | skipping: Conditional result was False
2025-11-24 08:39:10.634084 | 
2025-11-24 08:39:10.634149 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-24 08:39:11.000875 | controller | changed
2025-11-24 08:39:11.006287 | 
2025-11-24 08:39:11.006356 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-24 08:39:11.187156 | controller | ok
2025-11-24 08:39:11.192032 | 
2025-11-24 08:39:11.192103 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-24 08:39:11.717780 | controller | changed
2025-11-24 08:39:11.722558 | 
2025-11-24 08:39:11.722627 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-24 08:39:12.261414 | controller | changed
2025-11-24 08:39:12.272393 | 
2025-11-24 08:39:12.272473 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-24 08:39:12.288083 | controller | skipping: Conditional result was False
2025-11-24 08:39:12.294747 | 
2025-11-24 08:39:12.294824 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-24 08:39:12.625837 | controller -> localhost | changed
2025-11-24 08:39:12.636715 | 
2025-11-24 08:39:12.636797 | TASK [add-build-sshkey : Add back temp key]
2025-11-24 08:39:12.887206 | controller -> localhost | Identity added: /var/lib/zuul/builds/a3ca31d396aa48b48ef0e4b1b9a7c8ad/work/a3ca31d396aa48b48ef0e4b1b9a7c8ad_id_rsa (zuul-build-sshkey)
2025-11-24 08:39:12.887405 | controller -> localhost | ok: Runtime: 0:00:00.007282
2025-11-24 08:39:12.893417 | 
2025-11-24 08:39:12.893481 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-24 08:39:13.175521 | controller | ok
2025-11-24 08:39:13.181021 | 
2025-11-24 08:39:13.181097 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-24 08:39:13.205689 | controller | skipping: Conditional result was False
2025-11-24 08:39:13.215093 | 
2025-11-24 08:39:13.215160 | TASK [include_role : validate-host]
2025-11-24 08:39:13.233427 | controller | ok
2025-11-24 08:39:13.255891 | 
2025-11-24 08:39:13.256008 | TASK [validate-host : Define zuul_info_dir fact]
2025-11-24 08:39:13.283790 | controller | ok
2025-11-24 08:39:13.288625 | 
2025-11-24 08:39:13.288689 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-11-24 08:39:13.485964 | controller -> localhost | ok
2025-11-24 08:39:13.491937 | 
2025-11-24 08:39:13.492024 | TASK [validate-host : Collect information about the host]
2025-11-24 08:39:14.078904 | controller | ok
2025-11-24 08:39:14.087332 | 
2025-11-24 08:39:14.087404 | TASK [validate-host : Sanitize hostname]
2025-11-24 08:39:14.157802 | controller | ok
2025-11-24 08:39:14.162927 | 
2025-11-24 08:39:14.162996 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-11-24 08:39:14.573363 | controller -> localhost | changed
2025-11-24 08:39:14.578813 | 
2025-11-24 08:39:14.578896 | TASK [validate-host : Collect information about zuul worker]
2025-11-24 08:39:14.890648 | controller | ok
2025-11-24 08:39:14.895330 | 
2025-11-24 08:39:14.895401 | TASK [validate-host : Write out all zuul information for each host]
2025-11-24 08:39:15.314470 | controller -> localhost | changed
2025-11-24 08:39:15.323924 | 
2025-11-24 08:39:15.324012 | TASK [include_role : prepare-workspace-openshift]
2025-11-24 08:39:15.337897 | controller | skipping: Conditional result was False
2025-11-24 08:39:15.344117 | 
2025-11-24 08:39:15.344208 | TASK [include_role : remove-zuul-sshkey]
2025-11-24 08:39:15.359122 | controller | skipping: Conditional result was False
2025-11-24 08:39:15.364681 | 
2025-11-24 08:39:15.364766 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-11-24 08:39:15.550685 | controller | ok: "logs"
2025-11-24 08:39:15.550903 | controller | ok: All items complete
2025-11-24 08:39:15.550954 | 
2025-11-24 08:39:15.714112 | controller | ok: "artifacts"
2025-11-24 08:39:15.876479 | controller | ok: "docs"
2025-11-24 08:39:15.892904 | 
2025-11-24 08:39:15.893023 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-11-24 08:39:16.084212 | controller | changed: "logs"
2025-11-24 08:39:16.250310 | controller | changed: "artifacts"
2025-11-24 08:39:16.415962 | controller | changed: "docs"
2025-11-24 08:39:16.446632 | 
2025-11-24 08:39:16.446710 | PLAY RECAP
2025-11-24 08:39:16.446755 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-11-24 08:39:16.446785 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-11-24 08:39:16.446806 | 
2025-11-24 08:39:16.532021 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-11-24 08:39:16.532801 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-11-24 08:39:17.125385 | 
2025-11-24 08:39:17.125636 | PLAY [all]
2025-11-24 08:39:17.146319 | 
2025-11-24 08:39:17.146563 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-11-24 08:39:17.205429 | controller | ok
2025-11-24 08:39:17.211071 | 
2025-11-24 08:39:17.211168 | TASK [mirror-info-fork : Create /etc/ci]
2025-11-24 08:39:17.575668 | controller | changed
2025-11-24 08:39:17.581458 | 
2025-11-24 08:39:17.581605 | TASK [mirror-info-fork : Install ci_mirror script]
2025-11-24 08:39:18.361182 | controller | changed
2025-11-24 08:39:18.373055 | 
2025-11-24 08:39:18.373185 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2025-11-24 08:39:18.736809 | controller | changed:
2025-11-24 08:39:18.737166 | controller | {
2025-11-24 08:39:18.737202 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2025-11-24 08:39:18.737311 | controller | }
2025-11-24 08:39:18.930974 | controller | changed:
2025-11-24 08:39:18.931060 | controller | {
2025-11-24 08:39:18.931090 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2025-11-24 08:39:18.931112 | controller | }
2025-11-24 08:39:19.128463 | controller | changed:
2025-11-24 08:39:19.128569 | controller | {
2025-11-24 08:39:19.128599 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com"
2025-11-24 08:39:19.128620 | controller | }
2025-11-24 08:39:19.323116 | controller | changed:
2025-11-24 08:39:19.323209 | controller | {
2025-11-24 08:39:19.323252 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2025-11-24 08:39:19.323275 | controller | }
2025-11-24 08:39:19.521040 | controller | changed:
2025-11-24 08:39:19.521129 | controller | {
2025-11-24 08:39:19.521154 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2025-11-24 08:39:19.521174 | controller | }
2025-11-24 08:39:19.715824 | controller | changed:
2025-11-24 08:39:19.716122 | controller | {
2025-11-24 08:39:19.716165 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2025-11-24 08:39:19.716189 | controller | }
2025-11-24 08:39:19.943489 | controller | changed:
2025-11-24 08:39:19.943590 | controller | {
2025-11-24 08:39:19.943617 | 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-11-24 08:39:19.943642 | controller | }
2025-11-24 08:39:20.140484 | controller | changed:
2025-11-24 08:39:20.140583 | controller | {
2025-11-24 08:39:20.140611 | 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-11-24 08:39:20.140634 | controller | }
2025-11-24 08:39:20.343153 | controller | changed:
2025-11-24 08:39:20.343267 | controller | {
2025-11-24 08:39:20.343297 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2025-11-24 08:39:20.343319 | controller | }
2025-11-24 08:39:20.543893 | controller | changed:
2025-11-24 08:39:20.544004 | controller | {
2025-11-24 08:39:20.544032 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2025-11-24 08:39:20.544054 | controller | }
2025-11-24 08:39:20.750777 | controller | changed:
2025-11-24 08:39:20.750870 | controller | {
2025-11-24 08:39:20.750898 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2025-11-24 08:39:20.750943 | controller | }
2025-11-24 08:39:20.991777 | controller | changed:
2025-11-24 08:39:20.991860 | controller | {
2025-11-24 08:39:20.991887 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2025-11-24 08:39:20.991933 | controller | }
2025-11-24 08:39:21.188580 | controller | changed:
2025-11-24 08:39:21.188697 | controller | {
2025-11-24 08:39:21.188733 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2025-11-24 08:39:21.188757 | controller | }
2025-11-24 08:39:21.393821 | controller | changed:
2025-11-24 08:39:21.393958 | controller | {
2025-11-24 08:39:21.394023 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2025-11-24 08:39:21.394048 | controller | }
2025-11-24 08:39:21.602847 | controller | changed:
2025-11-24 08:39:21.603051 | controller | {
2025-11-24 08:39:21.603088 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2025-11-24 08:39:21.603130 | controller | }
2025-11-24 08:39:21.813686 | controller | changed:
2025-11-24 08:39:21.813811 | controller | {
2025-11-24 08:39:21.813837 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2025-11-24 08:39:21.813857 | controller | }
2025-11-24 08:39:22.027345 | controller | changed:
2025-11-24 08:39:22.027432 | controller | {
2025-11-24 08:39:22.027459 | 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-11-24 08:39:22.027482 | controller | }
2025-11-24 08:39:22.242829 | controller | changed:
2025-11-24 08:39:22.242930 | controller | {
2025-11-24 08:39:22.242963 | 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-11-24 08:39:22.242993 | controller | }
2025-11-24 08:39:22.447712 | controller | changed:
2025-11-24 08:39:22.447797 | controller | {
2025-11-24 08:39:22.447824 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2025-11-24 08:39:22.447846 | controller | }
2025-11-24 08:39:22.656119 | controller | changed:
2025-11-24 08:39:22.656194 | controller | {
2025-11-24 08:39:22.656250 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2025-11-24 08:39:22.656275 | controller | }
2025-11-24 08:39:22.855043 | controller | changed:
2025-11-24 08:39:22.855114 | controller | {
2025-11-24 08:39:22.855597 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2025-11-24 08:39:22.855627 | controller | }
2025-11-24 08:39:23.059314 | controller | changed:
2025-11-24 08:39:23.059394 | controller | {
2025-11-24 08:39:23.059420 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2025-11-24 08:39:23.059441 | controller | }
2025-11-24 08:39:23.264710 | controller | changed:
2025-11-24 08:39:23.264797 | controller | {
2025-11-24 08:39:23.264828 | 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-11-24 08:39:23.264850 | controller | }
2025-11-24 08:39:23.469324 | controller | changed:
2025-11-24 08:39:23.469416 | controller | {
2025-11-24 08:39:23.469446 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2025-11-24 08:39:23.469468 | controller | }
2025-11-24 08:39:23.676838 | controller | changed:
2025-11-24 08:39:23.676934 | controller | {
2025-11-24 08:39:23.676967 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2025-11-24 08:39:23.676988 | controller | }
2025-11-24 08:39:23.880093 | controller | changed:
2025-11-24 08:39:23.880177 | controller | {
2025-11-24 08:39:23.880205 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2025-11-24 08:39:23.880239 | controller | }
2025-11-24 08:39:23.898402 | 
2025-11-24 08:39:23.898489 | TASK [Set timezone to UTC]
2025-11-24 08:39:24.292399 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2025-11-24 08:39:24.297400 | 
2025-11-24 08:39:24.297473 | TASK [Create nodepool directory]
2025-11-24 08:39:24.499597 | controller | changed
2025-11-24 08:39:24.505072 | 
2025-11-24 08:39:24.505144 | TASK [Create nodepool sub_nodes file]
2025-11-24 08:39:25.026436 | controller | changed
2025-11-24 08:39:25.031814 | 
2025-11-24 08:39:25.031882 | TASK [Create nodepool sub_nodes_private file]
2025-11-24 08:39:25.539478 | controller | changed
2025-11-24 08:39:25.545128 | 
2025-11-24 08:39:25.545198 | LOOP [Populate nodepool sub_nodes file]
2025-11-24 08:39:25.590084 | 
2025-11-24 08:39:25.590323 | LOOP [Populate nodepool sub_nodes_private file]
2025-11-24 08:39:25.628425 | 
2025-11-24 08:39:25.628583 | TASK [Create nodepool primary file]
2025-11-24 08:39:25.652320 | controller | skipping: Conditional result was False
2025-11-24 08:39:25.658157 | 
2025-11-24 08:39:25.658356 | TASK [Create nodepool node_private for this node]
2025-11-24 08:39:26.231893 | controller | changed
2025-11-24 08:39:26.239411 | 
2025-11-24 08:39:26.239497 | LOOP [Copy ssh keys to nodepool directory]
2025-11-24 08:39:26.624538 | controller | ok: Item: id_rsa Runtime: 0:00:00.004069
2025-11-24 08:39:26.624708 | 
2025-11-24 08:39:26.789430 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.004614
2025-11-24 08:39:26.806246 | 
2025-11-24 08:39:26.806355 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2025-11-24 08:39:27.446940 | controller | changed
2025-11-24 08:39:27.457676 | 
2025-11-24 08:39:27.457776 | TASK [Validate sudoers config after edits]
2025-11-24 08:39:27.778011 | controller | /etc/sudoers: parsed OK
2025-11-24 08:39:27.778104 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2025-11-24 08:39:27.778126 | controller | /etc/sudoers.d/zuul: parsed OK
2025-11-24 08:39:27.778136 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2025-11-24 08:39:28.043932 | controller | ok: Runtime: 0:00:00.007021
2025-11-24 08:39:28.049567 | 
2025-11-24 08:39:28.049636 | TASK [Show the environment passed in to job shell scripts]
2025-11-24 08:39:28.284445 | controller | SHELL=/bin/bash
2025-11-24 08:39:28.284487 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2025-11-24 08:39:28.284496 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2025-11-24 08:39:28.284502 | controller | ZUUL_CHANGES=rdo-jobs:master:refs/changes/88/58488/1^openstack-k8s-operators/ci-framework:main:refs/changes/51/3451/9e962b797235f287fc3e87d5e76ab3a88eb03cd8
2025-11-24 08:39:28.284509 | controller | PWD=/home/zuul
2025-11-24 08:39:28.284515 | controller | ZUUL_PIPELINE=github-check
2025-11-24 08:39:28.284520 | controller | LOGNAME=zuul
2025-11-24 08:39:28.284526 | controller | XDG_SESSION_TYPE=tty
2025-11-24 08:39:28.284531 | controller | _=/usr/bin/env
2025-11-24 08:39:28.284567 | controller | MOTD_SHOWN=pam
2025-11-24 08:39:28.284575 | controller | HOME=/home/zuul
2025-11-24 08:39:28.284581 | controller | LANG=en_US.UTF-8
2025-11-24 08:39:28.284587 | controller | SSH_CONNECTION=192.168.26.12 55356 192.168.26.82 22
2025-11-24 08:39:28.284592 | 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-11-24 08:39:28.284599 | controller | ZUUL_CHANGE_IDS=58488,1 3451,9e962b797235f287fc3e87d5e76ab3a88eb03cd8
2025-11-24 08:39:28.284605 | controller | WORKSPACE=/home/zuul/workspace
2025-11-24 08:39:28.284610 | controller | XDG_SESSION_CLASS=user
2025-11-24 08:39:28.284615 | controller | SELINUX_ROLE_REQUESTED=
2025-11-24 08:39:28.284621 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2025-11-24 08:39:28.284626 | controller | USER=zuul
2025-11-24 08:39:28.284631 | controller | ZUUL_VOTING=True
2025-11-24 08:39:28.284637 | controller | BUILD_TIMEOUT=1800000
2025-11-24 08:39:28.284642 | controller | SELINUX_USE_CURRENT_RANGE=
2025-11-24 08:39:28.284647 | controller | SHLVL=1
2025-11-24 08:39:28.284653 | controller | ZUUL_PATCHSET=9e962b797235f287fc3e87d5e76ab3a88eb03cd8
2025-11-24 08:39:28.284658 | controller | XDG_SESSION_ID=1
2025-11-24 08:39:28.284663 | controller | ZUUL_BRANCH=main
2025-11-24 08:39:28.284669 | controller | XDG_RUNTIME_DIR=/run/user/1000
2025-11-24 08:39:28.284674 | controller | SSH_CLIENT=192.168.26.12 55356 22
2025-11-24 08:39:28.284701 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2025-11-24 08:39:28.284707 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2025-11-24 08:39:28.284712 | controller | which_declare=declare -f
2025-11-24 08:39:28.284718 | controller | PATH=/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2025-11-24 08:39:28.284723 | controller | SELINUX_LEVEL_REQUESTED=
2025-11-24 08:39:28.284728 | controller | ZUUL_CHANGE=3451
2025-11-24 08:39:28.284734 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2025-11-24 08:39:28.284739 | controller | ZUUL_UUID=a3ca31d396aa48b48ef0e4b1b9a7c8ad
2025-11-24 08:39:28.284746 | controller | BASH_FUNC_which%%=() {  ( alias;
2025-11-24 08:39:28.284752 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2025-11-24 08:39:28.284757 | controller | }
2025-11-24 08:39:28.594964 | controller | ok: Runtime: 0:00:00.005427
2025-11-24 08:39:28.600582 | 
2025-11-24 08:39:28.600652 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2025-11-24 08:39:28.614270 | controller | skipping: Conditional result was False
2025-11-24 08:39:28.620248 | 
2025-11-24 08:39:28.620320 | TASK [Symlink /home/zuul-worker/workspace]
2025-11-24 08:39:29.147841 | controller | skipping: Conditional result was False
2025-11-24 08:39:29.153696 | 
2025-11-24 08:39:29.153773 | TASK [Ensure legacy workspace directory]
2025-11-24 08:39:29.345284 | controller | changed
2025-11-24 08:39:29.365422 | 
2025-11-24 08:39:29.365518 | PLAY RECAP
2025-11-24 08:39:29.365564 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-11-24 08:39:29.365587 | 
2025-11-24 08:39:29.473874 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-11-24 08:39:29.474677 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-11-24 08:39:30.144339 | 
2025-11-24 08:39:30.144455 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2025-11-24 08:39:30.193791 | 
2025-11-24 08:39:30.193940 | TASK [Create zuul-output directory]
2025-11-24 08:39:30.563535 | controller | changed
2025-11-24 08:39:30.580620 | 
2025-11-24 08:39:30.580744 | TASK [Slurp Zuul inventory test]
2025-11-24 08:39:31.146314 | controller -> localhost | ok
2025-11-24 08:39:31.152716 | 
2025-11-24 08:39:31.152813 | TASK [Save zuul inventory]
2025-11-24 08:39:32.226838 | controller | changed
2025-11-24 08:39:32.237049 | 
2025-11-24 08:39:32.237130 | TASK [Save zuul vars without the change_message]
2025-11-24 08:39:33.043123 | controller | changed
2025-11-24 08:39:33.068618 | 
2025-11-24 08:39:33.068693 | PLAY RECAP
2025-11-24 08:39:33.068741 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-11-24 08:39:33.068765 | 
2025-11-24 08:39:33.264642 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-11-24 08:39:33.265395 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-11-24 08:39:34.161471 | 
2025-11-24 08:39:34.161581 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2025-11-24 08:39:34.193816 | 
2025-11-24 08:39:34.193946 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2025-11-24 08:39:34.212462 | controller | ok
2025-11-24 08:39:34.251357 | 
2025-11-24 08:39:34.251478 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-11-24 08:39:34.285609 | controller | skipping: Conditional result was False
2025-11-24 08:39:34.294605 | 
2025-11-24 08:39:34.294695 | TASK [mirror-info-fork : Create /etc/ci]
2025-11-24 08:39:34.770379 | controller | ok
2025-11-24 08:39:34.778873 | 
2025-11-24 08:39:34.779024 | TASK [mirror-info-fork : Install ci_mirror script]
2025-11-24 08:39:35.691798 | controller | ok
2025-11-24 08:39:35.717886 | 
2025-11-24 08:39:35.718000 | TASK [Prepare workspace]
2025-11-24 08:39:35.763009 | controller | ok
2025-11-24 08:39:35.806431 | 
2025-11-24 08:39:35.806536 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-11-24 08:39:36.351470 | controller | ok
2025-11-24 08:39:36.360755 | 
2025-11-24 08:39:36.360844 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-11-24 08:39:40.932581 | controller | Output suppressed because no_log was given
2025-11-24 08:39:40.953974 | 
2025-11-24 08:39:40.956028 | LOOP [Create zuul-output directory]
2025-11-24 08:39:41.245690 | controller | changed: "/home/zuul/ci-framework-data/logs"
2025-11-24 08:39:41.409758 | controller | ok: "/home/zuul/zuul-output/logs"
2025-11-24 08:39:41.420335 | 
2025-11-24 08:39:41.420425 | TASK [Install required packages]
2025-11-24 08:40:35.240354 | controller | changed
2025-11-24 08:40:35.247925 | 
2025-11-24 08:40:35.248036 | TASK [Install venv]
2025-11-24 08:41:40.192691 | controller | changed
2025-11-24 08:41:40.235318 | 
2025-11-24 08:41:40.235399 | PLAY RECAP
2025-11-24 08:41:40.235439 | controller | ok: 7 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-11-24 08:41:40.235461 | 
2025-11-24 08:41:40.301944 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-11-24 08:41:40.302736 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-11-24 08:41:40.840879 | 
2025-11-24 08:41:40.841024 | PLAY [Run ci/playbooks/molecule-test.yml]
2025-11-24 08:41:40.862566 | 
2025-11-24 08:41:40.863011 | TASK [Gather required facts]
2025-11-24 08:41:41.340008 | controller | ok
2025-11-24 08:41:41.345840 | 
2025-11-24 08:41:41.345974 | TASK [Load environment var if instructed to]
2025-11-24 08:41:41.371514 | controller | skipping: Conditional result was False
2025-11-24 08:41:41.377503 | 
2025-11-24 08:41:41.377588 | TASK [Ensure group_vars dir exists]
2025-11-24 08:41:41.691629 | controller | ok
2025-11-24 08:41:41.697857 | 
2025-11-24 08:41:41.697952 | TASK [Print related variables]
2025-11-24 08:41:41.727097 | controller | ok:
2025-11-24 08:41:41.727244 | controller | mol_config_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config_local.yml
2025-11-24 08:41:41.727289 | controller | roles_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/run_hook
2025-11-24 08:41:41.732057 | 
2025-11-24 08:41:41.732122 | TASK [Run molecule]
2025-11-24 08:41:42.675705 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2025-11-24 08:41:42.755899 | controller | INFO     Running default > prepare
2025-11-24 08:41:43.416176 | controller |
2025-11-24 08:41:43.416239 | controller | PLAY [Prepare] *****************************************************************
2025-11-24 08:41:43.416277 | controller |
2025-11-24 08:41:43.416747 | controller | TASK [Gathering Facts] *********************************************************
2025-11-24 08:41:43.417016 | controller | Monday 24 November 2025  08:41:43 +0000 (0:00:00.011)       0:00:00.011 *******
2025-11-24 08:41:44.244050 | controller | ok: [instance]
2025-11-24 08:41:44.244103 | controller |
2025-11-24 08:41:44.244273 | controller | TASK [Create dummy env file] ***************************************************
2025-11-24 08:41:44.244382 | controller | Monday 24 November 2025  08:41:44 +0000 (0:00:00.828)       0:00:00.840 *******
2025-11-24 08:41:44.756589 | controller | changed: [instance]
2025-11-24 08:41:44.756655 | controller |
2025-11-24 08:41:44.756763 | controller | TASK [Create dummy playbook] ***************************************************
2025-11-24 08:41:44.756866 | controller | Monday 24 November 2025  08:41:44 +0000 (0:00:00.512)       0:00:01.353 *******
2025-11-24 08:41:46.642070 | controller | changed: [instance] => (item=dummy-1.yml)
2025-11-24 08:41:46.642214 | controller | changed: [instance] => (item=dummy-2.yml)
2025-11-24 08:41:46.642353 | controller | changed: [instance] => (item=dummy-3.yml)
2025-11-24 08:41:46.642486 | controller | changed: [instance] => (item=dummy-4.yml)
2025-11-24 08:41:46.642613 | controller | changed: [instance] => (item=dummy-5.yml)
2025-11-24 08:41:46.642737 | controller | changed: [instance] => (item=dummy-6.yml)
2025-11-24 08:41:46.642844 | controller |
2025-11-24 08:41:46.642951 | controller | TASK [Remove dummy file for retry playbook test] *******************************
2025-11-24 08:41:46.643070 | controller | Monday 24 November 2025  08:41:46 +0000 (0:00:01.885)       0:00:03.238 *******
2025-11-24 08:41:46.916934 | controller | ok: [instance]
2025-11-24 08:41:46.916987 | controller |
2025-11-24 08:41:46.917147 | controller | TASK [Create dummy retry playbook] *********************************************
2025-11-24 08:41:46.917259 | controller | Monday 24 November 2025  08:41:46 +0000 (0:00:00.274)       0:00:03.513 *******
2025-11-24 08:41:47.262071 | controller | changed: [instance]
2025-11-24 08:41:47.262147 | controller |
2025-11-24 08:41:47.262265 | controller | PLAY RECAP *********************************************************************
2025-11-24 08:41:47.262390 | controller | instance                   : ok=5    changed=3    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-11-24 08:41:47.262503 | controller |
2025-11-24 08:41:47.262596 | controller | Monday 24 November 2025  08:41:47 +0000 (0:00:00.345)       0:00:03.859 *******
2025-11-24 08:41:47.262695 | controller | ===============================================================================
2025-11-24 08:41:47.262878 | controller | Create dummy playbook --------------------------------------------------- 1.89s
2025-11-24 08:41:47.262909 | controller | Gathering Facts --------------------------------------------------------- 0.83s
2025-11-24 08:41:47.263006 | controller | Create dummy env file --------------------------------------------------- 0.51s
2025-11-24 08:41:47.263173 | controller | Create dummy retry playbook --------------------------------------------- 0.35s
2025-11-24 08:41:47.263254 | controller | Remove dummy file for retry playbook test ------------------------------- 0.27s
2025-11-24 08:41:47.315032 | controller | INFO     Running default > converge
2025-11-24 08:41:47.738246 | controller |
2025-11-24 08:41:47.738291 | controller | PLAY [Converge] ****************************************************************
2025-11-24 08:41:47.738459 | controller |
2025-11-24 08:41:47.738554 | controller | TASK [Gathering Facts] *********************************************************
2025-11-24 08:41:47.738674 | controller | Monday 24 November 2025  08:41:47 +0000 (0:00:00.015)       0:00:00.015 *******
2025-11-24 08:41:48.529009 | controller | ok: [instance]
2025-11-24 08:41:48.558463 | controller |
2025-11-24 08:41:48.558491 | controller | TASK [No hook] *****************************************************************
2025-11-24 08:41:48.558498 | controller | Monday 24 November 2025  08:41:48 +0000 (0:00:00.790)       0:00:00.806 *******
2025-11-24 08:41:48.558508 | controller |
2025-11-24 08:41:48.617633 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-11-24 08:41:48.617678 | controller | Monday 24 November 2025  08:41:48 +0000 (0:00:00.029)       0:00:00.835 *******
2025-11-24 08:41:48.617690 | controller | ok: [instance]
2025-11-24 08:41:48.693227 | controller |
2025-11-24 08:41:48.693264 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-11-24 08:41:48.693274 | controller | Monday 24 November 2025  08:41:48 +0000 (0:00:00.059)       0:00:00.894 *******
2025-11-24 08:41:48.693287 | controller | ok: [instance]
2025-11-24 08:41:48.693318 | controller |
2025-11-24 08:41:48.693607 | controller | TASK [run_hook : Loop on hooks for no_hook] ************************************
2025-11-24 08:41:48.772168 | controller | Monday 24 November 2025  08:41:48 +0000 (0:00:00.075)       0:00:00.970 *******
2025-11-24 08:41:48.772213 | controller | skipping: [instance]
2025-11-24 08:41:48.797087 | controller |
2025-11-24 08:41:48.797108 | controller | TASK [Ensure we do not have ceph_uuid] *****************************************
2025-11-24 08:41:48.797156 | controller | Monday 24 November 2025  08:41:48 +0000 (0:00:00.078)       0:00:01.049 *******
2025-11-24 08:41:48.797167 | controller | ok: [instance] => changed=false
2025-11-24 08:41:48.828174 | controller |   msg: All assertions passed
2025-11-24 08:41:48.828197 | controller |
2025-11-24 08:41:48.828205 | controller | TASK [Combined hooks] **********************************************************
2025-11-24 08:41:48.828212 | controller | Monday 24 November 2025  08:41:48 +0000 (0:00:00.025)       0:00:01.074 *******
2025-11-24 08:41:48.828223 | controller |
2025-11-24 08:41:48.828272 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-11-24 08:41:48.828284 | controller | Monday 24 November 2025  08:41:48 +0000 (0:00:00.031)       0:00:01.105 *******
2025-11-24 08:41:48.888223 | controller | ok: [instance]
2025-11-24 08:41:48.888274 | controller |
2025-11-24 08:41:48.888552 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-11-24 08:41:48.963242 | controller | Monday 24 November 2025  08:41:48 +0000 (0:00:00.060)       0:00:01.165 *******
2025-11-24 08:41:48.963284 | controller | ok: [instance]
2025-11-24 08:41:48.963314 | controller |
2025-11-24 08:41:48.963324 | controller | TASK [run_hook : Loop on hooks for run_molecule] *******************************
2025-11-24 08:41:48.963350 | controller | Monday 24 November 2025  08:41:48 +0000 (0:00:00.074)       0:00:01.240 *******
2025-11-24 08:41:49.090878 | 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-11-24 08:41:49.139675 | 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-11-24 08:41:49.139704 | 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-11-24 08:41:49.139716 | controller |
2025-11-24 08:41:49.139723 | controller | TASK [run_hook : Set playbook path for 01 Default noop hook] *******************
2025-11-24 08:41:49.139728 | controller | Monday 24 November 2025  08:41:49 +0000 (0:00:00.126)       0:00:01.367 *******
2025-11-24 08:41:49.139738 | controller | ok: [instance]
2025-11-24 08:41:49.438098 | controller |
2025-11-24 08:41:49.438155 | controller | TASK [run_hook : Get file stat] ************************************************
2025-11-24 08:41:49.438164 | controller | Monday 24 November 2025  08:41:49 +0000 (0:00:00.049)       0:00:01.417 *******
2025-11-24 08:41:49.438174 | controller | ok: [instance]
2025-11-24 08:41:49.455157 | controller |
2025-11-24 08:41:49.455175 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-11-24 08:41:49.455186 | controller | Monday 24 November 2025  08:41:49 +0000 (0:00:00.298)       0:00:01.715 *******
2025-11-24 08:41:49.455195 | controller | skipping: [instance]
2025-11-24 08:41:49.455482 | controller |
2025-11-24 08:41:49.743891 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-11-24 08:41:49.743923 | controller | Monday 24 November 2025  08:41:49 +0000 (0:00:00.017)       0:00:01.732 *******
2025-11-24 08:41:49.743942 | controller | ok: [instance]
2025-11-24 08:41:49.764831 | controller |
2025-11-24 08:41:49.764854 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-11-24 08:41:49.764861 | controller | Monday 24 November 2025  08:41:49 +0000 (0:00:00.288)       0:00:02.021 *******
2025-11-24 08:41:49.764871 | controller | ok: [instance]
2025-11-24 08:41:50.060625 | controller |
2025-11-24 08:41:50.060658 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-11-24 08:41:50.060666 | controller | Monday 24 November 2025  08:41:49 +0000 (0:00:00.021)       0:00:02.042 *******
2025-11-24 08:41:50.060677 | controller | ok: [instance]
2025-11-24 08:41:50.259578 | controller |
2025-11-24 08:41:50.259614 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-11-24 08:41:50.259622 | controller | Monday 24 November 2025  08:41:50 +0000 (0:00:00.295)       0:00:02.337 *******
2025-11-24 08:41:50.259633 | controller | ok: [instance]
2025-11-24 08:41:50.882071 | controller |
2025-11-24 08:41:50.882105 | controller | TASK [run_hook : Run hook without retry - 01 Default noop hook] ****************
2025-11-24 08:41:50.882144 | controller | Monday 24 November 2025  08:41:50 +0000 (0:00:00.198)       0:00:02.536 *******
2025-11-24 08:41:50.882160 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_000_run_hook_without_retry_01.log
2025-11-24 08:41:50.913032 | controller | changed: [instance]
2025-11-24 08:41:50.913055 | controller |
2025-11-24 08:41:50.913063 | controller | TASK [run_hook : Run hook with retry - 01 Default noop hook] *******************
2025-11-24 08:41:50.913074 | controller | Monday 24 November 2025  08:41:50 +0000 (0:00:00.622)       0:00:03.159 *******
2025-11-24 08:41:50.913085 | controller | skipping: [instance]
2025-11-24 08:41:51.090531 | controller |
2025-11-24 08:41:51.090566 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-11-24 08:41:51.090575 | controller | Monday 24 November 2025  08:41:50 +0000 (0:00:00.031)       0:00:03.190 *******
2025-11-24 08:41:51.090586 | controller | ok: [instance]
2025-11-24 08:41:51.109737 | controller |
2025-11-24 08:41:51.109766 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-11-24 08:41:51.109776 | controller | Monday 24 November 2025  08:41:51 +0000 (0:00:00.177)       0:00:03.367 *******
2025-11-24 08:41:51.109790 | controller | skipping: [instance]
2025-11-24 08:41:51.158895 | controller |
2025-11-24 08:41:51.158918 | controller | TASK [run_hook : Set playbook path for 02 Re-run noop] *************************
2025-11-24 08:41:51.158926 | controller | Monday 24 November 2025  08:41:51 +0000 (0:00:00.019)       0:00:03.387 *******
2025-11-24 08:41:51.158936 | controller | ok: [instance]
2025-11-24 08:41:51.352362 | controller |
2025-11-24 08:41:51.352393 | controller | TASK [run_hook : Get file stat] ************************************************
2025-11-24 08:41:51.352401 | controller | Monday 24 November 2025  08:41:51 +0000 (0:00:00.049)       0:00:03.436 *******
2025-11-24 08:41:51.352412 | controller | ok: [instance]
2025-11-24 08:41:51.370094 | controller |
2025-11-24 08:41:51.370125 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-11-24 08:41:51.370136 | controller | Monday 24 November 2025  08:41:51 +0000 (0:00:00.193)       0:00:03.629 *******
2025-11-24 08:41:51.370145 | controller | skipping: [instance]
2025-11-24 08:41:51.563862 | controller |
2025-11-24 08:41:51.563897 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-11-24 08:41:51.563906 | controller | Monday 24 November 2025  08:41:51 +0000 (0:00:00.018)       0:00:03.647 *******
2025-11-24 08:41:51.563917 | controller | ok: [instance]
2025-11-24 08:41:51.585786 | controller |
2025-11-24 08:41:51.585809 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-11-24 08:41:51.585818 | controller | Monday 24 November 2025  08:41:51 +0000 (0:00:00.193)       0:00:03.841 *******
2025-11-24 08:41:51.585829 | controller | ok: [instance]
2025-11-24 08:41:51.782033 | controller |
2025-11-24 08:41:51.782065 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-11-24 08:41:51.782078 | controller | Monday 24 November 2025  08:41:51 +0000 (0:00:00.022)       0:00:03.863 *******
2025-11-24 08:41:51.782090 | controller | ok: [instance]
2025-11-24 08:41:51.970760 | controller |
2025-11-24 08:41:51.970804 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-11-24 08:41:51.970813 | controller | Monday 24 November 2025  08:41:51 +0000 (0:00:00.196)       0:00:04.059 *******
2025-11-24 08:41:51.970824 | controller | ok: [instance]
2025-11-24 08:41:52.597447 | controller |
2025-11-24 08:41:52.597477 | controller | TASK [run_hook : Run hook without retry - 02 Re-run noop] **********************
2025-11-24 08:41:52.597485 | controller | Monday 24 November 2025  08:41:51 +0000 (0:00:00.188)       0:00:04.247 *******
2025-11-24 08:41:52.597496 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_001_run_hook_without_retry_02_re.log
2025-11-24 08:41:52.626660 | controller | changed: [instance]
2025-11-24 08:41:52.626688 | controller |
2025-11-24 08:41:52.626696 | controller | TASK [run_hook : Run hook with retry - 02 Re-run noop] *************************
2025-11-24 08:41:52.626702 | controller | Monday 24 November 2025  08:41:52 +0000 (0:00:00.626)       0:00:04.874 *******
2025-11-24 08:41:52.626712 | controller | skipping: [instance]
2025-11-24 08:41:52.797176 | controller |
2025-11-24 08:41:52.797210 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-11-24 08:41:52.797217 | controller | Monday 24 November 2025  08:41:52 +0000 (0:00:00.029)       0:00:04.904 *******
2025-11-24 08:41:52.797228 | controller | ok: [instance]
2025-11-24 08:41:52.816689 | controller |
2025-11-24 08:41:52.816718 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-11-24 08:41:52.816726 | controller | Monday 24 November 2025  08:41:52 +0000 (0:00:00.170)       0:00:05.074 *******
2025-11-24 08:41:52.816737 | controller | skipping: [instance]
2025-11-24 08:41:52.865227 | controller |
2025-11-24 08:41:52.865260 | controller | TASK [run_hook : Set playbook path for 03 single hook] *************************
2025-11-24 08:41:52.865267 | controller | Monday 24 November 2025  08:41:52 +0000 (0:00:00.019)       0:00:05.094 *******
2025-11-24 08:41:52.865278 | controller | ok: [instance]
2025-11-24 08:41:53.056802 | controller |
2025-11-24 08:41:53.056834 | controller | TASK [run_hook : Get file stat] ************************************************
2025-11-24 08:41:53.056842 | controller | Monday 24 November 2025  08:41:52 +0000 (0:00:00.048)       0:00:05.142 *******
2025-11-24 08:41:53.056852 | controller | ok: [instance]
2025-11-24 08:41:53.073136 | controller |
2025-11-24 08:41:53.073154 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-11-24 08:41:53.073161 | controller | Monday 24 November 2025  08:41:53 +0000 (0:00:00.191)       0:00:05.334 *******
2025-11-24 08:41:53.073170 | controller | skipping: [instance]
2025-11-24 08:41:53.267508 | controller |
2025-11-24 08:41:53.267542 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-11-24 08:41:53.267551 | controller | Monday 24 November 2025  08:41:53 +0000 (0:00:00.016)       0:00:05.350 *******
2025-11-24 08:41:53.267561 | controller | ok: [instance]
2025-11-24 08:41:53.287565 | controller |
2025-11-24 08:41:53.287586 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-11-24 08:41:53.287593 | controller | Monday 24 November 2025  08:41:53 +0000 (0:00:00.194)       0:00:05.544 *******
2025-11-24 08:41:53.287603 | controller | ok: [instance]
2025-11-24 08:41:53.477582 | controller |
2025-11-24 08:41:53.477616 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-11-24 08:41:53.477624 | controller | Monday 24 November 2025  08:41:53 +0000 (0:00:00.020)       0:00:05.565 *******
2025-11-24 08:41:53.477634 | controller | ok: [instance]
2025-11-24 08:41:53.662220 | controller |
2025-11-24 08:41:53.662251 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-11-24 08:41:53.662260 | controller | Monday 24 November 2025  08:41:53 +0000 (0:00:00.189)       0:00:05.754 *******
2025-11-24 08:41:53.662270 | controller | ok: [instance]
2025-11-24 08:41:55.601371 | controller |
2025-11-24 08:41:55.601400 | controller | TASK [run_hook : Run hook without retry - 03 single hook] **********************
2025-11-24 08:41:55.601408 | controller | Monday 24 November 2025  08:41:53 +0000 (0:00:00.184)       0:00:05.939 *******
2025-11-24 08:41:55.601418 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_002_run_hook_without_retry_03.log
2025-11-24 08:41:55.632237 | controller | changed: [instance]
2025-11-24 08:41:55.632282 | controller |
2025-11-24 08:41:55.632291 | controller | TASK [run_hook : Run hook with retry - 03 single hook] *************************
2025-11-24 08:41:55.632297 | controller | Monday 24 November 2025  08:41:55 +0000 (0:00:01.939)       0:00:07.878 *******
2025-11-24 08:41:55.632308 | controller | skipping: [instance]
2025-11-24 08:41:55.819100 | controller |
2025-11-24 08:41:55.819165 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-11-24 08:41:55.819174 | controller | Monday 24 November 2025  08:41:55 +0000 (0:00:00.031)       0:00:07.909 *******
2025-11-24 08:41:55.819190 | controller | ok: [instance]
2025-11-24 08:41:55.845483 | controller |
2025-11-24 08:41:55.845502 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-11-24 08:41:55.845509 | controller | Monday 24 November 2025  08:41:55 +0000 (0:00:00.186)       0:00:08.096 *******
2025-11-24 08:41:55.845518 | controller | ok: [instance]
2025-11-24 08:41:55.871088 | controller |
2025-11-24 08:41:55.871109 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-11-24 08:41:55.871142 | controller | Monday 24 November 2025  08:41:55 +0000 (0:00:00.026)       0:00:08.122 *******
2025-11-24 08:41:55.871154 | controller | ok: [instance] => changed=false
2025-11-24 08:41:55.904246 | controller |   msg: All assertions passed
2025-11-24 08:41:55.904273 | controller |
2025-11-24 08:41:55.904280 | controller | TASK [Only listed hooks] *******************************************************
2025-11-24 08:41:55.904286 | controller | Monday 24 November 2025  08:41:55 +0000 (0:00:00.025)       0:00:08.148 *******
2025-11-24 08:41:55.904296 | controller |
2025-11-24 08:41:55.964851 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-11-24 08:41:55.964870 | controller | Monday 24 November 2025  08:41:55 +0000 (0:00:00.033)       0:00:08.181 *******
2025-11-24 08:41:55.964880 | controller | ok: [instance]
2025-11-24 08:41:56.039236 | controller |
2025-11-24 08:41:56.039275 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-11-24 08:41:56.039285 | controller | Monday 24 November 2025  08:41:55 +0000 (0:00:00.060)       0:00:08.242 *******
2025-11-24 08:41:56.039298 | controller | ok: [instance]
2025-11-24 08:41:56.148015 | controller |
2025-11-24 08:41:56.148046 | controller | TASK [run_hook : Loop on hooks for list_hooks] *********************************
2025-11-24 08:41:56.148054 | controller | Monday 24 November 2025  08:41:56 +0000 (0:00:00.074)       0:00:08.316 *******
2025-11-24 08:41:56.148064 | 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-11-24 08:41:56.195234 | 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-11-24 08:41:56.195274 | controller |
2025-11-24 08:41:56.195282 | controller | TASK [run_hook : Set playbook path for Run dummy-2] ****************************
2025-11-24 08:41:56.195289 | controller | Monday 24 November 2025  08:41:56 +0000 (0:00:00.108)       0:00:08.425 *******
2025-11-24 08:41:56.195299 | controller | ok: [instance]
2025-11-24 08:41:56.195323 | controller |
2025-11-24 08:41:56.195332 | controller | TASK [run_hook : Get file stat] ************************************************
2025-11-24 08:41:56.195454 | controller | Monday 24 November 2025  08:41:56 +0000 (0:00:00.047)       0:00:08.472 *******
2025-11-24 08:41:56.384210 | controller | ok: [instance]
2025-11-24 08:41:56.401165 | controller |
2025-11-24 08:41:56.401182 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-11-24 08:41:56.401189 | controller | Monday 24 November 2025  08:41:56 +0000 (0:00:00.188)       0:00:08.661 *******
2025-11-24 08:41:56.401198 | controller | skipping: [instance]
2025-11-24 08:41:56.401341 | controller |
2025-11-24 08:41:56.401370 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-11-24 08:41:56.401382 | controller | Monday 24 November 2025  08:41:56 +0000 (0:00:00.017)       0:00:08.678 *******
2025-11-24 08:41:56.589313 | controller | ok: [instance]
2025-11-24 08:41:56.609310 | controller |
2025-11-24 08:41:56.609336 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-11-24 08:41:56.609345 | controller | Monday 24 November 2025  08:41:56 +0000 (0:00:00.187)       0:00:08.866 *******
2025-11-24 08:41:56.609357 | controller | ok: [instance]
2025-11-24 08:41:56.802059 | controller |
2025-11-24 08:41:56.802089 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-11-24 08:41:56.802097 | controller | Monday 24 November 2025  08:41:56 +0000 (0:00:00.020)       0:00:08.886 *******
2025-11-24 08:41:56.802107 | controller | ok: [instance]
2025-11-24 08:41:56.986915 | controller |
2025-11-24 08:41:56.986946 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-11-24 08:41:56.986955 | controller | Monday 24 November 2025  08:41:56 +0000 (0:00:00.192)       0:00:09.079 *******
2025-11-24 08:41:56.986965 | controller | ok: [instance]
2025-11-24 08:41:58.863194 | controller |
2025-11-24 08:41:58.863224 | controller | TASK [run_hook : Run hook without retry - Run dummy-2] *************************
2025-11-24 08:41:58.863232 | controller | Monday 24 November 2025  08:41:56 +0000 (0:00:00.184)       0:00:09.264 *******
2025-11-24 08:41:58.863242 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_003_run_hook_without_retry_run.log
2025-11-24 08:41:58.863370 | controller | changed: [instance]
2025-11-24 08:41:58.863381 | controller |
2025-11-24 08:41:58.863387 | controller | TASK [run_hook : Run hook with retry - Run dummy-2] ****************************
2025-11-24 08:41:58.863396 | controller | Monday 24 November 2025  08:41:58 +0000 (0:00:01.876)       0:00:11.140 *******
2025-11-24 08:41:58.893968 | controller | skipping: [instance]
2025-11-24 08:41:59.083571 | controller |
2025-11-24 08:41:59.083601 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-11-24 08:41:59.083614 | controller | Monday 24 November 2025  08:41:58 +0000 (0:00:00.030)       0:00:11.171 *******
2025-11-24 08:41:59.083625 | controller | ok: [instance]
2025-11-24 08:41:59.106199 | controller |
2025-11-24 08:41:59.106220 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-11-24 08:41:59.106228 | controller | Monday 24 November 2025  08:41:59 +0000 (0:00:00.189)       0:00:11.360 *******
2025-11-24 08:41:59.106237 | controller | ok: [instance]
2025-11-24 08:41:59.106260 | controller |
2025-11-24 08:41:59.106513 | controller | TASK [run_hook : Set playbook path for Run dummy-3] ****************************
2025-11-24 08:41:59.153512 | controller | Monday 24 November 2025  08:41:59 +0000 (0:00:00.023)       0:00:11.384 *******
2025-11-24 08:41:59.153533 | controller | ok: [instance]
2025-11-24 08:41:59.341106 | controller |
2025-11-24 08:41:59.341152 | controller | TASK [run_hook : Get file stat] ************************************************
2025-11-24 08:41:59.341160 | controller | Monday 24 November 2025  08:41:59 +0000 (0:00:00.046)       0:00:11.431 *******
2025-11-24 08:41:59.341171 | controller | ok: [instance]
2025-11-24 08:41:59.358165 | controller |
2025-11-24 08:41:59.358189 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-11-24 08:41:59.358197 | controller | Monday 24 November 2025  08:41:59 +0000 (0:00:00.187)       0:00:11.618 *******
2025-11-24 08:41:59.358209 | controller | skipping: [instance]
2025-11-24 08:41:59.358482 | controller |
2025-11-24 08:41:59.358496 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-11-24 08:41:59.548413 | controller | Monday 24 November 2025  08:41:59 +0000 (0:00:00.017)       0:00:11.635 *******
2025-11-24 08:41:59.548462 | controller | ok: [instance]
2025-11-24 08:41:59.568827 | controller |
2025-11-24 08:41:59.568846 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-11-24 08:41:59.568853 | controller | Monday 24 November 2025  08:41:59 +0000 (0:00:00.189)       0:00:11.825 *******
2025-11-24 08:41:59.568862 | controller | ok: [instance]
2025-11-24 08:41:59.769158 | controller |
2025-11-24 08:41:59.769190 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-11-24 08:41:59.769198 | controller | Monday 24 November 2025  08:41:59 +0000 (0:00:00.020)       0:00:11.846 *******
2025-11-24 08:41:59.769209 | controller | ok: [instance]
2025-11-24 08:41:59.961765 | controller |
2025-11-24 08:41:59.961795 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-11-24 08:41:59.961810 | controller | Monday 24 November 2025  08:41:59 +0000 (0:00:00.199)       0:00:12.046 *******
2025-11-24 08:41:59.961820 | controller | ok: [instance]
2025-11-24 08:42:01.891465 | controller |
2025-11-24 08:42:01.891496 | controller | TASK [run_hook : Run hook without retry - Run dummy-3] *************************
2025-11-24 08:42:01.891504 | controller | Monday 24 November 2025  08:41:59 +0000 (0:00:00.192)       0:00:12.239 *******
2025-11-24 08:42:01.891514 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_004_run_hook_without_retry_run.log
2025-11-24 08:42:01.921834 | controller | changed: [instance]
2025-11-24 08:42:01.921865 | controller |
2025-11-24 08:42:01.921874 | controller | TASK [run_hook : Run hook with retry - Run dummy-3] ****************************
2025-11-24 08:42:01.921881 | controller | Monday 24 November 2025  08:42:01 +0000 (0:00:01.929)       0:00:14.168 *******
2025-11-24 08:42:01.921893 | controller | skipping: [instance]
2025-11-24 08:42:02.109839 | controller |
2025-11-24 08:42:02.109870 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-11-24 08:42:02.109878 | controller | Monday 24 November 2025  08:42:01 +0000 (0:00:00.030)       0:00:14.199 *******
2025-11-24 08:42:02.109888 | controller | ok: [instance]
2025-11-24 08:42:02.137170 | controller |
2025-11-24 08:42:02.137208 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-11-24 08:42:02.137216 | controller | Monday 24 November 2025  08:42:02 +0000 (0:00:00.188)       0:00:14.387 *******
2025-11-24 08:42:02.137228 | controller | ok: [instance]
2025-11-24 08:42:02.162764 | controller |
2025-11-24 08:42:02.162797 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-11-24 08:42:02.162805 | controller | Monday 24 November 2025  08:42:02 +0000 (0:00:00.027)       0:00:14.414 *******
2025-11-24 08:42:02.162814 | controller | ok: [instance] => changed=false
2025-11-24 08:42:02.197475 | controller |   msg: All assertions passed
2025-11-24 08:42:02.197505 | controller |
2025-11-24 08:42:02.197515 | controller | TASK [Only filtered hooks] *****************************************************
2025-11-24 08:42:02.197522 | controller | Monday 24 November 2025  08:42:02 +0000 (0:00:00.025)       0:00:14.439 *******
2025-11-24 08:42:02.197533 | controller |
2025-11-24 08:42:02.256717 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-11-24 08:42:02.256750 | controller | Monday 24 November 2025  08:42:02 +0000 (0:00:00.034)       0:00:14.474 *******
2025-11-24 08:42:02.256770 | controller | ok: [instance]
2025-11-24 08:42:02.333010 | controller |
2025-11-24 08:42:02.333040 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-11-24 08:42:02.333048 | controller | Monday 24 November 2025  08:42:02 +0000 (0:00:00.059)       0:00:14.533 *******
2025-11-24 08:42:02.333057 | controller | ok: [instance]
2025-11-24 08:42:02.429250 | controller |
2025-11-24 08:42:02.429281 | controller | TASK [run_hook : Loop on hooks for filtered_hooks] *****************************
2025-11-24 08:42:02.429289 | controller | Monday 24 November 2025  08:42:02 +0000 (0:00:00.076)       0:00:14.610 *******
2025-11-24 08:42:02.429299 | 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-11-24 08:42:02.429445 | controller |
2025-11-24 08:42:02.429614 | controller | TASK [run_hook : Set playbook path for 01 my hook] *****************************
2025-11-24 08:42:02.429764 | controller | Monday 24 November 2025  08:42:02 +0000 (0:00:00.096)       0:00:14.706 *******
2025-11-24 08:42:02.477304 | controller | ok: [instance]
2025-11-24 08:42:02.477513 | controller |
2025-11-24 08:42:02.477690 | controller | TASK [run_hook : Get file stat] ************************************************
2025-11-24 08:42:02.477867 | controller | Monday 24 November 2025  08:42:02 +0000 (0:00:00.048)       0:00:14.755 *******
2025-11-24 08:42:02.668369 | controller | ok: [instance]
2025-11-24 08:42:02.686088 | controller |
2025-11-24 08:42:02.686141 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-11-24 08:42:02.686152 | controller | Monday 24 November 2025  08:42:02 +0000 (0:00:00.190)       0:00:14.945 *******
2025-11-24 08:42:02.686162 | controller | skipping: [instance]
2025-11-24 08:42:02.871973 | controller |
2025-11-24 08:42:02.872002 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-11-24 08:42:02.872010 | controller | Monday 24 November 2025  08:42:02 +0000 (0:00:00.017)       0:00:14.963 *******
2025-11-24 08:42:02.872020 | controller | ok: [instance]
2025-11-24 08:42:02.891180 | controller |
2025-11-24 08:42:02.891206 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-11-24 08:42:02.891215 | controller | Monday 24 November 2025  08:42:02 +0000 (0:00:00.185)       0:00:15.149 *******
2025-11-24 08:42:02.891225 | controller | ok: [instance]
2025-11-24 08:42:02.891248 | controller |
2025-11-24 08:42:02.891562 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-11-24 08:42:03.086850 | controller | Monday 24 November 2025  08:42:02 +0000 (0:00:00.019)       0:00:15.168 *******
2025-11-24 08:42:03.086885 | controller | ok: [instance]
2025-11-24 08:42:03.273137 | controller |
2025-11-24 08:42:03.273169 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-11-24 08:42:03.273177 | controller | Monday 24 November 2025  08:42:03 +0000 (0:00:00.195)       0:00:15.364 *******
2025-11-24 08:42:03.273187 | controller | ok: [instance]
2025-11-24 08:42:05.215757 | controller |
2025-11-24 08:42:05.215787 | controller | TASK [run_hook : Run hook without retry - 01 my hook] **************************
2025-11-24 08:42:05.215795 | controller | Monday 24 November 2025  08:42:03 +0000 (0:00:00.186)       0:00:15.550 *******
2025-11-24 08:42:05.215805 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_005_run_hook_without_retry_01_my.log
2025-11-24 08:42:05.246593 | controller | changed: [instance]
2025-11-24 08:42:05.246619 | controller |
2025-11-24 08:42:05.246626 | controller | TASK [run_hook : Run hook with retry - 01 my hook] *****************************
2025-11-24 08:42:05.246632 | controller | Monday 24 November 2025  08:42:05 +0000 (0:00:01.942)       0:00:17.492 *******
2025-11-24 08:42:05.246642 | controller | skipping: [instance]
2025-11-24 08:42:05.439653 | controller |
2025-11-24 08:42:05.439687 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-11-24 08:42:05.439695 | controller | Monday 24 November 2025  08:42:05 +0000 (0:00:00.030)       0:00:17.523 *******
2025-11-24 08:42:05.439705 | controller | ok: [instance]
2025-11-24 08:42:05.466996 | controller |
2025-11-24 08:42:05.467013 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-11-24 08:42:05.467020 | controller | Monday 24 November 2025  08:42:05 +0000 (0:00:00.193)       0:00:17.716 *******
2025-11-24 08:42:05.467029 | controller | ok: [instance]
2025-11-24 08:42:05.494886 | controller |
2025-11-24 08:42:05.494904 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-11-24 08:42:05.494911 | controller | Monday 24 November 2025  08:42:05 +0000 (0:00:00.027)       0:00:17.744 *******
2025-11-24 08:42:05.494920 | controller | ok: [instance] => changed=false
2025-11-24 08:42:05.532774 | controller |   msg: All assertions passed
2025-11-24 08:42:05.532795 | controller |
2025-11-24 08:42:05.532803 | controller | TASK [Direct hooks] ************************************************************
2025-11-24 08:42:05.532810 | controller | Monday 24 November 2025  08:42:05 +0000 (0:00:00.027)       0:00:17.772 *******
2025-11-24 08:42:05.532820 | controller |
2025-11-24 08:42:05.592648 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-11-24 08:42:05.592674 | controller | Monday 24 November 2025  08:42:05 +0000 (0:00:00.037)       0:00:17.810 *******
2025-11-24 08:42:05.592685 | controller | ok: [instance]
2025-11-24 08:42:05.671186 | controller |
2025-11-24 08:42:05.671208 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-11-24 08:42:05.671215 | controller | Monday 24 November 2025  08:42:05 +0000 (0:00:00.059)       0:00:17.870 *******
2025-11-24 08:42:05.671224 | controller | ok: [instance]
2025-11-24 08:42:05.671453 | controller |
2025-11-24 08:42:05.671482 | controller | TASK [run_hook : Loop on hooks for no_hook] ************************************
2025-11-24 08:42:05.769228 | controller | Monday 24 November 2025  08:42:05 +0000 (0:00:00.078)       0:00:17.948 *******
2025-11-24 08:42:05.769267 | 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-11-24 08:42:05.818664 | controller |
2025-11-24 08:42:05.818693 | controller | TASK [run_hook : Set playbook path for Dummy-5] ********************************
2025-11-24 08:42:05.818700 | controller | Monday 24 November 2025  08:42:05 +0000 (0:00:00.097)       0:00:18.046 *******
2025-11-24 08:42:05.818709 | controller | ok: [instance]
2025-11-24 08:42:06.011138 | controller |
2025-11-24 08:42:06.011168 | controller | TASK [run_hook : Get file stat] ************************************************
2025-11-24 08:42:06.011176 | controller | Monday 24 November 2025  08:42:05 +0000 (0:00:00.049)       0:00:18.095 *******
2025-11-24 08:42:06.011186 | controller | ok: [instance]
2025-11-24 08:42:06.030248 | controller |
2025-11-24 08:42:06.030292 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-11-24 08:42:06.030301 | controller | Monday 24 November 2025  08:42:06 +0000 (0:00:00.192)       0:00:18.288 *******
2025-11-24 08:42:06.030311 | controller | skipping: [instance]
2025-11-24 08:42:06.030329 | controller |
2025-11-24 08:42:06.030337 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-11-24 08:42:06.030434 | controller | Monday 24 November 2025  08:42:06 +0000 (0:00:00.019)       0:00:18.307 *******
2025-11-24 08:42:06.220899 | controller | ok: [instance]
2025-11-24 08:42:06.240807 | controller |
2025-11-24 08:42:06.240832 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-11-24 08:42:06.240840 | controller | Monday 24 November 2025  08:42:06 +0000 (0:00:00.190)       0:00:18.498 *******
2025-11-24 08:42:06.240850 | controller | ok: [instance]
2025-11-24 08:42:06.438857 | controller |
2025-11-24 08:42:06.438888 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-11-24 08:42:06.438896 | controller | Monday 24 November 2025  08:42:06 +0000 (0:00:00.020)       0:00:18.518 *******
2025-11-24 08:42:06.438906 | controller | ok: [instance]
2025-11-24 08:42:06.622203 | controller |
2025-11-24 08:42:06.622232 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-11-24 08:42:06.622240 | controller | Monday 24 November 2025  08:42:06 +0000 (0:00:00.197)       0:00:18.716 *******
2025-11-24 08:42:06.622250 | controller | ok: [instance]
2025-11-24 08:42:06.622273 | controller |
2025-11-24 08:42:06.622454 | controller | TASK [run_hook : Run hook without retry - Dummy-5] *****************************
2025-11-24 08:42:08.517957 | controller | Monday 24 November 2025  08:42:06 +0000 (0:00:00.183)       0:00:18.899 *******
2025-11-24 08:42:08.517994 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_006_run_hook_without_retry_dummy.log
2025-11-24 08:42:08.547216 | controller | changed: [instance]
2025-11-24 08:42:08.547249 | controller |
2025-11-24 08:42:08.547258 | controller | TASK [run_hook : Run hook with retry - Dummy-5] ********************************
2025-11-24 08:42:08.547266 | controller | Monday 24 November 2025  08:42:08 +0000 (0:00:01.895)       0:00:20.795 *******
2025-11-24 08:42:08.547277 | controller | skipping: [instance]
2025-11-24 08:42:08.547495 | controller |
2025-11-24 08:42:08.547517 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-11-24 08:42:08.729986 | controller | Monday 24 November 2025  08:42:08 +0000 (0:00:00.029)       0:00:20.824 *******
2025-11-24 08:42:08.730019 | controller | ok: [instance]
2025-11-24 08:42:08.756673 | controller |
2025-11-24 08:42:08.756697 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-11-24 08:42:08.756705 | controller | Monday 24 November 2025  08:42:08 +0000 (0:00:00.182)       0:00:21.007 *******
2025-11-24 08:42:08.756715 | controller | ok: [instance]
2025-11-24 08:42:08.781186 | controller |
2025-11-24 08:42:08.781210 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-11-24 08:42:08.781218 | controller | Monday 24 November 2025  08:42:08 +0000 (0:00:00.026)       0:00:21.034 *******
2025-11-24 08:42:08.781227 | controller | ok: [instance] => changed=false
2025-11-24 08:42:08.781249 | controller |   msg: All assertions passed
2025-11-24 08:42:08.781256 | controller |
2025-11-24 08:42:08.781450 | controller | TASK [Direct hooks as param] ***************************************************
2025-11-24 08:42:08.820438 | controller | Monday 24 November 2025  08:42:08 +0000 (0:00:00.024)       0:00:21.058 *******
2025-11-24 08:42:08.820485 | controller |
2025-11-24 08:42:08.895404 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-11-24 08:42:08.895431 | controller | Monday 24 November 2025  08:42:08 +0000 (0:00:00.039)       0:00:21.097 *******
2025-11-24 08:42:08.895442 | controller | ok: [instance]
2025-11-24 08:42:08.986277 | controller |
2025-11-24 08:42:08.986306 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-11-24 08:42:08.986314 | controller | Monday 24 November 2025  08:42:08 +0000 (0:00:00.074)       0:00:21.172 *******
2025-11-24 08:42:08.986325 | controller | ok: [instance]
2025-11-24 08:42:09.098981 | controller |
2025-11-24 08:42:09.099011 | controller | TASK [run_hook : Loop on hooks for no_hook] ************************************
2025-11-24 08:42:09.099019 | controller | Monday 24 November 2025  08:42:08 +0000 (0:00:00.090)       0:00:21.263 *******
2025-11-24 08:42:09.099034 | 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-11-24 08:42:09.161929 | controller |
2025-11-24 08:42:09.161960 | controller | TASK [run_hook : Set playbook path for Hook as param] **************************
2025-11-24 08:42:09.161967 | controller | Monday 24 November 2025  08:42:09 +0000 (0:00:00.112)       0:00:21.376 *******
2025-11-24 08:42:09.161978 | controller | ok: [instance]
2025-11-24 08:42:09.346961 | controller |
2025-11-24 08:42:09.346990 | controller | TASK [run_hook : Get file stat] ************************************************
2025-11-24 08:42:09.346998 | controller | Monday 24 November 2025  08:42:09 +0000 (0:00:00.063)       0:00:21.439 *******
2025-11-24 08:42:09.347008 | controller | ok: [instance]
2025-11-24 08:42:09.364206 | controller |
2025-11-24 08:42:09.364239 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-11-24 08:42:09.364247 | controller | Monday 24 November 2025  08:42:09 +0000 (0:00:00.184)       0:00:21.624 *******
2025-11-24 08:42:09.364258 | controller | skipping: [instance]
2025-11-24 08:42:09.552370 | controller |
2025-11-24 08:42:09.552399 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-11-24 08:42:09.552407 | controller | Monday 24 November 2025  08:42:09 +0000 (0:00:00.017)       0:00:21.641 *******
2025-11-24 08:42:09.552417 | controller | ok: [instance]
2025-11-24 08:42:09.571974 | controller |
2025-11-24 08:42:09.572000 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-11-24 08:42:09.572007 | controller | Monday 24 November 2025  08:42:09 +0000 (0:00:00.188)       0:00:21.829 *******
2025-11-24 08:42:09.572017 | controller | ok: [instance]
2025-11-24 08:42:09.759187 | controller |
2025-11-24 08:42:09.759216 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-11-24 08:42:09.759224 | controller | Monday 24 November 2025  08:42:09 +0000 (0:00:00.019)       0:00:21.849 *******
2025-11-24 08:42:09.759235 | controller | ok: [instance]
2025-11-24 08:42:09.942343 | controller |
2025-11-24 08:42:09.942373 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-11-24 08:42:09.942381 | controller | Monday 24 November 2025  08:42:09 +0000 (0:00:00.187)       0:00:22.036 *******
2025-11-24 08:42:09.942391 | controller | ok: [instance]
2025-11-24 08:42:11.855446 | controller |
2025-11-24 08:42:11.855488 | controller | TASK [run_hook : Run hook without retry - Hook as param] ***********************
2025-11-24 08:42:11.855497 | controller | Monday 24 November 2025  08:42:09 +0000 (0:00:00.182)       0:00:22.219 *******
2025-11-24 08:42:11.855507 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_007_run_hook_without_retry_hook.log
2025-11-24 08:42:11.886221 | controller | changed: [instance]
2025-11-24 08:42:11.886241 | controller |
2025-11-24 08:42:11.886249 | controller | TASK [run_hook : Run hook with retry - Hook as param] **************************
2025-11-24 08:42:11.886255 | controller | Monday 24 November 2025  08:42:11 +0000 (0:00:01.913)       0:00:24.132 *******
2025-11-24 08:42:11.886264 | controller | skipping: [instance]
2025-11-24 08:42:11.886287 | controller |
2025-11-24 08:42:11.886549 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-11-24 08:42:12.074553 | controller | Monday 24 November 2025  08:42:11 +0000 (0:00:00.031)       0:00:24.163 *******
2025-11-24 08:42:12.074591 | controller | ok: [instance]
2025-11-24 08:42:12.102216 | controller |
2025-11-24 08:42:12.102235 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-11-24 08:42:12.102243 | controller | Monday 24 November 2025  08:42:12 +0000 (0:00:00.187)       0:00:24.351 *******
2025-11-24 08:42:12.102251 | controller | ok: [instance]
2025-11-24 08:42:12.129173 | controller |
2025-11-24 08:42:12.129190 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-11-24 08:42:12.129198 | controller | Monday 24 November 2025  08:42:12 +0000 (0:00:00.027)       0:00:24.379 *******
2025-11-24 08:42:12.129206 | controller | ok: [instance] => changed=false
2025-11-24 08:42:12.165680 | controller |   msg: All assertions passed
2025-11-24 08:42:12.165697 | controller |
2025-11-24 08:42:12.165705 | controller | TASK [Ensure we have the test_list variable now] *******************************
2025-11-24 08:42:12.165715 | controller | Monday 24 November 2025  08:42:12 +0000 (0:00:00.026)       0:00:24.406 *******
2025-11-24 08:42:12.165724 | controller | ok: [instance] => changed=false
2025-11-24 08:42:12.192085 | controller |   msg: All assertions passed
2025-11-24 08:42:12.192101 | controller |
2025-11-24 08:42:12.192108 | controller | TASK [Run hook with retry] *****************************************************
2025-11-24 08:42:12.192132 | controller | Monday 24 November 2025  08:42:12 +0000 (0:00:00.036)       0:00:24.443 *******
2025-11-24 08:42:12.192141 | controller |
2025-11-24 08:42:12.249964 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-11-24 08:42:12.249981 | controller | Monday 24 November 2025  08:42:12 +0000 (0:00:00.026)       0:00:24.469 *******
2025-11-24 08:42:12.249991 | controller | ok: [instance]
2025-11-24 08:42:12.329135 | controller |
2025-11-24 08:42:12.329170 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-11-24 08:42:12.329178 | controller | Monday 24 November 2025  08:42:12 +0000 (0:00:00.057)       0:00:24.527 *******
2025-11-24 08:42:12.329188 | controller | ok: [instance]
2025-11-24 08:42:12.329345 | controller |
2025-11-24 08:42:12.329522 | controller | TASK [run_hook : Loop on hooks for retry_hook] *********************************
2025-11-24 08:42:12.329666 | controller | Monday 24 November 2025  08:42:12 +0000 (0:00:00.079)       0:00:24.606 *******
2025-11-24 08:42:12.425002 | 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-11-24 08:42:12.425202 | controller |
2025-11-24 08:42:12.425354 | controller | TASK [run_hook : Set playbook path for Run hook with retry] ********************
2025-11-24 08:42:12.425517 | controller | Monday 24 November 2025  08:42:12 +0000 (0:00:00.095)       0:00:24.702 *******
2025-11-24 08:42:12.474418 | controller | ok: [instance]
2025-11-24 08:42:12.474632 | controller |
2025-11-24 08:42:12.474808 | controller | TASK [run_hook : Get file stat] ************************************************
2025-11-24 08:42:12.474979 | controller | Monday 24 November 2025  08:42:12 +0000 (0:00:00.049)       0:00:24.752 *******
2025-11-24 08:42:12.668574 | controller | ok: [instance]
2025-11-24 08:42:12.685993 | controller |
2025-11-24 08:42:12.686021 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-11-24 08:42:12.686030 | controller | Monday 24 November 2025  08:42:12 +0000 (0:00:00.193)       0:00:24.945 *******
2025-11-24 08:42:12.686041 | controller | skipping: [instance]
2025-11-24 08:42:12.873870 | controller |
2025-11-24 08:42:12.873898 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-11-24 08:42:12.873906 | controller | Monday 24 November 2025  08:42:12 +0000 (0:00:00.017)       0:00:24.963 *******
2025-11-24 08:42:12.873917 | controller | ok: [instance]
2025-11-24 08:42:12.892223 | controller |
2025-11-24 08:42:12.892259 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-11-24 08:42:12.892269 | controller | Monday 24 November 2025  08:42:12 +0000 (0:00:00.187)       0:00:25.151 *******
2025-11-24 08:42:12.892281 | controller | ok: [instance]
2025-11-24 08:42:12.892309 | controller |
2025-11-24 08:42:12.892319 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-11-24 08:42:12.892417 | controller | Monday 24 November 2025  08:42:12 +0000 (0:00:00.018)       0:00:25.169 *******
2025-11-24 08:42:13.083302 | controller | ok: [instance]
2025-11-24 08:42:13.264864 | controller |
2025-11-24 08:42:13.264894 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-11-24 08:42:13.264902 | controller | Monday 24 November 2025  08:42:13 +0000 (0:00:00.190)       0:00:25.360 *******
2025-11-24 08:42:13.264912 | controller | ok: [instance]
2025-11-24 08:42:15.118438 | controller |
2025-11-24 08:42:15.118468 | controller | TASK [run_hook : Run hook without retry - Run hook with retry] *****************
2025-11-24 08:42:15.118502 | controller | Monday 24 November 2025  08:42:13 +0000 (0:00:00.181)       0:00:25.542 *******
2025-11-24 08:42:15.118512 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_008_run_hook_without_retry_run.log
2025-11-24 08:42:15.148187 | controller | changed: [instance]
2025-11-24 08:42:15.148212 | controller |
2025-11-24 08:42:15.148219 | controller | TASK [run_hook : Run hook with retry - Run hook with retry] ********************
2025-11-24 08:42:15.148226 | controller | Monday 24 November 2025  08:42:15 +0000 (0:00:01.853)       0:00:27.395 *******
2025-11-24 08:42:15.148236 | controller | skipping: [instance]
2025-11-24 08:42:15.148334 | controller |
2025-11-24 08:42:15.148348 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-11-24 08:42:15.148358 | controller | Monday 24 November 2025  08:42:15 +0000 (0:00:00.030)       0:00:27.425 *******
2025-11-24 08:42:15.320597 | controller | ok: [instance]
2025-11-24 08:42:15.342684 | controller |
2025-11-24 08:42:15.342706 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-11-24 08:42:15.342714 | controller | Monday 24 November 2025  08:42:15 +0000 (0:00:00.172)       0:00:27.597 *******
2025-11-24 08:42:15.342729 | controller | skipping: [instance]
2025-11-24 08:42:15.524097 | controller |
2025-11-24 08:42:15.524141 | controller | TASK [Check if fake file exists for retry playbook] ****************************
2025-11-24 08:42:15.524150 | controller | Monday 24 November 2025  08:42:15 +0000 (0:00:00.022)       0:00:27.620 *******
2025-11-24 08:42:15.524160 | controller | ok: [instance]
2025-11-24 08:42:15.544782 | controller |
2025-11-24 08:42:15.544808 | controller | TASK [Ensure file exists and was created on retry] *****************************
2025-11-24 08:42:15.544816 | controller | Monday 24 November 2025  08:42:15 +0000 (0:00:00.181)       0:00:27.801 *******
2025-11-24 08:42:15.544828 | controller | ok: [instance] => changed=false
2025-11-24 08:42:15.736528 | controller |   msg: All assertions passed
2025-11-24 08:42:15.736561 | controller |
2025-11-24 08:42:15.736569 | controller | TASK [Remove generated file] ***************************************************
2025-11-24 08:42:15.736575 | controller | Monday 24 November 2025  08:42:15 +0000 (0:00:00.020)       0:00:27.822 *******
2025-11-24 08:42:15.736586 | controller | changed: [instance]
2025-11-24 08:42:15.799070 | controller |
2025-11-24 08:42:15.799100 | controller | PLAY RECAP *********************************************************************
2025-11-24 08:42:15.799131 | controller | instance                   : ok=112  changed=10   unreachable=0    failed=0    skipped=22   rescued=0    ignored=0
2025-11-24 08:42:15.799144 | controller |
2025-11-24 08:42:15.799150 | controller | Monday 24 November 2025  08:42:15 +0000 (0:00:00.189)       0:00:28.011 *******
2025-11-24 08:42:15.799155 | controller | ===============================================================================
2025-11-24 08:42:15.799160 | controller | run_hook : Run hook without retry - 01 my hook -------------------------- 1.94s
2025-11-24 08:42:15.799165 | controller | run_hook : Run hook without retry - 03 single hook ---------------------- 1.94s
2025-11-24 08:42:15.799171 | controller | run_hook : Run hook without retry - Run dummy-3 ------------------------- 1.93s
2025-11-24 08:42:15.799176 | controller | run_hook : Run hook without retry - Hook as param ----------------------- 1.91s
2025-11-24 08:42:15.799181 | controller | run_hook : Run hook without retry - Dummy-5 ----------------------------- 1.90s
2025-11-24 08:42:15.799186 | controller | run_hook : Run hook without retry - Run dummy-2 ------------------------- 1.88s
2025-11-24 08:42:15.799192 | controller | run_hook : Run hook without retry - Run hook with retry ----------------- 1.85s
2025-11-24 08:42:15.799197 | controller | Gathering Facts --------------------------------------------------------- 0.79s
2025-11-24 08:42:15.799207 | controller | run_hook : Run hook without retry - 02 Re-run noop ---------------------- 0.63s
2025-11-24 08:42:15.799212 | controller | run_hook : Run hook without retry - 01 Default noop hook ---------------- 0.62s
2025-11-24 08:42:15.799218 | controller | run_hook : Get file stat ------------------------------------------------ 0.30s
2025-11-24 08:42:15.799223 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.30s
2025-11-24 08:42:15.799228 | controller | run_hook : Get parameters files ----------------------------------------- 0.29s
2025-11-24 08:42:15.799233 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.20s
2025-11-24 08:42:15.799238 | controller | run_hook : Ensure artifacts directory exists ---------------------------- 0.20s
2025-11-24 08:42:15.799244 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.20s
2025-11-24 08:42:15.799249 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.20s
2025-11-24 08:42:15.799254 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.20s
2025-11-24 08:42:15.799259 | controller | run_hook : Get parameters files ----------------------------------------- 0.19s
2025-11-24 08:42:15.799264 | controller | run_hook : Get file stat ------------------------------------------------ 0.19s
2025-11-24 08:42:15.799274 | controller | INFO     Running default > cleanup
2025-11-24 08:42:15.799751 | controller | WARNING  Skipping, cleanup playbook not configured.
2025-11-24 08:42:15.800366 | controller | INFO     Writing /tmp/report.html report.
2025-11-24 08:42:16.294855 | controller | changed
2025-11-24 08:42:16.317297 | 
2025-11-24 08:42:16.317353 | PLAY RECAP
2025-11-24 08:42:16.317393 | controller | ok: 4 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-11-24 08:42:16.317414 | 
2025-11-24 08:42:16.390055 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-11-24 08:42:16.390860 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-11-24 08:42:16.931386 | 
2025-11-24 08:42:16.931508 | PLAY [Run ci/playbooks/collect-logs.yml]
2025-11-24 08:42:16.952133 | 
2025-11-24 08:42:16.952214 | TASK [Filter out host if needed]
2025-11-24 08:42:16.960650 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2025-11-24 08:42:16.965034 | 
2025-11-24 08:42:16.965100 | TASK [Ensure file is present]
2025-11-24 08:42:17.268437 | controller | ok
2025-11-24 08:42:17.275112 | 
2025-11-24 08:42:17.275206 | TASK [Manage molecule report file]
2025-11-24 08:42:17.806280 | controller | changed
2025-11-24 08:42:17.812792 | 
2025-11-24 08:42:17.812881 | TASK [Check if we get ci-framework-data basedir]
2025-11-24 08:42:17.993120 | controller | ok
2025-11-24 08:42:17.998691 | 
2025-11-24 08:42:17.998770 | TASK [Create ci-framework-data log directory for zuul]
2025-11-24 08:42:18.300514 | controller | changed
2025-11-24 08:42:18.305547 | 
2025-11-24 08:42:18.305613 | TASK [Copy ci-framework interesting files]
2025-11-24 08:42:18.501915 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory
2025-11-24 08:42:18.831326 | controller | changed
2025-11-24 08:42:18.836563 | 
2025-11-24 08:42:18.836632 | TASK [Get SELinux listing]
2025-11-24 08:42:19.361984 | controller | changed
2025-11-24 08:42:19.367811 | 
2025-11-24 08:42:19.367886 | TASK [Generate log index]
2025-11-24 08:42:20.004259 | controller | changed
2025-11-24 08:42:20.008949 | 
2025-11-24 08:42:20.009013 | TASK [Get some env related data]
2025-11-24 08:42:20.538186 | controller | /home/zuul/.local/bin/ansible
2025-11-24 08:42:21.535776 | controller | changed
2025-11-24 08:42:21.540825 | 
2025-11-24 08:42:21.540887 | TASK [Generate list of logs to collect in home directory]
2025-11-24 08:42:21.832325 | controller | ok: All paths examined
2025-11-24 08:42:21.837382 | 
2025-11-24 08:42:21.837446 | LOOP [Copy logs from home directory]
2025-11-24 08:42:22.138034 | controller | changed:
2025-11-24 08:42:22.138148 | controller | {
2025-11-24 08:42:22.138176 | controller |   "atime": 1763973683.577828,
2025-11-24 08:42:22.138198 | controller |   "ctime": 1763973699.7639441,
2025-11-24 08:42:22.138217 | controller |   "dev": 64513,
2025-11-24 08:42:22.138236 | controller |   "gid": 1000,
2025-11-24 08:42:22.138253 | controller |   "gr_name": "zuul",
2025-11-24 08:42:22.138285 | controller |   "inode": 4330410,
2025-11-24 08:42:22.138304 | controller |   "isblk": false,
2025-11-24 08:42:22.138321 | controller |   "ischr": false,
2025-11-24 08:42:22.138336 | controller |   "isdir": false,
2025-11-24 08:42:22.138351 | controller |   "isfifo": false,
2025-11-24 08:42:22.138461 | controller |   "isgid": false,
2025-11-24 08:42:22.138495 | controller |   "islnk": false,
2025-11-24 08:42:22.138516 | controller |   "isreg": true,
2025-11-24 08:42:22.138533 | controller |   "issock": false,
2025-11-24 08:42:22.138559 | controller |   "isuid": false,
2025-11-24 08:42:22.138575 | controller |   "mode": "0644",
2025-11-24 08:42:22.138591 | controller |   "mtime": 1763973699.7639441,
2025-11-24 08:42:22.138606 | controller |   "nlink": 1,
2025-11-24 08:42:22.138622 | controller |   "path": "/home/zuul/ansible.log",
2025-11-24 08:42:22.138638 | controller |   "pw_name": "zuul",
2025-11-24 08:42:22.138654 | controller |   "rgrp": true,
2025-11-24 08:42:22.138668 | controller |   "roth": true,
2025-11-24 08:42:22.138682 | controller |   "rusr": true,
2025-11-24 08:42:22.138696 | controller |   "size": 6749,
2025-11-24 08:42:22.138710 | controller |   "uid": 1000,
2025-11-24 08:42:22.138724 | controller |   "wgrp": false,
2025-11-24 08:42:22.138737 | controller |   "woth": false,
2025-11-24 08:42:22.138753 | controller |   "wusr": true,
2025-11-24 08:42:22.138767 | controller |   "xgrp": false,
2025-11-24 08:42:22.138781 | controller |   "xoth": false,
2025-11-24 08:42:22.138795 | controller |   "xusr": false
2025-11-24 08:42:22.138808 | controller | }
2025-11-24 08:42:22.152162 | 
2025-11-24 08:42:22.152285 | TASK [Copy crio stats log file]
2025-11-24 08:42:22.165908 | controller | skipping: Conditional result was False
2025-11-24 08:42:22.171290 | 
2025-11-24 08:42:22.171357 | TASK [Get SELinux related data]
2025-11-24 08:42:22.370853 | controller | <no matches>
2025-11-24 08:42:22.697388 | controller | ERROR
2025-11-24 08:42:22.697662 | controller | {
2025-11-24 08:42:22.697702 | controller |   "delta": "0:00:00.009206",
2025-11-24 08:42:22.697724 | controller |   "end": "2025-11-24 08:42:22.371932",
2025-11-24 08:42:22.697749 | controller |   "msg": "non-zero return code",
2025-11-24 08:42:22.697765 | controller |   "rc": 1,
2025-11-24 08:42:22.697783 | controller |   "start": "2025-11-24 08:42:22.362726"
2025-11-24 08:42:22.697797 | controller | }
2025-11-24 08:42:22.697818 | controller | ERROR: Ignoring Errors
2025-11-24 08:42:22.703060 | 
2025-11-24 08:42:22.703130 | TASK [Create system configuration directory]
2025-11-24 08:42:22.883877 | controller | changed
2025-11-24 08:42:22.888833 | 
2025-11-24 08:42:22.888899 | TASK [Get some of the system configurations]
2025-11-24 08:42:23.413014 | controller | changed
2025-11-24 08:42:23.418324 | 
2025-11-24 08:42:23.418390 | TASK [Copy generated documentation if available]
2025-11-24 08:42:23.432212 | controller | skipping: Conditional result was False
2025-11-24 08:42:23.437766 | 
2025-11-24 08:42:23.437836 | TASK [Copy generated AsciiDoc documentation if available]
2025-11-24 08:42:23.461494 | controller | skipping: Conditional result was False
2025-11-24 08:42:23.467627 | 
2025-11-24 08:42:23.467699 | TASK [Compress logs bigger than 2MB]
2025-11-24 08:42:23.992308 | controller | changed
2025-11-24 08:42:23.998714 | 
2025-11-24 08:42:23.998794 | TASK [Copy files from workspace on node]
2025-11-24 08:42:24.017326 | controller | ok
2025-11-24 08:42:24.042037 | 
2025-11-24 08:42:24.042134 | TASK [fetch-output : Set log path for multiple nodes]
2025-11-24 08:42:24.055656 | controller | skipping: Conditional result was False
2025-11-24 08:42:24.062652 | 
2025-11-24 08:42:24.062725 | TASK [fetch-output : Set log path for single node]
2025-11-24 08:42:24.091357 | controller | ok
2025-11-24 08:42:24.097204 | 
2025-11-24 08:42:24.097282 | LOOP [fetch-output : Ensure local output dirs]
2025-11-24 08:42:24.312391 | controller -> localhost | ok: "/var/lib/zuul/builds/a3ca31d396aa48b48ef0e4b1b9a7c8ad/work/logs"
2025-11-24 08:42:24.312615 | controller -> localhost | changed: All items complete
2025-11-24 08:42:24.312659 | 
2025-11-24 08:42:24.496048 | controller -> localhost | changed: "/var/lib/zuul/builds/a3ca31d396aa48b48ef0e4b1b9a7c8ad/work/artifacts"
2025-11-24 08:42:24.681284 | controller -> localhost | changed: "/var/lib/zuul/builds/a3ca31d396aa48b48ef0e4b1b9a7c8ad/work/docs"
2025-11-24 08:42:24.697654 | 
2025-11-24 08:42:24.697760 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-11-24 08:42:25.245225 | controller | changed:
2025-11-24 08:42:25.245413 | controller | .d..t...... ./
2025-11-24 08:42:25.245447 | controller | >f+++++++++ README.html
2025-11-24 08:42:25.245470 | controller | >f+++++++++ ansible-execution.log
2025-11-24 08:42:25.245491 | controller | >f+++++++++ ansible.log
2025-11-24 08:42:25.245510 | controller | >f+++++++++ dmesg.log
2025-11-24 08:42:25.245528 | controller | >f+++++++++ installed-pkgs.log
2025-11-24 08:42:25.245550 | controller | >f+++++++++ python.log
2025-11-24 08:42:25.245571 | controller | >f+++++++++ registries.conf
2025-11-24 08:42:25.245588 | controller | >f+++++++++ report.html
2025-11-24 08:42:25.245607 | controller | >f+++++++++ selinux-denials.log
2025-11-24 08:42:25.245623 | controller | >f+++++++++ selinux-listing.log
2025-11-24 08:42:25.245640 | controller | cd+++++++++ ci-framework-data/
2025-11-24 08:42:25.245656 | controller | cd+++++++++ ci-framework-data/artifacts/
2025-11-24 08:42:25.245671 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_000_run_hook_without_retry_01.sh
2025-11-24 08:42:25.245687 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_001_run_hook_without_retry_02_re.sh
2025-11-24 08:42:25.245703 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_002_run_hook_without_retry_03.sh
2025-11-24 08:42:25.245724 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_003_run_hook_without_retry_run.sh
2025-11-24 08:42:25.245742 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_004_run_hook_without_retry_run.sh
2025-11-24 08:42:25.245757 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_005_run_hook_without_retry_01_my.sh
2025-11-24 08:42:25.245772 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_006_run_hook_without_retry_dummy.sh
2025-11-24 08:42:25.245787 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_007_run_hook_without_retry_hook.sh
2025-11-24 08:42:25.245801 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_008_run_hook_without_retry_run.sh
2025-11-24 08:42:25.245816 | controller | >f+++++++++ ci-framework-data/artifacts/filtered_hooks_01_my_hook.yml
2025-11-24 08:42:25.245831 | controller | >f+++++++++ ci-framework-data/artifacts/list_hooks_run_dummy-2.yml
2025-11-24 08:42:25.245846 | controller | >f+++++++++ ci-framework-data/artifacts/list_hooks_run_dummy-3.yml
2025-11-24 08:42:25.245861 | controller | >f+++++++++ ci-framework-data/artifacts/no_hook_dummy-5.yml
2025-11-24 08:42:25.245876 | controller | >f+++++++++ ci-framework-data/artifacts/no_hook_hook_as_param.yml
2025-11-24 08:42:25.245891 | controller | >f+++++++++ ci-framework-data/artifacts/run_molecule_03_single_hook.yml
2025-11-24 08:42:25.245931 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2025-11-24 08:42:25.245963 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2025-11-24 08:42:25.245983 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2025-11-24 08:42:25.246001 | controller | cd+++++++++ ci-framework-data/logs/
2025-11-24 08:42:25.246017 | controller | >f+++++++++ ci-framework-data/logs/ci_script_000_run_hook_without_retry_01.log
2025-11-24 08:42:25.246033 | controller | >f+++++++++ ci-framework-data/logs/ci_script_001_run_hook_without_retry_02_re.log
2025-11-24 08:42:25.246049 | controller | >f+++++++++ ci-framework-data/logs/ci_script_002_run_hook_without_retry_03.log
2025-11-24 08:42:25.246064 | controller | >f+++++++++ ci-framework-data/logs/ci_script_003_run_hook_without_retry_run.log
2025-11-24 08:42:25.246079 | controller | >f+++++++++ ci-framework-data/logs/ci_script_004_run_hook_without_retry_run.log
2025-11-24 08:42:25.246094 | controller | >f+++++++++ ci-framework-data/logs/ci_script_005_run_hook_without_retry_01_my.log
2025-11-24 08:42:25.246109 | controller | >f+++++++++ ci-framework-data/logs/ci_script_006_run_hook_without_retry_dummy.log
2025-11-24 08:42:25.246123 | controller | >f+++++++++ ci-framework-data/logs/ci_script_007_run_hook_without_retry_hook.log
2025-11-24 08:42:25.246137 | controller | >f+++++++++ ci-framework-data/logs/ci_script_008_run_hook_without_retry_run.log
2025-11-24 08:42:25.246152 | controller | >f+++++++++ ci-framework-data/logs/filtered_hooks_01_my_hook.log
2025-11-24 08:42:25.246167 | controller | >f+++++++++ ci-framework-data/logs/list_hooks_run_dummy-2.log
2025-11-24 08:42:25.246182 | controller | >f+++++++++ ci-framework-data/logs/list_hooks_run_dummy-3.log
2025-11-24 08:42:25.246197 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2025-11-24 08:42:25.246211 | controller | >f+++++++++ ci-framework-data/logs/no_hook_dummy-5.log
2025-11-24 08:42:25.246226 | controller | >f+++++++++ ci-framework-data/logs/no_hook_hook_as_param.log
2025-11-24 08:42:25.246241 | controller | >f+++++++++ ci-framework-data/logs/retry_hook_run_hook_with_retry.log
2025-11-24 08:42:25.246256 | controller | >f+++++++++ ci-framework-data/logs/run_molecule_01_default_noop_hook.log
2025-11-24 08:42:25.246283 | controller | >f+++++++++ ci-framework-data/logs/run_molecule_02_re-run_noop.log
2025-11-24 08:42:25.246302 | controller | >f+++++++++ ci-framework-data/logs/run_molecule_03_single_hook.log
2025-11-24 08:42:25.246319 | controller | cd+++++++++ registries.conf.d/
2025-11-24 08:42:25.246335 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2025-11-24 08:42:25.246355 | controller | cd+++++++++ system-config/
2025-11-24 08:42:25.246372 | controller | cd+++++++++ system-config/libvirt/
2025-11-24 08:42:25.246388 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2025-11-24 08:42:25.246403 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2025-11-24 08:42:25.609060 | controller | changed: .d..t...... ./
2025-11-24 08:42:25.974321 | controller | changed: .d..t...... ./
2025-11-24 08:42:25.989198 | 
2025-11-24 08:42:25.989342 | TASK [Return artifact to Zuul]
2025-11-24 08:42:26.017525 | controller | ok
2025-11-24 08:42:26.037102 | 
2025-11-24 08:42:26.037162 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2025-11-24 08:42:26.037262 | 
2025-11-24 08:42:26.037304 | PLAY RECAP
2025-11-24 08:42:26.037340 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-11-24 08:42:26.037361 | 
2025-11-24 08:42:26.122177 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-11-24 08:42:26.122952 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-11-24 08:42:26.651472 | 
2025-11-24 08:42:26.651579 | PLAY [all]
2025-11-24 08:42:26.671381 | 
2025-11-24 08:42:26.671531 | TASK [include_role : fetch-output]
2025-11-24 08:42:26.700654 | controller | ok
2025-11-24 08:42:26.717489 | 
2025-11-24 08:42:26.717571 | TASK [fetch-output : Set log path for multiple nodes]
2025-11-24 08:42:26.761779 | controller | skipping: Conditional result was False
2025-11-24 08:42:26.767265 | 
2025-11-24 08:42:26.767347 | TASK [fetch-output : Set log path for single node]
2025-11-24 08:42:26.795775 | controller | ok
2025-11-24 08:42:26.800867 | 
2025-11-24 08:42:26.800951 | LOOP [fetch-output : Ensure local output dirs]
2025-11-24 08:42:27.137139 | controller -> localhost | ok: "/var/lib/zuul/builds/a3ca31d396aa48b48ef0e4b1b9a7c8ad/work/logs"
2025-11-24 08:42:27.327460 | controller -> localhost | ok: "/var/lib/zuul/builds/a3ca31d396aa48b48ef0e4b1b9a7c8ad/work/artifacts"
2025-11-24 08:42:27.514031 | controller -> localhost | ok: "/var/lib/zuul/builds/a3ca31d396aa48b48ef0e4b1b9a7c8ad/work/docs"
2025-11-24 08:42:27.522005 | 
2025-11-24 08:42:27.522078 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-11-24 08:42:28.039250 | controller | ok
2025-11-24 08:42:28.039446 | controller | ok: All items complete
2025-11-24 08:42:28.039477 | 
2025-11-24 08:42:28.406529 | controller | ok
2025-11-24 08:42:28.763685 | controller | ok
2025-11-24 08:42:28.783319 | 
2025-11-24 08:42:28.783425 | TASK [include_role : fetch-output-openshift]
2025-11-24 08:42:28.796778 | controller | skipping: Conditional result was False
2025-11-24 08:42:28.802457 | 
2025-11-24 08:42:28.802526 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-11-24 08:42:29.157156 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.006520
2025-11-24 08:42:29.353373 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.006614
2025-11-24 08:42:29.387131 | 
2025-11-24 08:42:29.387256 | PLAY [all]
2025-11-24 08:42:29.400947 | 
2025-11-24 08:42:29.401016 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-11-24 08:42:29.794905 | controller | changed
2025-11-24 08:42:29.816765 | 
2025-11-24 08:42:29.816834 | PLAY RECAP
2025-11-24 08:42:29.816882 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-11-24 08:42:29.816924 | 
2025-11-24 08:42:29.889366 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-11-24 08:42:29.890137 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-11-24 08:42:30.436539 | 
2025-11-24 08:42:30.436646 | PLAY [localhost]
2025-11-24 08:42:30.454145 | 
2025-11-24 08:42:30.454233 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-11-24 08:42:30.765663 | localhost | changed
2025-11-24 08:42:30.770185 | 
2025-11-24 08:42:30.770266 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-11-24 08:42:30.787543 | localhost | ok
2025-11-24 08:42:30.795348 | 
2025-11-24 08:42:30.795422 | TASK [add-fileserver : Create SSH private key tempfile]
2025-11-24 08:42:31.095717 | localhost | changed
2025-11-24 08:42:31.101172 | 
2025-11-24 08:42:31.101244 | TASK [add-fileserver : Create SSH private key from secret]
2025-11-24 08:42:31.654607 | localhost | changed
2025-11-24 08:42:31.659756 | 
2025-11-24 08:42:31.659825 | TASK [add-fileserver : Add fileserver ssh key]
2025-11-24 08:42:32.001158 | localhost | Identity added: /var/lib/zuul/builds/a3ca31d396aa48b48ef0e4b1b9a7c8ad/work/tmp/ansible.2drl6hp9 (/var/lib/zuul/builds/a3ca31d396aa48b48ef0e4b1b9a7c8ad/work/tmp/ansible.2drl6hp9)
2025-11-24 08:42:32.001330 | localhost | ok: Runtime: 0:00:00.005953
2025-11-24 08:42:32.005704 | 
2025-11-24 08:42:32.005774 | TASK [add-fileserver : Remove SSH private key from disk]
2025-11-24 08:42:32.226700 | localhost | ok: Runtime: 0:00:00.004102
2025-11-24 08:42:32.231477 | 
2025-11-24 08:42:32.231550 | TASK [add-fileserver : Add fileserver to inventory]
2025-11-24 08:42:32.279589 | localhost | changed
2025-11-24 08:42:32.285003 | 
2025-11-24 08:42:32.285076 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-11-24 08:42:32.608177 | localhost | changed
2025-11-24 08:42:32.628401 | 
2025-11-24 08:42:32.628510 | PLAY [localhost]
2025-11-24 08:42:32.640266 | 
2025-11-24 08:42:32.640351 | TASK [Generate bulk log download script]
2025-11-24 08:42:32.658999 | localhost | ok
2025-11-24 08:42:32.671019 | 
2025-11-24 08:42:32.671108 | TASK [local-log-download : Check API endpoint is defined]
2025-11-24 08:42:32.698812 | localhost | ok: All assertions passed
2025-11-24 08:42:32.703214 | 
2025-11-24 08:42:32.703297 | TASK [local-log-download : Create download script]
2025-11-24 08:42:33.062656 | localhost -> localhost | changed
2025-11-24 08:42:33.073639 | 
2025-11-24 08:42:33.073786 | TASK [Register quick-download link]
2025-11-24 08:42:33.095949 | localhost | ok
2025-11-24 08:42:33.153605 | 
2025-11-24 08:42:33.153758 | PLAY [logserver.rdoproject.org]
2025-11-24 08:42:33.164365 | 
2025-11-24 08:42:33.164432 | TASK [Set zuul-log-path fact]
2025-11-24 08:42:33.184763 | logserver.rdoproject.org | ok
2025-11-24 08:42:33.195128 | 
2025-11-24 08:42:33.195201 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-24 08:42:33.224450 | logserver.rdoproject.org | ok
2025-11-24 08:42:33.230843 | 
2025-11-24 08:42:33.230945 | TASK [upload-logs : Create log directories]
2025-11-24 08:42:35.799935 | logserver.rdoproject.org | changed
2025-11-24 08:42:35.802954 | 
2025-11-24 08:42:35.803019 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-11-24 08:42:36.041354 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.004795
2025-11-24 08:42:36.046157 | 
2025-11-24 08:42:36.046229 | TASK [upload-logs : Upload logs to log server]
2025-11-24 08:42:37.543734 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-11-24 08:42:37.546647 | 
2025-11-24 08:42:37.546714 | LOOP [upload-logs : Compress console log and json output]
2025-11-24 08:42:37.591761 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-24 08:42:37.600881 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-24 08:42:37.606158 | 
2025-11-24 08:42:37.606259 | LOOP [upload-logs : Upload compressed console log and json output]
2025-11-24 08:42:37.646651 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-24 08:42:37.646941 | 
2025-11-24 08:42:37.650141 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-24 08:42:37.655053 | 
2025-11-24 08:42:37.655172 | LOOP [upload-logs : Upload console log and json output]