2025-10-14 07:37:46.869558 | Job console starting...
2025-10-14 07:37:47.109277 | Updating repositories
2025-10-14 07:37:47.139454 | Preparing job workspace
2025-10-14 07:37:55.522697 | Running Ansible setup...
2025-10-14 07:37:58.518973 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-14 07:37:59.065750 | 
2025-10-14 07:37:59.065861 | PLAY [localhost]
2025-10-14 07:37:59.074709 | 
2025-10-14 07:37:59.074784 | TASK [Gathering Facts]
2025-10-14 07:37:59.941622 | localhost | ok
2025-10-14 07:37:59.954709 | 
2025-10-14 07:37:59.954819 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-14 07:38:00.313353 | localhost -> localhost | changed
2025-10-14 07:38:00.319236 | 
2025-10-14 07:38:00.319313 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-14 07:38:01.117542 | localhost -> localhost | changed
2025-10-14 07:38:01.125878 | 
2025-10-14 07:38:01.125981 | TASK [Setup log path fact]
2025-10-14 07:38:01.145810 | localhost | ok
2025-10-14 07:38:01.157267 | 
2025-10-14 07:38:01.157360 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-14 07:38:01.185394 | localhost | ok
2025-10-14 07:38:01.193093 | 
2025-10-14 07:38:01.193285 | TASK [emit-job-header : Print job information]
2025-10-14 07:38:01.221605 | # Job Information
2025-10-14 07:38:01.221827 | Ansible Version: 2.15.12
2025-10-14 07:38:01.221866 | Job: cifmw-molecule-run_hook
2025-10-14 07:38:01.221890 | Pipeline: github-check
2025-10-14 07:38:01.221936 | Executor: ibm-bm4-ze.softwarefactory-project.io
2025-10-14 07:38:01.221960 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3237
2025-10-14 07:38:01.221981 | Log URL (when completed): https://logserver.rdoproject.org/0c9/rdoproject.org/0c9d90ba401a4223bf75da6be8e2f3c6/
2025-10-14 07:38:01.222001 | Event ID: 345da600-a8cd-11f0-86c5-939673711c42
2025-10-14 07:38:01.226850 | 
2025-10-14 07:38:01.226950 | LOOP [emit-job-header : Print node information]
2025-10-14 07:38:01.328475 | localhost | ok:
2025-10-14 07:38:01.328672 | localhost | # Node Information
2025-10-14 07:38:01.328706 | localhost | Inventory Hostname: controller
2025-10-14 07:38:01.328734 | localhost | Hostname: np0005487116
2025-10-14 07:38:01.328756 | localhost | Username: zuul
2025-10-14 07:38:01.328778 | localhost | Distro: CentOS 9
2025-10-14 07:38:01.328797 | localhost | Provider: ibm-bm4-nodepool
2025-10-14 07:38:01.328815 | localhost | Region: regionOne
2025-10-14 07:38:01.328835 | localhost | Label: cloud-centos-9-stream-tripleo-ibm
2025-10-14 07:38:01.328853 | localhost | Product Name: OpenStack Compute
2025-10-14 07:38:01.328871 | localhost | Interface IP: 192.168.26.90
2025-10-14 07:38:01.352742 | 
2025-10-14 07:38:01.352830 | PLAY [all]
2025-10-14 07:38:01.359931 | 
2025-10-14 07:38:01.360006 | TASK [Gather network facts]
2025-10-14 07:38:01.739226 | controller | ok
2025-10-14 07:38:01.755097 | 
2025-10-14 07:38:01.755215 | TASK [include_role : start-zuul-console]
2025-10-14 07:38:01.773752 | controller | ok
2025-10-14 07:38:01.787263 | 
2025-10-14 07:38:01.787353 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-14 07:38:02.131480 | controller | ok
2025-10-14 07:38:02.145502 | 
2025-10-14 07:38:02.145610 | TASK [include_role : add-build-sshkey]
2025-10-14 07:38:02.175553 | controller | ok
2025-10-14 07:38:02.189884 | 
2025-10-14 07:38:02.190010 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-14 07:38:02.418208 | controller -> localhost | ok
2025-10-14 07:38:02.424327 | 
2025-10-14 07:38:02.424415 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-14 07:38:02.444072 | controller | ok
2025-10-14 07:38:02.458017 | controller | included: /var/lib/zuul/builds/0c9d90ba401a4223bf75da6be8e2f3c6/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-14 07:38:02.464435 | 
2025-10-14 07:38:02.464518 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-14 07:38:02.979970 | controller -> localhost | Generating public/private rsa key pair.
2025-10-14 07:38:02.980208 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0c9d90ba401a4223bf75da6be8e2f3c6/work/0c9d90ba401a4223bf75da6be8e2f3c6_id_rsa.
2025-10-14 07:38:02.980246 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0c9d90ba401a4223bf75da6be8e2f3c6/work/0c9d90ba401a4223bf75da6be8e2f3c6_id_rsa.pub.
2025-10-14 07:38:02.980273 | controller -> localhost | The key fingerprint is:
2025-10-14 07:38:02.980296 | controller -> localhost | SHA256:JOfVqHBin+yThz1b26ufygdMM7la1eHr7ELuadA6bn8 zuul-build-sshkey
2025-10-14 07:38:02.980318 | controller -> localhost | The key's randomart image is:
2025-10-14 07:38:02.980339 | controller -> localhost | +---[RSA 3072]----+
2025-10-14 07:38:02.980359 | controller -> localhost | |                 |
2025-10-14 07:38:02.980394 | controller -> localhost | |           o   . |
2025-10-14 07:38:02.980418 | controller -> localhost | |      = + o .....|
2025-10-14 07:38:02.980440 | controller -> localhost | |     . @ +  = ...|
2025-10-14 07:38:02.980458 | controller -> localhost | |        S  o.=  .|
2025-10-14 07:38:02.980477 | controller -> localhost | |       . + .=o . |
2025-10-14 07:38:02.980495 | controller -> localhost | |        = +o*.o  |
2025-10-14 07:38:02.980531 | controller -> localhost | |         o.O *oE |
2025-10-14 07:38:02.980552 | controller -> localhost | |          +.XOOo |
2025-10-14 07:38:02.980571 | controller -> localhost | +----[SHA256]-----+
2025-10-14 07:38:02.980615 | controller -> localhost | ok: Runtime: 0:00:00.148405
2025-10-14 07:38:02.987149 | 
2025-10-14 07:38:02.987216 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-14 07:38:03.006639 | controller | ok
2025-10-14 07:38:03.017035 | controller | included: /var/lib/zuul/builds/0c9d90ba401a4223bf75da6be8e2f3c6/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-14 07:38:03.025626 | 
2025-10-14 07:38:03.025701 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-14 07:38:03.039850 | controller | skipping: Conditional result was False
2025-10-14 07:38:03.046097 | 
2025-10-14 07:38:03.046188 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-14 07:38:03.425968 | controller | changed
2025-10-14 07:38:03.431145 | 
2025-10-14 07:38:03.431236 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-14 07:38:03.623041 | controller | ok
2025-10-14 07:38:03.628295 | 
2025-10-14 07:38:03.628384 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-14 07:38:04.224481 | controller | changed
2025-10-14 07:38:04.230204 | 
2025-10-14 07:38:04.230304 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-14 07:38:04.836669 | controller | changed
2025-10-14 07:38:04.843029 | 
2025-10-14 07:38:04.843117 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-14 07:38:04.856833 | controller | skipping: Conditional result was False
2025-10-14 07:38:04.864508 | 
2025-10-14 07:38:04.864606 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-14 07:38:05.205013 | controller -> localhost | changed
2025-10-14 07:38:05.216341 | 
2025-10-14 07:38:05.216434 | TASK [add-build-sshkey : Add back temp key]
2025-10-14 07:38:05.465310 | controller -> localhost | Identity added: /var/lib/zuul/builds/0c9d90ba401a4223bf75da6be8e2f3c6/work/0c9d90ba401a4223bf75da6be8e2f3c6_id_rsa (zuul-build-sshkey)
2025-10-14 07:38:05.465556 | controller -> localhost | ok: Runtime: 0:00:00.007964
2025-10-14 07:38:05.471747 | 
2025-10-14 07:38:05.471817 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-14 07:38:05.784278 | controller | ok
2025-10-14 07:38:05.789841 | 
2025-10-14 07:38:05.789964 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-14 07:38:05.839117 | controller | skipping: Conditional result was False
2025-10-14 07:38:05.849890 | 
2025-10-14 07:38:05.850014 | TASK [include_role : validate-host]
2025-10-14 07:38:05.901423 | controller | ok
2025-10-14 07:38:05.926502 | 
2025-10-14 07:38:05.926661 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-14 07:38:05.958321 | controller | ok
2025-10-14 07:38:05.964171 | 
2025-10-14 07:38:05.964290 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-14 07:38:06.213762 | controller -> localhost | ok
2025-10-14 07:38:06.221226 | 
2025-10-14 07:38:06.221351 | TASK [validate-host : Collect information about the host]
2025-10-14 07:38:06.814944 | controller | ok
2025-10-14 07:38:06.824412 | 
2025-10-14 07:38:06.824498 | TASK [validate-host : Sanitize hostname]
2025-10-14 07:38:06.930213 | controller | ok
2025-10-14 07:38:06.935276 | 
2025-10-14 07:38:06.935348 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-14 07:38:07.335092 | controller -> localhost | changed
2025-10-14 07:38:07.340767 | 
2025-10-14 07:38:07.340867 | TASK [validate-host : Collect information about zuul worker]
2025-10-14 07:38:07.674672 | controller | ok
2025-10-14 07:38:07.679946 | 
2025-10-14 07:38:07.680032 | TASK [validate-host : Write out all zuul information for each host]
2025-10-14 07:38:08.089605 | controller -> localhost | changed
2025-10-14 07:38:08.100184 | 
2025-10-14 07:38:08.100289 | TASK [include_role : prepare-workspace-openshift]
2025-10-14 07:38:08.114654 | controller | skipping: Conditional result was False
2025-10-14 07:38:08.120081 | 
2025-10-14 07:38:08.120179 | TASK [include_role : remove-zuul-sshkey]
2025-10-14 07:38:08.133980 | controller | skipping: Conditional result was False
2025-10-14 07:38:08.139682 | 
2025-10-14 07:38:08.139753 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-14 07:38:08.333832 | controller | ok: "logs"
2025-10-14 07:38:08.334167 | controller | ok: All items complete
2025-10-14 07:38:08.334202 | 
2025-10-14 07:38:08.500064 | controller | ok: "artifacts"
2025-10-14 07:38:08.666744 | controller | ok: "docs"
2025-10-14 07:38:08.681291 | 
2025-10-14 07:38:08.681419 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-14 07:38:08.892361 | controller | changed: "logs"
2025-10-14 07:38:09.067521 | controller | changed: "artifacts"
2025-10-14 07:38:09.236354 | controller | changed: "docs"
2025-10-14 07:38:09.264281 | 
2025-10-14 07:38:09.264421 | PLAY RECAP
2025-10-14 07:38:09.264474 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-14 07:38:09.264504 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-14 07:38:09.264525 | 
2025-10-14 07:38:09.370597 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-14 07:38:09.371380 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-10-14 07:38:10.011577 | 
2025-10-14 07:38:10.011756 | PLAY [all]
2025-10-14 07:38:10.034460 | 
2025-10-14 07:38:10.034614 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-10-14 07:38:10.094378 | controller | ok
2025-10-14 07:38:10.100332 | 
2025-10-14 07:38:10.100474 | TASK [mirror-info-fork : Create /etc/ci]
2025-10-14 07:38:10.458648 | controller | changed
2025-10-14 07:38:10.465194 | 
2025-10-14 07:38:10.465286 | TASK [mirror-info-fork : Install ci_mirror script]
2025-10-14 07:38:11.306054 | controller | changed
2025-10-14 07:38:11.317189 | 
2025-10-14 07:38:11.317277 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2025-10-14 07:38:11.699687 | controller | changed:
2025-10-14 07:38:11.700063 | controller | {
2025-10-14 07:38:11.700096 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2025-10-14 07:38:11.700159 | controller | }
2025-10-14 07:38:11.909105 | controller | changed:
2025-10-14 07:38:11.909221 | controller | {
2025-10-14 07:38:11.909251 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2025-10-14 07:38:11.909274 | controller | }
2025-10-14 07:38:12.118216 | controller | changed:
2025-10-14 07:38:12.118357 | controller | {
2025-10-14 07:38:12.118385 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com"
2025-10-14 07:38:12.118407 | controller | }
2025-10-14 07:38:12.330433 | controller | changed:
2025-10-14 07:38:12.330545 | controller | {
2025-10-14 07:38:12.330577 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2025-10-14 07:38:12.330598 | controller | }
2025-10-14 07:38:12.540207 | controller | changed:
2025-10-14 07:38:12.540296 | controller | {
2025-10-14 07:38:12.540325 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2025-10-14 07:38:12.540346 | controller | }
2025-10-14 07:38:12.741541 | controller | changed:
2025-10-14 07:38:12.741640 | controller | {
2025-10-14 07:38:12.741671 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2025-10-14 07:38:12.741694 | controller | }
2025-10-14 07:38:12.942436 | controller | changed:
2025-10-14 07:38:12.942522 | controller | {
2025-10-14 07:38:12.942549 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDLOQd4ZLtkZXQGY6UwAr/06ppWQK4fDO3HaqxPk98csyOCBXsliSKK39Bso828+5srIXiW7aI6aC9P5mwi4mUZlGPfJlQbfrcGvY+b/SocuvaGK+1RrHLoJCT52LBhwgrzlXio2jeksZeein8iaTrhsPrOAs7KggIL/rB9hEiB3NaOPWhhoCP4vlW6MEMExGcqB/1FVxXFBPnLkEyW0Lk7ycVflZl2ocRxbfjZi0+tI1Wlinp8PvSQSc/WVrAcDgKjc/mB4ODPOyYy3G8FHgfMsrXSDEyjBKgLKMsdCrAUcqJQWjkqXleXSYOV4q3pzL+9umK+q/e3P/bIoSFQzmJKTU1eDfuvPXmow9F5H54fii/Da7ezlMJ+wPGHJrRAkmzvMbALy7xwswLhZMkOGNtRcPqaKYRmIBKpw3o6bCTtcNUHOtOQnzwY8JzrM2eBWJBXAANYw+9/ho80JIiwhg29CFNpVBuHbql2YxJQNrnl90guN65rYNpDxdIluweyUf8= anbanerj@kaermorhen"
2025-10-14 07:38:12.942571 | controller | }
2025-10-14 07:38:13.152779 | controller | changed:
2025-10-14 07:38:13.152863 | controller | {
2025-10-14 07:38:13.152893 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC3VwV8Im9kRm49lt3tM36hj4Zv27FxGo4C1Q/0jqhzFmHY7RHbmeRr8ObhwWoHjXSozKWg8FL5ER0z3hTwL0W6lez3sL7hUaCmSuZmG5Hnl3x4vTSxDI9JZ/Y65rtYiiWQo2fC5xJhU/4+0e5e/pseCm8cKRSu+SaxhO+sd6FDojA2x1BzOzKiQRDy/1zWGp/cZkxcEuB1wHI5LMzN03c67vmbu+fhZRAUO4dQkvcnj2LrhQtpa+ytvnSjr8icMDosf1OsbSffwZFyHB/hfWGAfe0eIeSA2XPraxiPknXxiPKx2MJsaUTYbsZcm3EjFdHBBMumw5rBI74zLrMRvCO9GwBEmGT4rFng1nP+yw5DB8sn2zqpOsPg1LYRwCPOUveC13P6pgsZZPh812e8v5EKnETct+5XI3dVpdw6CnNiLwAyVAF15DJvBGT/u1k0Myg/bQn+Gv9k2MSj6LvQmf6WbZu2Wgjm30z3FyCneBqTL7mLF19YXzeC0ufHz5pnO1E= dasm@fedora"
2025-10-14 07:38:13.152961 | controller | }
2025-10-14 07:38:13.358359 | controller | changed:
2025-10-14 07:38:13.358464 | controller | {
2025-10-14 07:38:13.358495 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2025-10-14 07:38:13.358517 | controller | }
2025-10-14 07:38:13.571639 | controller | changed:
2025-10-14 07:38:13.571736 | controller | {
2025-10-14 07:38:13.571764 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2025-10-14 07:38:13.571786 | controller | }
2025-10-14 07:38:13.785746 | controller | changed:
2025-10-14 07:38:13.785846 | controller | {
2025-10-14 07:38:13.785876 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2025-10-14 07:38:13.785897 | controller | }
2025-10-14 07:38:14.023838 | controller | changed:
2025-10-14 07:38:14.023958 | controller | {
2025-10-14 07:38:14.023990 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2025-10-14 07:38:14.024013 | controller | }
2025-10-14 07:38:14.209206 | controller | changed:
2025-10-14 07:38:14.209301 | controller | {
2025-10-14 07:38:14.209328 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2025-10-14 07:38:14.209351 | controller | }
2025-10-14 07:38:14.417223 | controller | changed:
2025-10-14 07:38:14.417308 | controller | {
2025-10-14 07:38:14.417337 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2025-10-14 07:38:14.417357 | controller | }
2025-10-14 07:38:14.628755 | controller | changed:
2025-10-14 07:38:14.628857 | controller | {
2025-10-14 07:38:14.628887 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2025-10-14 07:38:14.628927 | controller | }
2025-10-14 07:38:14.836767 | controller | changed:
2025-10-14 07:38:14.836872 | controller | {
2025-10-14 07:38:14.836901 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2025-10-14 07:38:14.836954 | controller | }
2025-10-14 07:38:15.041589 | controller | changed:
2025-10-14 07:38:15.041704 | controller | {
2025-10-14 07:38:15.041730 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQCfNtF7NvKl915TGsGGoseUb06Hj8L/S4toWf0hExeY+F00woL6NvBlJD0nDct+P5a22I4EhvoQCRQ8reaPCm1lybR3uiRIJsj+8zkVvLwby9LXzfZorlNG9ofjd00FEmB09uW/YvTl6Q9XwwwX6tInzIOv3TMqTHHGOL74ibbj8J/FJR0cFEyj0z4WQRvtkh32xAHl83gbuINryMt0sqRI+clj2381NKL55DRLQrVw0gsfqqxiHAnXg21qWmc4J+b9e9kiuAFQjcjwTVkwJCcg3xbPwC/qokYRby/Y5S40UUd7/jEARGXT7RZgpzTuDd1oZiCVrnrqJNPaMNdVv5MLeFdf1B7iIe5aa/fGouX7AO4SdKhZUdnJmCFAGvjC6S3JMZ2wAcUl+OHnssfmdj7XL50cLo27vjuzMtLAgSqi6N99m92WCF2s8J9aVzszX7Xz9OKZCeGsiVJp3/NdABKzSEAyM9xBD/5Vho894Sav+otpySHe3p6RUTgbB5Zu8VyZRZ/UtB3ueXxyo764yrc6qWIDqrehm84Xm9g+/jpIBzGPl07NUNJpdt/6Sgf9RIKXw/7XypO5yZfUcuFNGTxLfqjTNrtgLZNcjfav6sSdVXVcMPL//XNuRdKmVFaO76eV/oGMQGr1fGcCD+N+CpI7+Q+fCNB6VFWG4nZFuI/Iuw== averdagu@redhat.com"
2025-10-14 07:38:15.041752 | controller | }
2025-10-14 07:38:15.260013 | controller | changed:
2025-10-14 07:38:15.260222 | controller | {
2025-10-14 07:38:15.260375 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDq8l27xI+QlQVdS4djp9ogSoyrNE2+Ox6vKPdhSNL1J3PE5w+WCSvMz9A5gnNuH810zwbekEApbxTze/gLQJwBHA52CChfURpXrFaxY7ePXRElwKAL3mJfzBWY/c5jnNL9TCVmFJTGZkFZP3Nh+BMgZvL6xBkt3WKm6Uq18qzd9XeKcZusrA+O+uLv1fVeQnadY9RIqOCyeFYCzLWrUfTyE8x/XG0hAWIM7qpnF2cALQS2h9n4hW5ybiUN790H08wf9hFwEf5nxY9Z9dVkPFQiTSGKNBzmnCXU9skxS/xhpFjJ5duGSZdtAHe9O+nGZm9c67hxgtf8e5PDuqAdXEv2cf6e3VBAt+Bz8EKI3yosTj0oZHfwr42Yzb1l/SKy14Rggsrc9KAQlrGXan6+u2jcQqqx7l+SWmnpFiWTV9u5cWj2IgOhApOitmRBPYqk9rE2usfO0hLn/Pj/R/Nau4803e1/EikdLE7Ps95s9mX5jRDjAoUa2JwFF5RsVFyL910= ashigupt@ashigupt.remote.csb"
2025-10-14 07:38:15.260415 | controller | }
2025-10-14 07:38:15.468008 | controller | changed:
2025-10-14 07:38:15.468114 | controller | {
2025-10-14 07:38:15.468163 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2025-10-14 07:38:15.468184 | controller | }
2025-10-14 07:38:15.681625 | controller | changed:
2025-10-14 07:38:15.681719 | controller | {
2025-10-14 07:38:15.681749 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2025-10-14 07:38:15.681769 | controller | }
2025-10-14 07:38:15.888521 | controller | changed:
2025-10-14 07:38:15.888597 | controller | {
2025-10-14 07:38:15.888624 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2025-10-14 07:38:15.888645 | controller | }
2025-10-14 07:38:16.092957 | controller | changed:
2025-10-14 07:38:16.093112 | controller | {
2025-10-14 07:38:16.093177 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2025-10-14 07:38:16.093200 | controller | }
2025-10-14 07:38:16.303698 | controller | changed:
2025-10-14 07:38:16.303788 | controller | {
2025-10-14 07:38:16.303815 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQDZdI7t1cxYx65heVI24HTV4F7oQLW1zyfxHreL2TIJKxjyrUUKIFEUmTutcBlJRLNT2Eoix6x1sOw9YrchloCLcn//SGfTElr9mSc5jbjb7QXEU+zJMhtxyEJ1Po3CUGnj7ckiIXw7wcawZtrEOAQ9pH3ExYCJcEMiyNjRQZCxT3tPK+S4B95EWh5Fsrz9CkwpjNRPPH7LigCeQTM3Wc7r97utAslBUUvYceDSLA7rMgkitJE38b7rZBeYzsGQ8YYUBjTCtehqQXxCRjizbHWaaZkBU+N3zkKB6n/iCNGIO690NK7A/qb6msTijiz1PeuM8ThOsi9qXnbX5v0PoTpcFSojV7NHAQ71f0XXuS43FhZctT+Dcx44dT8Fb5vJu2cJGrk+qF8ZgJYNpRS7gPg0EG2EqjK7JMf9ULdjSu0r+KlqIAyLvtzT4eOnQipoKlb/WG5D/0ohKv7OMQ352ggfkBFIQsRXyyTCT98Ft9juqPuahi3CAQmP4H9dyE+7+Kz437PEtsxLmfm6naNmWi7Ee1DqWPwS8rEajsm4sNM4wW9gdBboJQtc0uZw0DfLj1I9r3Mc8Ol0jYtz0yNQDSzVLrGCaJlC311trU70tZ+ZkAVV6Mn8lOhSbj1cK0lvSr6ZK4dgqGl3I1eTZJJhbLNdg7UOVaiRx9543+C/p/As7w== brjackma@redhat.com"
2025-10-14 07:38:16.303836 | controller | }
2025-10-14 07:38:16.511699 | controller | changed:
2025-10-14 07:38:16.511948 | controller | {
2025-10-14 07:38:16.511990 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2025-10-14 07:38:16.512015 | controller | }
2025-10-14 07:38:16.722231 | controller | changed:
2025-10-14 07:38:16.722314 | controller | {
2025-10-14 07:38:16.722342 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2025-10-14 07:38:16.722363 | controller | }
2025-10-14 07:38:16.928811 | controller | changed:
2025-10-14 07:38:16.928977 | controller | {
2025-10-14 07:38:16.929014 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2025-10-14 07:38:16.929038 | controller | }
2025-10-14 07:38:16.954230 | 
2025-10-14 07:38:16.954316 | TASK [Set timezone to UTC]
2025-10-14 07:38:17.398785 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2025-10-14 07:38:17.405810 | 
2025-10-14 07:38:17.405899 | TASK [Create nodepool directory]
2025-10-14 07:38:17.630365 | controller | changed
2025-10-14 07:38:17.636105 | 
2025-10-14 07:38:17.636187 | TASK [Create nodepool sub_nodes file]
2025-10-14 07:38:18.156454 | controller | changed
2025-10-14 07:38:18.161467 | 
2025-10-14 07:38:18.161540 | TASK [Create nodepool sub_nodes_private file]
2025-10-14 07:38:18.725375 | controller | changed
2025-10-14 07:38:18.730280 | 
2025-10-14 07:38:18.730342 | LOOP [Populate nodepool sub_nodes file]
2025-10-14 07:38:18.759098 | 
2025-10-14 07:38:18.759261 | LOOP [Populate nodepool sub_nodes_private file]
2025-10-14 07:38:18.788025 | 
2025-10-14 07:38:18.788185 | TASK [Create nodepool primary file]
2025-10-14 07:38:18.811722 | controller | skipping: Conditional result was False
2025-10-14 07:38:18.817662 | 
2025-10-14 07:38:18.817751 | TASK [Create nodepool node_private for this node]
2025-10-14 07:38:19.364823 | controller | changed
2025-10-14 07:38:19.371820 | 
2025-10-14 07:38:19.371893 | LOOP [Copy ssh keys to nodepool directory]
2025-10-14 07:38:19.746950 | controller | ok: Item: id_rsa Runtime: 0:00:00.004856
2025-10-14 07:38:19.747121 | 
2025-10-14 07:38:19.915551 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.006431
2025-10-14 07:38:19.929793 | 
2025-10-14 07:38:19.929865 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2025-10-14 07:38:20.460204 | controller | changed
2025-10-14 07:38:20.465721 | 
2025-10-14 07:38:20.465798 | TASK [Validate sudoers config after edits]
2025-10-14 07:38:20.691396 | controller | /etc/sudoers: parsed OK
2025-10-14 07:38:20.691469 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2025-10-14 07:38:20.691480 | controller | /etc/sudoers.d/zuul: parsed OK
2025-10-14 07:38:20.691486 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2025-10-14 07:38:20.990485 | controller | ok: Runtime: 0:00:00.005077
2025-10-14 07:38:20.996352 | 
2025-10-14 07:38:20.996416 | TASK [Show the environment passed in to job shell scripts]
2025-10-14 07:38:21.210347 | controller | SHELL=/bin/bash
2025-10-14 07:38:21.210406 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2025-10-14 07:38:21.210520 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2025-10-14 07:38:21.210531 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/04/3404/9f142a3066b32ef704ae4f0d5fc5f7189e41a1f8^openstack-k8s-operators/ci-framework:main:refs/changes/37/3237/d91a18454890fd10f6c9de90caf479fc9c5b11c1
2025-10-14 07:38:21.210540 | controller | PWD=/home/zuul
2025-10-14 07:38:21.210546 | controller | ZUUL_PIPELINE=github-check
2025-10-14 07:38:21.210551 | controller | LOGNAME=zuul
2025-10-14 07:38:21.210557 | controller | XDG_SESSION_TYPE=tty
2025-10-14 07:38:21.210563 | controller | _=/usr/bin/env
2025-10-14 07:38:21.210568 | controller | MOTD_SHOWN=pam
2025-10-14 07:38:21.210574 | controller | HOME=/home/zuul
2025-10-14 07:38:21.210579 | controller | LANG=en_US.UTF-8
2025-10-14 07:38:21.210584 | controller | SSH_CONNECTION=192.168.26.12 49028 192.168.26.90 22
2025-10-14 07:38:21.210590 | controller | TOX_TESTENV_PASSENV=ZUUL_UUID ZUUL_PROJECT ZUUL_SHORT_PROJECT_NAME ZUUL_PIPELINE ZUUL_VOTING WORKSPACE BUILD_TIMEOUT ZUUL_BRANCH ZUUL_CHANGES ZUUL_CHANGE_IDS ZUUL_CHANGE ZUUL_PATCHSET
2025-10-14 07:38:21.210597 | controller | ZUUL_CHANGE_IDS=3404,9f142a3066b32ef704ae4f0d5fc5f7189e41a1f8 3237,d91a18454890fd10f6c9de90caf479fc9c5b11c1
2025-10-14 07:38:21.210603 | controller | WORKSPACE=/home/zuul/workspace
2025-10-14 07:38:21.210609 | controller | XDG_SESSION_CLASS=user
2025-10-14 07:38:21.210614 | controller | SELINUX_ROLE_REQUESTED=
2025-10-14 07:38:21.210620 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2025-10-14 07:38:21.210626 | controller | USER=zuul
2025-10-14 07:38:21.210631 | controller | ZUUL_VOTING=True
2025-10-14 07:38:21.210637 | controller | BUILD_TIMEOUT=1800000
2025-10-14 07:38:21.210642 | controller | SELINUX_USE_CURRENT_RANGE=
2025-10-14 07:38:21.210648 | controller | SHLVL=1
2025-10-14 07:38:21.210653 | controller | ZUUL_PATCHSET=d91a18454890fd10f6c9de90caf479fc9c5b11c1
2025-10-14 07:38:21.210659 | controller | XDG_SESSION_ID=1
2025-10-14 07:38:21.210664 | controller | ZUUL_BRANCH=main
2025-10-14 07:38:21.210670 | controller | XDG_RUNTIME_DIR=/run/user/1000
2025-10-14 07:38:21.210675 | controller | SSH_CLIENT=192.168.26.12 49028 22
2025-10-14 07:38:21.210681 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2025-10-14 07:38:21.210686 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2025-10-14 07:38:21.210692 | controller | which_declare=declare -f
2025-10-14 07:38:21.210698 | controller | PATH=/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2025-10-14 07:38:21.210704 | controller | SELINUX_LEVEL_REQUESTED=
2025-10-14 07:38:21.210710 | controller | ZUUL_CHANGE=3237
2025-10-14 07:38:21.210715 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2025-10-14 07:38:21.210721 | controller | ZUUL_UUID=0c9d90ba401a4223bf75da6be8e2f3c6
2025-10-14 07:38:21.210726 | controller | BASH_FUNC_which%%=() {  ( alias;
2025-10-14 07:38:21.210732 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2025-10-14 07:38:21.210737 | controller | }
2025-10-14 07:38:21.522880 | controller | ok: Runtime: 0:00:00.007472
2025-10-14 07:38:21.528633 | 
2025-10-14 07:38:21.528721 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2025-10-14 07:38:21.542150 | controller | skipping: Conditional result was False
2025-10-14 07:38:21.547760 | 
2025-10-14 07:38:21.547835 | TASK [Symlink /home/zuul-worker/workspace]
2025-10-14 07:38:22.086819 | controller | skipping: Conditional result was False
2025-10-14 07:38:22.092885 | 
2025-10-14 07:38:22.093000 | TASK [Ensure legacy workspace directory]
2025-10-14 07:38:22.296176 | controller | changed
2025-10-14 07:38:22.329470 | 
2025-10-14 07:38:22.329564 | PLAY RECAP
2025-10-14 07:38:22.329620 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-14 07:38:22.329648 | 
2025-10-14 07:38:22.426436 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-10-14 07:38:22.427256 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-10-14 07:38:23.066321 | 
2025-10-14 07:38:23.066443 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2025-10-14 07:38:23.104759 | 
2025-10-14 07:38:23.104884 | TASK [Create zuul-output directory]
2025-10-14 07:38:23.463772 | controller | changed
2025-10-14 07:38:23.469887 | 
2025-10-14 07:38:23.470025 | TASK [Slurp Zuul inventory test]
2025-10-14 07:38:23.890295 | controller -> localhost | ok
2025-10-14 07:38:23.897177 | 
2025-10-14 07:38:23.897265 | TASK [Save zuul inventory]
2025-10-14 07:38:24.658385 | controller | changed
2025-10-14 07:38:24.663408 | 
2025-10-14 07:38:24.663476 | TASK [Save zuul vars without the change_message]
2025-10-14 07:38:25.247738 | controller | changed
2025-10-14 07:38:25.268040 | 
2025-10-14 07:38:25.268130 | PLAY RECAP
2025-10-14 07:38:25.268196 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-14 07:38:25.268226 | 
2025-10-14 07:38:25.356974 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-10-14 07:38:25.358201 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-10-14 07:38:26.174829 | 
2025-10-14 07:38:26.174963 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2025-10-14 07:38:26.196868 | 
2025-10-14 07:38:26.196990 | TASK [Read group_vars]
2025-10-14 07:38:26.238221 | controller | ok
2025-10-14 07:38:26.257347 | 
2025-10-14 07:38:26.257481 | TASK [cifmw_helpers : Check directory is available]
2025-10-14 07:38:26.582305 | controller | ok
2025-10-14 07:38:26.591638 | 
2025-10-14 07:38:26.591781 | TASK [cifmw_helpers : Print var]
2025-10-14 07:38:26.621142 | controller | ok:
2025-10-14 07:38:26.621302 | controller | provide_var is /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/group_vars
2025-10-14 07:38:26.621334 | controller |  and registered one is {'changed': False, 'stat': {'exists': False}, 'failed': False}
2025-10-14 07:38:26.627000 | 
2025-10-14 07:38:26.627076 | TASK [cifmw_helpers : List dir in ansible user home]
2025-10-14 07:38:26.980280 | controller | ls: cannot access '/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/group_vars': No such file or directory
2025-10-14 07:38:26.981820 | controller | ls: cannot access '/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/group_vars': No such file or directory
2025-10-14 07:38:26.983287 | controller | ls: cannot access '/root/src/github.com/openstack-k8s-operators/ci-framework/group_vars': Permission denied
2025-10-14 07:38:26.984762 | controller | ls: cannot access '/workspace/src/github.com/openstack-k8s-operators/ci-framework/group_vars': No such file or directory
2025-10-14 07:38:27.151658 | controller | ERROR
2025-10-14 07:38:27.151834 | controller | {
2025-10-14 07:38:27.151866 | controller |   "delta": "0:00:00.009691",
2025-10-14 07:38:27.151893 | controller |   "end": "2025-10-14 07:38:26.985105",
2025-10-14 07:38:27.151948 | controller |   "msg": "non-zero return code",
2025-10-14 07:38:27.151972 | controller |   "rc": 2,
2025-10-14 07:38:27.151991 | controller |   "start": "2025-10-14 07:38:26.975414"
2025-10-14 07:38:27.152009 | controller | }
2025-10-14 07:38:27.152035 | controller | ERROR: Ignoring Errors
2025-10-14 07:38:27.157639 | 
2025-10-14 07:38:27.157716 | TASK [cifmw_helpers : Find yaml files]
2025-10-14 07:38:27.179173 | controller | skipping: Conditional result was False
2025-10-14 07:38:27.185019 | 
2025-10-14 07:38:27.185099 | TASK [cifmw_helpers : Print available yaml files]
2025-10-14 07:38:27.199485 | controller | skipping: Conditional result was False
2025-10-14 07:38:27.205799 | 
2025-10-14 07:38:27.205885 | LOOP [cifmw_helpers : Read vars]
2025-10-14 07:38:27.233886 | 
2025-10-14 07:38:27.234089 | LOOP [cifmw_helpers : Call task to parse all files as fact]
2025-10-14 07:38:27.258751 | 
2025-10-14 07:38:27.258996 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2025-10-14 07:38:27.278833 | controller | ok
2025-10-14 07:38:27.302049 | 
2025-10-14 07:38:27.302156 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-10-14 07:38:27.366564 | controller | skipping: Conditional result was False
2025-10-14 07:38:27.418333 | 
2025-10-14 07:38:27.418443 | TASK [mirror-info-fork : Create /etc/ci]
2025-10-14 07:38:27.763886 | controller | ok
2025-10-14 07:38:27.769388 | 
2025-10-14 07:38:27.769548 | TASK [mirror-info-fork : Install ci_mirror script]
2025-10-14 07:38:28.272247 | controller | ok
2025-10-14 07:38:28.286416 | 
2025-10-14 07:38:28.286509 | TASK [Prepare workspace]
2025-10-14 07:38:28.336073 | controller | ok
2025-10-14 07:38:28.377806 | 
2025-10-14 07:38:28.377939 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-14 07:38:28.690753 | controller | ok
2025-10-14 07:38:28.696624 | 
2025-10-14 07:38:28.696708 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-14 07:38:31.498290 | controller | Output suppressed because no_log was given
2025-10-14 07:38:31.518296 | 
2025-10-14 07:38:31.518408 | LOOP [Create zuul-output directory]
2025-10-14 07:38:31.705724 | controller | changed: "/home/zuul/ci-framework-data/logs"
2025-10-14 07:38:31.705990 | 
2025-10-14 07:38:31.858829 | controller | ok: "/home/zuul/zuul-output/logs"
2025-10-14 07:38:31.876565 | 
2025-10-14 07:38:31.876675 | TASK [Install required packages]
2025-10-14 07:39:37.779670 | controller | changed
2025-10-14 07:39:37.784697 | 
2025-10-14 07:39:37.784762 | TASK [Install venv]
2025-10-14 07:40:39.519786 | controller | changed
2025-10-14 07:40:39.546262 | 
2025-10-14 07:40:39.546356 | PLAY RECAP
2025-10-14 07:40:39.546398 | controller | ok: 10 changed: 5 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 1
2025-10-14 07:40:39.546422 | 
2025-10-14 07:40:39.648867 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-10-14 07:40:39.649736 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-10-14 07:40:40.208688 | 
2025-10-14 07:40:40.208786 | PLAY [Run ci/playbooks/molecule-test.yml]
2025-10-14 07:40:40.230054 | 
2025-10-14 07:40:40.230131 | TASK [Gather required facts]
2025-10-14 07:40:40.775961 | controller | ok
2025-10-14 07:40:40.781388 | 
2025-10-14 07:40:40.781465 | TASK [Load environment var if instructed to]
2025-10-14 07:40:40.830778 | controller | skipping: Conditional result was False
2025-10-14 07:40:40.836324 | 
2025-10-14 07:40:40.836396 | TASK [Ensure group_vars dir exists]
2025-10-14 07:40:41.163148 | controller | ok
2025-10-14 07:40:41.169250 | 
2025-10-14 07:40:41.169323 | TASK [Run molecule]
2025-10-14 07:40:42.120083 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2025-10-14 07:40:42.201416 | controller | INFO     Running default > prepare
2025-10-14 07:40:42.883877 | controller |
2025-10-14 07:40:42.883937 | controller | PLAY [Prepare] *****************************************************************
2025-10-14 07:40:42.884449 | controller |
2025-10-14 07:40:42.884465 | controller | TASK [Gathering Facts] *********************************************************
2025-10-14 07:40:42.884563 | controller | Tuesday 14 October 2025  07:40:42 +0000 (0:00:00.010)       0:00:00.010 *******
2025-10-14 07:40:43.702557 | controller | ok: [instance]
2025-10-14 07:40:43.702632 | controller |
2025-10-14 07:40:43.702760 | controller | TASK [Create dummy env file] ***************************************************
2025-10-14 07:40:43.702873 | controller | Tuesday 14 October 2025  07:40:43 +0000 (0:00:00.819)       0:00:00.830 *******
2025-10-14 07:40:44.218895 | controller | changed: [instance]
2025-10-14 07:40:44.218954 | controller |
2025-10-14 07:40:44.219060 | controller | TASK [Create dummy playbook] ***************************************************
2025-10-14 07:40:44.219170 | controller | Tuesday 14 October 2025  07:40:44 +0000 (0:00:00.516)       0:00:01.346 *******
2025-10-14 07:40:46.170901 | controller | changed: [instance] => (item=dummy-1.yml)
2025-10-14 07:40:46.170962 | controller | changed: [instance] => (item=dummy-2.yml)
2025-10-14 07:40:46.171073 | controller | changed: [instance] => (item=dummy-3.yml)
2025-10-14 07:40:46.171174 | controller | changed: [instance] => (item=dummy-4.yml)
2025-10-14 07:40:46.171276 | controller | changed: [instance] => (item=dummy-5.yml)
2025-10-14 07:40:46.171393 | controller | changed: [instance] => (item=dummy-6.yml)
2025-10-14 07:40:46.171484 | controller |
2025-10-14 07:40:46.171581 | controller | TASK [Remove dummy file for retry playbook test] *******************************
2025-10-14 07:40:46.171699 | controller | Tuesday 14 October 2025  07:40:46 +0000 (0:00:01.951)       0:00:03.298 *******
2025-10-14 07:40:46.448934 | controller | ok: [instance]
2025-10-14 07:40:46.448992 | controller |
2025-10-14 07:40:46.449105 | controller | TASK [Create dummy retry playbook] *********************************************
2025-10-14 07:40:46.449202 | controller | Tuesday 14 October 2025  07:40:46 +0000 (0:00:00.278)       0:00:03.576 *******
2025-10-14 07:40:46.796898 | controller | changed: [instance]
2025-10-14 07:40:46.796969 | controller |
2025-10-14 07:40:46.797074 | controller | PLAY RECAP *********************************************************************
2025-10-14 07:40:46.797186 | controller | instance                   : ok=5    changed=3    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-10-14 07:40:46.797285 | controller |
2025-10-14 07:40:46.797404 | controller | Tuesday 14 October 2025  07:40:46 +0000 (0:00:00.348)       0:00:03.925 *******
2025-10-14 07:40:46.797505 | controller | ===============================================================================
2025-10-14 07:40:46.797596 | controller | Create dummy playbook --------------------------------------------------- 1.95s
2025-10-14 07:40:46.797709 | controller | Gathering Facts --------------------------------------------------------- 0.82s
2025-10-14 07:40:46.797804 | controller | Create dummy env file --------------------------------------------------- 0.52s
2025-10-14 07:40:46.797896 | controller | Create dummy retry playbook --------------------------------------------- 0.35s
2025-10-14 07:40:46.797989 | controller | Remove dummy file for retry playbook test ------------------------------- 0.28s
2025-10-14 07:40:46.856831 | controller | INFO     Running default > converge
2025-10-14 07:40:47.285575 | controller |
2025-10-14 07:40:47.286040 | controller | PLAY [Converge] ****************************************************************
2025-10-14 07:40:48.084447 | controller |
2025-10-14 07:40:48.084476 | controller | TASK [Gathering Facts] *********************************************************
2025-10-14 07:40:48.084484 | controller | Tuesday 14 October 2025  07:40:47 +0000 (0:00:00.018)       0:00:00.018 *******
2025-10-14 07:40:48.084497 | controller | ok: [instance]
2025-10-14 07:40:48.084519 | controller |
2025-10-14 07:40:48.084525 | controller | TASK [No hook] *****************************************************************
2025-10-14 07:40:48.084532 | controller | Tuesday 14 October 2025  07:40:48 +0000 (0:00:00.798)       0:00:00.817 *******
2025-10-14 07:40:48.112875 | controller |
2025-10-14 07:40:48.171529 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-10-14 07:40:48.171567 | controller | Tuesday 14 October 2025  07:40:48 +0000 (0:00:00.028)       0:00:00.846 *******
2025-10-14 07:40:48.171579 | controller | ok: [instance]
2025-10-14 07:40:48.245018 | controller |
2025-10-14 07:40:48.245043 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-10-14 07:40:48.245051 | controller | Tuesday 14 October 2025  07:40:48 +0000 (0:00:00.058)       0:00:00.904 *******
2025-10-14 07:40:48.245061 | controller | ok: [instance]
2025-10-14 07:40:48.318479 | controller |
2025-10-14 07:40:48.318510 | controller | TASK [run_hook : Loop on hooks for no_hook] ************************************
2025-10-14 07:40:48.318519 | controller | Tuesday 14 October 2025  07:40:48 +0000 (0:00:00.073)       0:00:00.977 *******
2025-10-14 07:40:48.318531 | controller | skipping: [instance]
2025-10-14 07:40:48.318726 | controller |
2025-10-14 07:40:48.318905 | controller | TASK [Ensure we do not have ceph_uuid] *****************************************
2025-10-14 07:40:48.319081 | controller | Tuesday 14 October 2025  07:40:48 +0000 (0:00:00.073)       0:00:01.051 *******
2025-10-14 07:40:48.340831 | controller | ok: [instance] => changed=false
2025-10-14 07:40:48.341027 | controller |   msg: All assertions passed
2025-10-14 07:40:48.341189 | controller |
2025-10-14 07:40:48.341358 | controller | TASK [Combined hooks] **********************************************************
2025-10-14 07:40:48.341518 | controller | Tuesday 14 October 2025  07:40:48 +0000 (0:00:00.022)       0:00:01.074 *******
2025-10-14 07:40:48.370118 | controller |
2025-10-14 07:40:48.370306 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-10-14 07:40:48.370470 | controller | Tuesday 14 October 2025  07:40:48 +0000 (0:00:00.029)       0:00:01.103 *******
2025-10-14 07:40:48.426948 | controller | ok: [instance]
2025-10-14 07:40:48.427141 | controller |
2025-10-14 07:40:48.427317 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-10-14 07:40:48.427511 | controller | Tuesday 14 October 2025  07:40:48 +0000 (0:00:00.056)       0:00:01.160 *******
2025-10-14 07:40:48.498316 | controller | ok: [instance]
2025-10-14 07:40:48.498538 | controller |
2025-10-14 07:40:48.498706 | controller | TASK [run_hook : Loop on hooks for run_molecule] *******************************
2025-10-14 07:40:48.498846 | controller | Tuesday 14 October 2025  07:40:48 +0000 (0:00:00.071)       0:00:01.231 *******
2025-10-14 07:40:48.619763 | 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-10-14 07:40:48.619967 | 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-10-14 07:40:48.620131 | 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-10-14 07:40:48.620265 | controller |
2025-10-14 07:40:48.620427 | controller | TASK [run_hook : Set playbook path for 01 Default noop hook] *******************
2025-10-14 07:40:48.620570 | controller | Tuesday 14 October 2025  07:40:48 +0000 (0:00:00.121)       0:00:01.352 *******
2025-10-14 07:40:48.668931 | controller | ok: [instance]
2025-10-14 07:40:48.669096 | controller |
2025-10-14 07:40:48.669240 | controller | TASK [run_hook : Get file stat] ************************************************
2025-10-14 07:40:48.669402 | controller | Tuesday 14 October 2025  07:40:48 +0000 (0:00:00.049)       0:00:01.402 *******
2025-10-14 07:40:48.948528 | controller | ok: [instance]
2025-10-14 07:40:48.965979 | controller |
2025-10-14 07:40:48.966004 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-10-14 07:40:48.966015 | controller | Tuesday 14 October 2025  07:40:48 +0000 (0:00:00.279)       0:00:01.681 *******
2025-10-14 07:40:48.966026 | controller | skipping: [instance]
2025-10-14 07:40:49.245291 | controller |
2025-10-14 07:40:49.245322 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-10-14 07:40:49.245415 | controller | Tuesday 14 October 2025  07:40:48 +0000 (0:00:00.017)       0:00:01.699 *******
2025-10-14 07:40:49.245436 | controller | ok: [instance]
2025-10-14 07:40:49.265721 | controller |
2025-10-14 07:40:49.265745 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-10-14 07:40:49.265755 | controller | Tuesday 14 October 2025  07:40:49 +0000 (0:00:00.279)       0:00:01.978 *******
2025-10-14 07:40:49.265766 | controller | ok: [instance]
2025-10-14 07:40:49.559167 | controller |
2025-10-14 07:40:49.559196 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-10-14 07:40:49.559204 | controller | Tuesday 14 October 2025  07:40:49 +0000 (0:00:00.020)       0:00:01.998 *******
2025-10-14 07:40:49.559215 | controller | ok: [instance]
2025-10-14 07:40:49.753036 | controller |
2025-10-14 07:40:49.753066 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-10-14 07:40:49.753074 | controller | Tuesday 14 October 2025  07:40:49 +0000 (0:00:00.293)       0:00:02.291 *******
2025-10-14 07:40:49.753084 | controller | ok: [instance]
2025-10-14 07:40:50.364459 | controller |
2025-10-14 07:40:50.364489 | controller | TASK [run_hook : Run hook without retry - 01 Default noop hook] ****************
2025-10-14 07:40:50.364497 | controller | Tuesday 14 October 2025  07:40:49 +0000 (0:00:00.193)       0:00:02.485 *******
2025-10-14 07:40:50.364507 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_000_run_hook_without_retry_01.log
2025-10-14 07:40:50.394100 | controller | changed: [instance]
2025-10-14 07:40:50.394121 | controller |
2025-10-14 07:40:50.394128 | controller | TASK [run_hook : Run hook with retry - 01 Default noop hook] *******************
2025-10-14 07:40:50.394137 | controller | Tuesday 14 October 2025  07:40:50 +0000 (0:00:00.611)       0:00:03.097 *******
2025-10-14 07:40:50.394146 | controller | skipping: [instance]
2025-10-14 07:40:50.578394 | controller |
2025-10-14 07:40:50.578421 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-10-14 07:40:50.578429 | controller | Tuesday 14 October 2025  07:40:50 +0000 (0:00:00.030)       0:00:03.127 *******
2025-10-14 07:40:50.578439 | controller | ok: [instance]
2025-10-14 07:40:50.578599 | controller |
2025-10-14 07:40:50.578617 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-10-14 07:40:50.596791 | controller | Tuesday 14 October 2025  07:40:50 +0000 (0:00:00.184)       0:00:03.311 *******
2025-10-14 07:40:50.596813 | controller | skipping: [instance]
2025-10-14 07:40:50.646295 | controller |
2025-10-14 07:40:50.646317 | controller | TASK [run_hook : Set playbook path for 02 Re-run noop] *************************
2025-10-14 07:40:50.646344 | controller | Tuesday 14 October 2025  07:40:50 +0000 (0:00:00.018)       0:00:03.330 *******
2025-10-14 07:40:50.646356 | controller | ok: [instance]
2025-10-14 07:40:50.835153 | controller |
2025-10-14 07:40:50.835182 | controller | TASK [run_hook : Get file stat] ************************************************
2025-10-14 07:40:50.835190 | controller | Tuesday 14 October 2025  07:40:50 +0000 (0:00:00.049)       0:00:03.379 *******
2025-10-14 07:40:50.835201 | controller | ok: [instance]
2025-10-14 07:40:50.851431 | controller |
2025-10-14 07:40:50.851464 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-10-14 07:40:50.851473 | controller | Tuesday 14 October 2025  07:40:50 +0000 (0:00:00.188)       0:00:03.568 *******
2025-10-14 07:40:50.851483 | controller | skipping: [instance]
2025-10-14 07:40:50.851507 | controller |
2025-10-14 07:40:50.851515 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-10-14 07:40:50.851659 | controller | Tuesday 14 October 2025  07:40:50 +0000 (0:00:00.016)       0:00:03.584 *******
2025-10-14 07:40:51.038450 | controller | ok: [instance]
2025-10-14 07:40:51.038497 | controller |
2025-10-14 07:40:51.038752 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-10-14 07:40:51.058403 | controller | Tuesday 14 October 2025  07:40:51 +0000 (0:00:00.186)       0:00:03.771 *******
2025-10-14 07:40:51.058433 | controller | ok: [instance]
2025-10-14 07:40:51.058729 | controller |
2025-10-14 07:40:51.252208 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-10-14 07:40:51.252242 | controller | Tuesday 14 October 2025  07:40:51 +0000 (0:00:00.020)       0:00:03.791 *******
2025-10-14 07:40:51.252254 | controller | ok: [instance]
2025-10-14 07:40:51.437049 | controller |
2025-10-14 07:40:51.437084 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-10-14 07:40:51.437093 | controller | Tuesday 14 October 2025  07:40:51 +0000 (0:00:00.193)       0:00:03.985 *******
2025-10-14 07:40:51.437103 | controller | ok: [instance]
2025-10-14 07:40:52.051554 | controller |
2025-10-14 07:40:52.051584 | controller | TASK [run_hook : Run hook without retry - 02 Re-run noop] **********************
2025-10-14 07:40:52.051592 | controller | Tuesday 14 October 2025  07:40:51 +0000 (0:00:00.184)       0:00:04.170 *******
2025-10-14 07:40:52.051602 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_001_run_hook_without_retry_02_re.log
2025-10-14 07:40:52.081215 | controller | changed: [instance]
2025-10-14 07:40:52.081241 | controller |
2025-10-14 07:40:52.081249 | controller | TASK [run_hook : Run hook with retry - 02 Re-run noop] *************************
2025-10-14 07:40:52.081256 | controller | Tuesday 14 October 2025  07:40:52 +0000 (0:00:00.614)       0:00:04.784 *******
2025-10-14 07:40:52.081266 | controller | skipping: [instance]
2025-10-14 07:40:52.254110 | controller |
2025-10-14 07:40:52.254138 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-10-14 07:40:52.254146 | controller | Tuesday 14 October 2025  07:40:52 +0000 (0:00:00.029)       0:00:04.814 *******
2025-10-14 07:40:52.254157 | controller | ok: [instance]
2025-10-14 07:40:52.271062 | controller |
2025-10-14 07:40:52.271092 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-10-14 07:40:52.271102 | controller | Tuesday 14 October 2025  07:40:52 +0000 (0:00:00.172)       0:00:04.987 *******
2025-10-14 07:40:52.271114 | controller | skipping: [instance]
2025-10-14 07:40:52.318500 | controller |
2025-10-14 07:40:52.318529 | controller | TASK [run_hook : Set playbook path for 03 single hook] *************************
2025-10-14 07:40:52.318539 | controller | Tuesday 14 October 2025  07:40:52 +0000 (0:00:00.017)       0:00:05.004 *******
2025-10-14 07:40:52.318550 | controller | ok: [instance]
2025-10-14 07:40:52.509524 | controller |
2025-10-14 07:40:52.509553 | controller | TASK [run_hook : Get file stat] ************************************************
2025-10-14 07:40:52.509561 | controller | Tuesday 14 October 2025  07:40:52 +0000 (0:00:00.047)       0:00:05.051 *******
2025-10-14 07:40:52.509571 | controller | ok: [instance]
2025-10-14 07:40:52.525900 | controller |
2025-10-14 07:40:52.525923 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-10-14 07:40:52.525931 | controller | Tuesday 14 October 2025  07:40:52 +0000 (0:00:00.191)       0:00:05.242 *******
2025-10-14 07:40:52.525941 | controller | skipping: [instance]
2025-10-14 07:40:52.716543 | controller |
2025-10-14 07:40:52.716573 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-10-14 07:40:52.716581 | controller | Tuesday 14 October 2025  07:40:52 +0000 (0:00:00.016)       0:00:05.259 *******
2025-10-14 07:40:52.716592 | controller | ok: [instance]
2025-10-14 07:40:52.734043 | controller |
2025-10-14 07:40:52.734065 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-10-14 07:40:52.734072 | controller | Tuesday 14 October 2025  07:40:52 +0000 (0:00:00.187)       0:00:05.447 *******
2025-10-14 07:40:52.734082 | controller | ok: [instance]
2025-10-14 07:40:52.934442 | controller |
2025-10-14 07:40:52.934471 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-10-14 07:40:52.934479 | controller | Tuesday 14 October 2025  07:40:52 +0000 (0:00:00.020)       0:00:05.467 *******
2025-10-14 07:40:52.934489 | controller | ok: [instance]
2025-10-14 07:40:53.119908 | controller |
2025-10-14 07:40:53.119939 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-10-14 07:40:53.119947 | controller | Tuesday 14 October 2025  07:40:52 +0000 (0:00:00.197)       0:00:05.664 *******
2025-10-14 07:40:53.119957 | controller | ok: [instance]
2025-10-14 07:40:54.984048 | controller |
2025-10-14 07:40:54.984078 | controller | TASK [run_hook : Run hook without retry - 03 single hook] **********************
2025-10-14 07:40:54.984086 | controller | Tuesday 14 October 2025  07:40:53 +0000 (0:00:00.188)       0:00:05.852 *******
2025-10-14 07:40:54.984096 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_002_run_hook_without_retry_03.log
2025-10-14 07:40:55.010929 | controller | changed: [instance]
2025-10-14 07:40:55.010964 | controller |
2025-10-14 07:40:55.010971 | controller | TASK [run_hook : Run hook with retry - 03 single hook] *************************
2025-10-14 07:40:55.010978 | controller | Tuesday 14 October 2025  07:40:54 +0000 (0:00:01.864)       0:00:07.716 *******
2025-10-14 07:40:55.010987 | controller | skipping: [instance]
2025-10-14 07:40:55.190432 | controller |
2025-10-14 07:40:55.190460 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-10-14 07:40:55.190468 | controller | Tuesday 14 October 2025  07:40:55 +0000 (0:00:00.026)       0:00:07.743 *******
2025-10-14 07:40:55.190483 | controller | ok: [instance]
2025-10-14 07:40:55.214760 | controller |
2025-10-14 07:40:55.214786 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-10-14 07:40:55.214793 | controller | Tuesday 14 October 2025  07:40:55 +0000 (0:00:00.179)       0:00:07.923 *******
2025-10-14 07:40:55.214802 | controller | ok: [instance]
2025-10-14 07:40:55.237734 | controller |
2025-10-14 07:40:55.237758 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-10-14 07:40:55.237766 | controller | Tuesday 14 October 2025  07:40:55 +0000 (0:00:00.024)       0:00:07.947 *******
2025-10-14 07:40:55.237775 | controller | ok: [instance] => changed=false
2025-10-14 07:40:55.268793 | controller |   msg: All assertions passed
2025-10-14 07:40:55.268821 | controller |
2025-10-14 07:40:55.268829 | controller | TASK [Only listed hooks] *******************************************************
2025-10-14 07:40:55.268837 | controller | Tuesday 14 October 2025  07:40:55 +0000 (0:00:00.022)       0:00:07.970 *******
2025-10-14 07:40:55.268848 | controller |
2025-10-14 07:40:55.327020 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-10-14 07:40:55.327048 | controller | Tuesday 14 October 2025  07:40:55 +0000 (0:00:00.031)       0:00:08.001 *******
2025-10-14 07:40:55.327060 | controller | ok: [instance]
2025-10-14 07:40:55.400182 | controller |
2025-10-14 07:40:55.400211 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-10-14 07:40:55.400219 | controller | Tuesday 14 October 2025  07:40:55 +0000 (0:00:00.058)       0:00:08.060 *******
2025-10-14 07:40:55.400230 | controller | ok: [instance]
2025-10-14 07:40:55.507035 | controller |
2025-10-14 07:40:55.507065 | controller | TASK [run_hook : Loop on hooks for list_hooks] *********************************
2025-10-14 07:40:55.507073 | controller | Tuesday 14 October 2025  07:40:55 +0000 (0:00:00.073)       0:00:08.133 *******
2025-10-14 07:40:55.507084 | 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-10-14 07:40:55.554436 | 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-10-14 07:40:55.554467 | controller |
2025-10-14 07:40:55.554475 | controller | TASK [run_hook : Set playbook path for Run dummy-2] ****************************
2025-10-14 07:40:55.554482 | controller | Tuesday 14 October 2025  07:40:55 +0000 (0:00:00.106)       0:00:08.239 *******
2025-10-14 07:40:55.554491 | controller | ok: [instance]
2025-10-14 07:40:55.554514 | controller |
2025-10-14 07:40:55.554718 | controller | TASK [run_hook : Get file stat] ************************************************
2025-10-14 07:40:55.739810 | controller | Tuesday 14 October 2025  07:40:55 +0000 (0:00:00.047)       0:00:08.287 *******
2025-10-14 07:40:55.739844 | controller | ok: [instance]
2025-10-14 07:40:55.755479 | controller |
2025-10-14 07:40:55.755505 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-10-14 07:40:55.755513 | controller | Tuesday 14 October 2025  07:40:55 +0000 (0:00:00.185)       0:00:08.472 *******
2025-10-14 07:40:55.755523 | controller | skipping: [instance]
2025-10-14 07:40:55.933390 | controller |
2025-10-14 07:40:55.933419 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-10-14 07:40:55.933427 | controller | Tuesday 14 October 2025  07:40:55 +0000 (0:00:00.015)       0:00:08.488 *******
2025-10-14 07:40:55.933437 | controller | ok: [instance]
2025-10-14 07:40:55.934053 | controller |
2025-10-14 07:40:55.951497 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-10-14 07:40:55.951522 | controller | Tuesday 14 October 2025  07:40:55 +0000 (0:00:00.178)       0:00:08.666 *******
2025-10-14 07:40:55.951533 | controller | ok: [instance]
2025-10-14 07:40:56.141947 | controller |
2025-10-14 07:40:56.141978 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-10-14 07:40:56.141986 | controller | Tuesday 14 October 2025  07:40:55 +0000 (0:00:00.017)       0:00:08.684 *******
2025-10-14 07:40:56.141997 | controller | ok: [instance]
2025-10-14 07:40:56.329888 | controller |
2025-10-14 07:40:56.329918 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-10-14 07:40:56.329926 | controller | Tuesday 14 October 2025  07:40:56 +0000 (0:00:00.190)       0:00:08.874 *******
2025-10-14 07:40:56.329937 | controller | ok: [instance]
2025-10-14 07:40:58.226599 | controller |
2025-10-14 07:40:58.226630 | controller | TASK [run_hook : Run hook without retry - Run dummy-2] *************************
2025-10-14 07:40:58.226639 | controller | Tuesday 14 October 2025  07:40:56 +0000 (0:00:00.187)       0:00:09.062 *******
2025-10-14 07:40:58.226660 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_003_run_hook_without_retry_run.log
2025-10-14 07:40:58.256448 | controller | changed: [instance]
2025-10-14 07:40:58.256479 | controller |
2025-10-14 07:40:58.256487 | controller | TASK [run_hook : Run hook with retry - Run dummy-2] ****************************
2025-10-14 07:40:58.256494 | controller | Tuesday 14 October 2025  07:40:58 +0000 (0:00:01.896)       0:00:10.959 *******
2025-10-14 07:40:58.256504 | controller | skipping: [instance]
2025-10-14 07:40:58.449154 | controller |
2025-10-14 07:40:58.449188 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-10-14 07:40:58.449204 | controller | Tuesday 14 October 2025  07:40:58 +0000 (0:00:00.030)       0:00:10.989 *******
2025-10-14 07:40:58.449215 | controller | ok: [instance]
2025-10-14 07:40:58.471519 | controller |
2025-10-14 07:40:58.471542 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-10-14 07:40:58.471549 | controller | Tuesday 14 October 2025  07:40:58 +0000 (0:00:00.192)       0:00:11.182 *******
2025-10-14 07:40:58.471559 | controller | ok: [instance]
2025-10-14 07:40:58.520050 | controller |
2025-10-14 07:40:58.520082 | controller | TASK [run_hook : Set playbook path for Run dummy-3] ****************************
2025-10-14 07:40:58.520091 | controller | Tuesday 14 October 2025  07:40:58 +0000 (0:00:00.022)       0:00:11.204 *******
2025-10-14 07:40:58.520103 | controller | ok: [instance]
2025-10-14 07:40:58.713120 | controller |
2025-10-14 07:40:58.713154 | controller | TASK [run_hook : Get file stat] ************************************************
2025-10-14 07:40:58.713162 | controller | Tuesday 14 October 2025  07:40:58 +0000 (0:00:00.048)       0:00:11.252 *******
2025-10-14 07:40:58.713173 | controller | ok: [instance]
2025-10-14 07:40:58.729867 | controller |
2025-10-14 07:40:58.729896 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-10-14 07:40:58.729904 | controller | Tuesday 14 October 2025  07:40:58 +0000 (0:00:00.193)       0:00:11.446 *******
2025-10-14 07:40:58.729914 | controller | skipping: [instance]
2025-10-14 07:40:58.925907 | controller |
2025-10-14 07:40:58.925940 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-10-14 07:40:58.925948 | controller | Tuesday 14 October 2025  07:40:58 +0000 (0:00:00.016)       0:00:11.462 *******
2025-10-14 07:40:58.925959 | controller | ok: [instance]
2025-10-14 07:40:58.945664 | controller |
2025-10-14 07:40:58.945696 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-10-14 07:40:58.945704 | controller | Tuesday 14 October 2025  07:40:58 +0000 (0:00:00.195)       0:00:11.658 *******
2025-10-14 07:40:58.945714 | controller | ok: [instance]
2025-10-14 07:40:59.144091 | controller |
2025-10-14 07:40:59.144124 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-10-14 07:40:59.144132 | controller | Tuesday 14 October 2025  07:40:58 +0000 (0:00:00.019)       0:00:11.678 *******
2025-10-14 07:40:59.144142 | controller | ok: [instance]
2025-10-14 07:40:59.335230 | controller |
2025-10-14 07:40:59.335261 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-10-14 07:40:59.335281 | controller | Tuesday 14 October 2025  07:40:59 +0000 (0:00:00.198)       0:00:11.877 *******
2025-10-14 07:40:59.335292 | controller | ok: [instance]
2025-10-14 07:41:01.394409 | controller |
2025-10-14 07:41:01.394440 | controller | TASK [run_hook : Run hook without retry - Run dummy-3] *************************
2025-10-14 07:41:01.394448 | controller | Tuesday 14 October 2025  07:40:59 +0000 (0:00:00.191)       0:00:12.068 *******
2025-10-14 07:41:01.394459 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_004_run_hook_without_retry_run.log
2025-10-14 07:41:01.425488 | controller | changed: [instance]
2025-10-14 07:41:01.425523 | controller |
2025-10-14 07:41:01.425535 | controller | TASK [run_hook : Run hook with retry - Run dummy-3] ****************************
2025-10-14 07:41:01.425543 | controller | Tuesday 14 October 2025  07:41:01 +0000 (0:00:02.059)       0:00:14.127 *******
2025-10-14 07:41:01.425556 | controller | skipping: [instance]
2025-10-14 07:41:01.617276 | controller |
2025-10-14 07:41:01.617307 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-10-14 07:41:01.617315 | controller | Tuesday 14 October 2025  07:41:01 +0000 (0:00:00.031)       0:00:14.158 *******
2025-10-14 07:41:01.617342 | controller | ok: [instance]
2025-10-14 07:41:01.644393 | controller |
2025-10-14 07:41:01.644419 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-10-14 07:41:01.644428 | controller | Tuesday 14 October 2025  07:41:01 +0000 (0:00:00.191)       0:00:14.350 *******
2025-10-14 07:41:01.644438 | controller | ok: [instance]
2025-10-14 07:41:01.669458 | controller |
2025-10-14 07:41:01.669494 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-10-14 07:41:01.669502 | controller | Tuesday 14 October 2025  07:41:01 +0000 (0:00:00.027)       0:00:14.377 *******
2025-10-14 07:41:01.669513 | controller | ok: [instance] => changed=false
2025-10-14 07:41:01.669537 | controller |   msg: All assertions passed
2025-10-14 07:41:01.669544 | controller |
2025-10-14 07:41:01.669557 | controller | TASK [Only filtered hooks] *****************************************************
2025-10-14 07:41:01.669622 | controller | Tuesday 14 October 2025  07:41:01 +0000 (0:00:00.025)       0:00:14.402 *******
2025-10-14 07:41:01.706110 | controller |
2025-10-14 07:41:01.766878 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-10-14 07:41:01.766915 | controller | Tuesday 14 October 2025  07:41:01 +0000 (0:00:00.036)       0:00:14.439 *******
2025-10-14 07:41:01.766935 | controller | ok: [instance]
2025-10-14 07:41:01.844730 | controller |
2025-10-14 07:41:01.844757 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-10-14 07:41:01.844765 | controller | Tuesday 14 October 2025  07:41:01 +0000 (0:00:00.060)       0:00:14.499 *******
2025-10-14 07:41:01.844774 | controller | ok: [instance]
2025-10-14 07:41:01.844914 | controller |
2025-10-14 07:41:01.845055 | controller | TASK [run_hook : Loop on hooks for filtered_hooks] *****************************
2025-10-14 07:41:01.845191 | controller | Tuesday 14 October 2025  07:41:01 +0000 (0:00:00.078)       0:00:14.578 *******
2025-10-14 07:41:01.942095 | 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-10-14 07:41:01.942286 | controller |
2025-10-14 07:41:01.942466 | controller | TASK [run_hook : Set playbook path for 01 my hook] *****************************
2025-10-14 07:41:01.942613 | controller | Tuesday 14 October 2025  07:41:01 +0000 (0:00:00.097)       0:00:14.675 *******
2025-10-14 07:41:01.993493 | controller | ok: [instance]
2025-10-14 07:41:01.993646 | controller |
2025-10-14 07:41:01.993809 | controller | TASK [run_hook : Get file stat] ************************************************
2025-10-14 07:41:01.993951 | controller | Tuesday 14 October 2025  07:41:01 +0000 (0:00:00.051)       0:00:14.726 *******
2025-10-14 07:41:02.189601 | controller | ok: [instance]
2025-10-14 07:41:02.208427 | controller |
2025-10-14 07:41:02.208461 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-10-14 07:41:02.208468 | controller | Tuesday 14 October 2025  07:41:02 +0000 (0:00:00.195)       0:00:14.922 *******
2025-10-14 07:41:02.208479 | controller | skipping: [instance]
2025-10-14 07:41:02.208513 | controller |
2025-10-14 07:41:02.208522 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-10-14 07:41:02.208585 | controller | Tuesday 14 October 2025  07:41:02 +0000 (0:00:00.019)       0:00:14.941 *******
2025-10-14 07:41:02.405865 | controller | ok: [instance]
2025-10-14 07:41:02.426227 | controller |
2025-10-14 07:41:02.426251 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-10-14 07:41:02.426259 | controller | Tuesday 14 October 2025  07:41:02 +0000 (0:00:00.197)       0:00:15.138 *******
2025-10-14 07:41:02.426269 | controller | ok: [instance]
2025-10-14 07:41:02.620014 | controller |
2025-10-14 07:41:02.620044 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-10-14 07:41:02.620051 | controller | Tuesday 14 October 2025  07:41:02 +0000 (0:00:00.020)       0:00:15.159 *******
2025-10-14 07:41:02.620061 | controller | ok: [instance]
2025-10-14 07:41:02.806104 | controller |
2025-10-14 07:41:02.806136 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-10-14 07:41:02.806144 | controller | Tuesday 14 October 2025  07:41:02 +0000 (0:00:00.193)       0:00:15.352 *******
2025-10-14 07:41:02.806154 | controller | ok: [instance]
2025-10-14 07:41:04.746101 | controller |
2025-10-14 07:41:04.746133 | controller | TASK [run_hook : Run hook without retry - 01 my hook] **************************
2025-10-14 07:41:04.746141 | controller | Tuesday 14 October 2025  07:41:02 +0000 (0:00:00.186)       0:00:15.539 *******
2025-10-14 07:41:04.746151 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_005_run_hook_without_retry_01_my.log
2025-10-14 07:41:04.776832 | controller | changed: [instance]
2025-10-14 07:41:04.776855 | controller |
2025-10-14 07:41:04.776864 | controller | TASK [run_hook : Run hook with retry - 01 my hook] *****************************
2025-10-14 07:41:04.776872 | controller | Tuesday 14 October 2025  07:41:04 +0000 (0:00:01.939)       0:00:17.478 *******
2025-10-14 07:41:04.776883 | controller | skipping: [instance]
2025-10-14 07:41:04.969073 | controller |
2025-10-14 07:41:04.969104 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-10-14 07:41:04.969113 | controller | Tuesday 14 October 2025  07:41:04 +0000 (0:00:00.030)       0:00:17.509 *******
2025-10-14 07:41:04.969123 | controller | ok: [instance]
2025-10-14 07:41:04.996406 | controller |
2025-10-14 07:41:04.996435 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-10-14 07:41:04.996444 | controller | Tuesday 14 October 2025  07:41:04 +0000 (0:00:00.192)       0:00:17.701 *******
2025-10-14 07:41:04.996456 | controller | ok: [instance]
2025-10-14 07:41:04.996829 | controller |
2025-10-14 07:41:05.022183 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-10-14 07:41:05.022206 | controller | Tuesday 14 October 2025  07:41:04 +0000 (0:00:00.027)       0:00:17.729 *******
2025-10-14 07:41:05.022217 | controller | ok: [instance] => changed=false
2025-10-14 07:41:05.059240 | controller |   msg: All assertions passed
2025-10-14 07:41:05.059260 | controller |
2025-10-14 07:41:05.059268 | controller | TASK [Direct hooks] ************************************************************
2025-10-14 07:41:05.059276 | controller | Tuesday 14 October 2025  07:41:05 +0000 (0:00:00.025)       0:00:17.755 *******
2025-10-14 07:41:05.059286 | controller |
2025-10-14 07:41:05.119431 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-10-14 07:41:05.119469 | controller | Tuesday 14 October 2025  07:41:05 +0000 (0:00:00.037)       0:00:17.792 *******
2025-10-14 07:41:05.119483 | controller | ok: [instance]
2025-10-14 07:41:05.119507 | controller |
2025-10-14 07:41:05.119517 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-10-14 07:41:05.119538 | controller | Tuesday 14 October 2025  07:41:05 +0000 (0:00:00.060)       0:00:17.852 *******
2025-10-14 07:41:05.194895 | controller | ok: [instance]
2025-10-14 07:41:05.288532 | controller |
2025-10-14 07:41:05.288566 | controller | TASK [run_hook : Loop on hooks for no_hook] ************************************
2025-10-14 07:41:05.288574 | controller | Tuesday 14 October 2025  07:41:05 +0000 (0:00:00.074)       0:00:17.927 *******
2025-10-14 07:41:05.288585 | 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-10-14 07:41:05.288749 | controller |
2025-10-14 07:41:05.288892 | controller | TASK [run_hook : Set playbook path for Dummy-5] ********************************
2025-10-14 07:41:05.289033 | controller | Tuesday 14 October 2025  07:41:05 +0000 (0:00:00.094)       0:00:18.021 *******
2025-10-14 07:41:05.337000 | controller | ok: [instance]
2025-10-14 07:41:05.337195 | controller |
2025-10-14 07:41:05.337408 | controller | TASK [run_hook : Get file stat] ************************************************
2025-10-14 07:41:05.337557 | controller | Tuesday 14 October 2025  07:41:05 +0000 (0:00:00.048)       0:00:18.070 *******
2025-10-14 07:41:05.531488 | controller | ok: [instance]
2025-10-14 07:41:05.548887 | controller |
2025-10-14 07:41:05.548920 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-10-14 07:41:05.548929 | controller | Tuesday 14 October 2025  07:41:05 +0000 (0:00:00.194)       0:00:18.264 *******
2025-10-14 07:41:05.548940 | controller | skipping: [instance]
2025-10-14 07:41:05.737429 | controller |
2025-10-14 07:41:05.737462 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-10-14 07:41:05.737470 | controller | Tuesday 14 October 2025  07:41:05 +0000 (0:00:00.017)       0:00:18.281 *******
2025-10-14 07:41:05.737480 | controller | ok: [instance]
2025-10-14 07:41:05.737533 | controller |
2025-10-14 07:41:05.737563 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-10-14 07:41:05.737575 | controller | Tuesday 14 October 2025  07:41:05 +0000 (0:00:00.188)       0:00:18.470 *******
2025-10-14 07:41:05.757647 | controller | ok: [instance]
2025-10-14 07:41:05.953167 | controller |
2025-10-14 07:41:05.953198 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-10-14 07:41:05.953206 | controller | Tuesday 14 October 2025  07:41:05 +0000 (0:00:00.020)       0:00:18.490 *******
2025-10-14 07:41:05.953216 | controller | ok: [instance]
2025-10-14 07:41:06.137154 | controller |
2025-10-14 07:41:06.137185 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-10-14 07:41:06.137193 | controller | Tuesday 14 October 2025  07:41:05 +0000 (0:00:00.195)       0:00:18.686 *******
2025-10-14 07:41:06.137203 | controller | ok: [instance]
2025-10-14 07:41:08.062156 | controller |
2025-10-14 07:41:08.062188 | controller | TASK [run_hook : Run hook without retry - Dummy-5] *****************************
2025-10-14 07:41:08.062196 | controller | Tuesday 14 October 2025  07:41:06 +0000 (0:00:00.183)       0:00:18.870 *******
2025-10-14 07:41:08.062207 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_006_run_hook_without_retry_dummy.log
2025-10-14 07:41:08.092238 | controller | changed: [instance]
2025-10-14 07:41:08.092263 | controller |
2025-10-14 07:41:08.092273 | controller | TASK [run_hook : Run hook with retry - Dummy-5] ********************************
2025-10-14 07:41:08.092280 | controller | Tuesday 14 October 2025  07:41:08 +0000 (0:00:01.924)       0:00:20.794 *******
2025-10-14 07:41:08.092291 | controller | skipping: [instance]
2025-10-14 07:41:08.285156 | controller |
2025-10-14 07:41:08.285187 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-10-14 07:41:08.285195 | controller | Tuesday 14 October 2025  07:41:08 +0000 (0:00:00.030)       0:00:20.825 *******
2025-10-14 07:41:08.285205 | controller | ok: [instance]
2025-10-14 07:41:08.309592 | controller |
2025-10-14 07:41:08.309634 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-10-14 07:41:08.309642 | controller | Tuesday 14 October 2025  07:41:08 +0000 (0:00:00.192)       0:00:21.018 *******
2025-10-14 07:41:08.309651 | controller | ok: [instance]
2025-10-14 07:41:08.332287 | controller |
2025-10-14 07:41:08.332310 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-10-14 07:41:08.332317 | controller | Tuesday 14 October 2025  07:41:08 +0000 (0:00:00.024)       0:00:21.042 *******
2025-10-14 07:41:08.332344 | controller | ok: [instance] => changed=false
2025-10-14 07:41:08.385459 | controller |   msg: All assertions passed
2025-10-14 07:41:08.385493 | controller |
2025-10-14 07:41:08.385503 | controller | TASK [Direct hooks as param] ***************************************************
2025-10-14 07:41:08.385511 | controller | Tuesday 14 October 2025  07:41:08 +0000 (0:00:00.022)       0:00:21.065 *******
2025-10-14 07:41:08.385538 | controller |
2025-10-14 07:41:08.444138 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-10-14 07:41:08.444172 | controller | Tuesday 14 October 2025  07:41:08 +0000 (0:00:00.053)       0:00:21.118 *******
2025-10-14 07:41:08.444186 | controller | ok: [instance]
2025-10-14 07:41:08.515840 | controller |
2025-10-14 07:41:08.515869 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-10-14 07:41:08.515877 | controller | Tuesday 14 October 2025  07:41:08 +0000 (0:00:00.058)       0:00:21.176 *******
2025-10-14 07:41:08.515887 | controller | ok: [instance]
2025-10-14 07:41:08.516048 | controller |
2025-10-14 07:41:08.516197 | controller | TASK [run_hook : Loop on hooks for no_hook] ************************************
2025-10-14 07:41:08.516360 | controller | Tuesday 14 October 2025  07:41:08 +0000 (0:00:00.072)       0:00:21.249 *******
2025-10-14 07:41:08.609598 | 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-10-14 07:41:08.609783 | controller |
2025-10-14 07:41:08.609930 | controller | TASK [run_hook : Set playbook path for Hook as param] **************************
2025-10-14 07:41:08.610073 | controller | Tuesday 14 October 2025  07:41:08 +0000 (0:00:00.093)       0:00:21.342 *******
2025-10-14 07:41:08.659608 | controller | ok: [instance]
2025-10-14 07:41:08.849924 | controller |
2025-10-14 07:41:08.849954 | controller | TASK [run_hook : Get file stat] ************************************************
2025-10-14 07:41:08.849963 | controller | Tuesday 14 October 2025  07:41:08 +0000 (0:00:00.049)       0:00:21.392 *******
2025-10-14 07:41:08.849973 | controller | ok: [instance]
2025-10-14 07:41:08.867240 | controller |
2025-10-14 07:41:08.867264 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-10-14 07:41:08.867272 | controller | Tuesday 14 October 2025  07:41:08 +0000 (0:00:00.190)       0:00:21.582 *******
2025-10-14 07:41:08.867281 | controller | skipping: [instance]
2025-10-14 07:41:09.055002 | controller |
2025-10-14 07:41:09.055031 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-10-14 07:41:09.055039 | controller | Tuesday 14 October 2025  07:41:08 +0000 (0:00:00.017)       0:00:21.600 *******
2025-10-14 07:41:09.055049 | controller | ok: [instance]
2025-10-14 07:41:09.075292 | controller |
2025-10-14 07:41:09.075322 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-10-14 07:41:09.075354 | controller | Tuesday 14 October 2025  07:41:09 +0000 (0:00:00.187)       0:00:21.787 *******
2025-10-14 07:41:09.075367 | controller | ok: [instance]
2025-10-14 07:41:09.278007 | controller |
2025-10-14 07:41:09.278038 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-10-14 07:41:09.278046 | controller | Tuesday 14 October 2025  07:41:09 +0000 (0:00:00.020)       0:00:21.808 *******
2025-10-14 07:41:09.278056 | controller | ok: [instance]
2025-10-14 07:41:09.468423 | controller |
2025-10-14 07:41:09.468456 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-10-14 07:41:09.468464 | controller | Tuesday 14 October 2025  07:41:09 +0000 (0:00:00.202)       0:00:22.010 *******
2025-10-14 07:41:09.468474 | controller | ok: [instance]
2025-10-14 07:41:09.468665 | controller |
2025-10-14 07:41:09.468703 | controller | TASK [run_hook : Run hook without retry - Hook as param] ***********************
2025-10-14 07:41:11.401907 | controller | Tuesday 14 October 2025  07:41:09 +0000 (0:00:00.190)       0:00:22.201 *******
2025-10-14 07:41:11.401941 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_007_run_hook_without_retry_hook.log
2025-10-14 07:41:11.435248 | controller | changed: [instance]
2025-10-14 07:41:11.435271 | controller |
2025-10-14 07:41:11.435279 | controller | TASK [run_hook : Run hook with retry - Hook as param] **************************
2025-10-14 07:41:11.435285 | controller | Tuesday 14 October 2025  07:41:11 +0000 (0:00:01.933)       0:00:24.134 *******
2025-10-14 07:41:11.435294 | controller | skipping: [instance]
2025-10-14 07:41:11.632843 | controller |
2025-10-14 07:41:11.632874 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-10-14 07:41:11.632889 | controller | Tuesday 14 October 2025  07:41:11 +0000 (0:00:00.033)       0:00:24.168 *******
2025-10-14 07:41:11.632904 | controller | ok: [instance]
2025-10-14 07:41:11.662338 | controller |
2025-10-14 07:41:11.662365 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-10-14 07:41:11.662373 | controller | Tuesday 14 October 2025  07:41:11 +0000 (0:00:00.197)       0:00:24.365 *******
2025-10-14 07:41:11.662383 | controller | ok: [instance]
2025-10-14 07:41:11.693410 | controller |
2025-10-14 07:41:11.693486 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-10-14 07:41:11.693496 | controller | Tuesday 14 October 2025  07:41:11 +0000 (0:00:00.029)       0:00:24.395 *******
2025-10-14 07:41:11.693512 | controller | ok: [instance] => changed=false
2025-10-14 07:41:11.734659 | controller |   msg: All assertions passed
2025-10-14 07:41:11.734703 | controller |
2025-10-14 07:41:11.734711 | controller | TASK [Ensure we have the test_list variable now] *******************************
2025-10-14 07:41:11.734724 | controller | Tuesday 14 October 2025  07:41:11 +0000 (0:00:00.030)       0:00:24.426 *******
2025-10-14 07:41:11.734734 | controller | ok: [instance] => changed=false
2025-10-14 07:41:11.762852 | controller |   msg: All assertions passed
2025-10-14 07:41:11.762876 | controller |
2025-10-14 07:41:11.762884 | controller | TASK [Run hook with retry] *****************************************************
2025-10-14 07:41:11.762890 | controller | Tuesday 14 October 2025  07:41:11 +0000 (0:00:00.041)       0:00:24.467 *******
2025-10-14 07:41:11.762900 | controller |
2025-10-14 07:41:11.822413 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-10-14 07:41:11.822457 | controller | Tuesday 14 October 2025  07:41:11 +0000 (0:00:00.028)       0:00:24.495 *******
2025-10-14 07:41:11.822472 | controller | ok: [instance]
2025-10-14 07:41:11.896439 | controller |
2025-10-14 07:41:11.896478 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-10-14 07:41:11.896487 | controller | Tuesday 14 October 2025  07:41:11 +0000 (0:00:00.059)       0:00:24.555 *******
2025-10-14 07:41:11.896497 | controller | ok: [instance]
2025-10-14 07:41:11.896524 | controller |
2025-10-14 07:41:11.896897 | controller | TASK [run_hook : Loop on hooks for retry_hook] *********************************
2025-10-14 07:41:11.992247 | controller | Tuesday 14 October 2025  07:41:11 +0000 (0:00:00.074)       0:00:24.629 *******
2025-10-14 07:41:11.992287 | 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-10-14 07:41:11.992493 | controller |
2025-10-14 07:41:11.992685 | controller | TASK [run_hook : Set playbook path for Run hook with retry] ********************
2025-10-14 07:41:11.992857 | controller | Tuesday 14 October 2025  07:41:11 +0000 (0:00:00.096)       0:00:24.725 *******
2025-10-14 07:41:12.042654 | controller | ok: [instance]
2025-10-14 07:41:12.042864 | controller |
2025-10-14 07:41:12.043037 | controller | TASK [run_hook : Get file stat] ************************************************
2025-10-14 07:41:12.043195 | controller | Tuesday 14 October 2025  07:41:12 +0000 (0:00:00.050)       0:00:24.775 *******
2025-10-14 07:41:12.239250 | controller | ok: [instance]
2025-10-14 07:41:12.256743 | controller |
2025-10-14 07:41:12.256768 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-10-14 07:41:12.256775 | controller | Tuesday 14 October 2025  07:41:12 +0000 (0:00:00.196)       0:00:24.972 *******
2025-10-14 07:41:12.256786 | controller | skipping: [instance]
2025-10-14 07:41:12.445873 | controller |
2025-10-14 07:41:12.445903 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-10-14 07:41:12.445911 | controller | Tuesday 14 October 2025  07:41:12 +0000 (0:00:00.017)       0:00:24.989 *******
2025-10-14 07:41:12.445921 | controller | ok: [instance]
2025-10-14 07:41:12.467151 | controller |
2025-10-14 07:41:12.467177 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-10-14 07:41:12.467185 | controller | Tuesday 14 October 2025  07:41:12 +0000 (0:00:00.188)       0:00:25.178 *******
2025-10-14 07:41:12.467195 | controller | ok: [instance]
2025-10-14 07:41:12.664584 | controller |
2025-10-14 07:41:12.664617 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-10-14 07:41:12.664632 | controller | Tuesday 14 October 2025  07:41:12 +0000 (0:00:00.021)       0:00:25.200 *******
2025-10-14 07:41:12.664642 | controller | ok: [instance]
2025-10-14 07:41:12.853112 | controller |
2025-10-14 07:41:12.853145 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-10-14 07:41:12.853153 | controller | Tuesday 14 October 2025  07:41:12 +0000 (0:00:00.197)       0:00:25.397 *******
2025-10-14 07:41:12.853164 | controller | ok: [instance]
2025-10-14 07:41:14.769396 | controller |
2025-10-14 07:41:14.769430 | controller | TASK [run_hook : Run hook without retry - Run hook with retry] *****************
2025-10-14 07:41:14.769437 | controller | Tuesday 14 October 2025  07:41:12 +0000 (0:00:00.188)       0:00:25.585 *******
2025-10-14 07:41:14.769448 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_008_run_hook_without_retry_run.log
2025-10-14 07:41:14.799614 | controller | changed: [instance]
2025-10-14 07:41:14.799636 | controller |
2025-10-14 07:41:14.799643 | controller | TASK [run_hook : Run hook with retry - Run hook with retry] ********************
2025-10-14 07:41:14.799650 | controller | Tuesday 14 October 2025  07:41:14 +0000 (0:00:01.916)       0:00:27.502 *******
2025-10-14 07:41:14.799658 | controller | skipping: [instance]
2025-10-14 07:41:14.974260 | controller |
2025-10-14 07:41:14.974291 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-10-14 07:41:14.974299 | controller | Tuesday 14 October 2025  07:41:14 +0000 (0:00:00.030)       0:00:27.532 *******
2025-10-14 07:41:14.974309 | controller | ok: [instance]
2025-10-14 07:41:14.997822 | controller |
2025-10-14 07:41:14.997842 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-10-14 07:41:14.997850 | controller | Tuesday 14 October 2025  07:41:14 +0000 (0:00:00.174)       0:00:27.707 *******
2025-10-14 07:41:14.997864 | controller | skipping: [instance]
2025-10-14 07:41:15.177550 | controller |
2025-10-14 07:41:15.177580 | controller | TASK [Check if fake file exists for retry playbook] ****************************
2025-10-14 07:41:15.177588 | controller | Tuesday 14 October 2025  07:41:14 +0000 (0:00:00.023)       0:00:27.730 *******
2025-10-14 07:41:15.177598 | controller | ok: [instance]
2025-10-14 07:41:15.197203 | controller |
2025-10-14 07:41:15.197220 | controller | TASK [Ensure file exists and was created on retry] *****************************
2025-10-14 07:41:15.197227 | controller | Tuesday 14 October 2025  07:41:15 +0000 (0:00:00.179)       0:00:27.910 *******
2025-10-14 07:41:15.197236 | controller | ok: [instance] => changed=false
2025-10-14 07:41:15.395359 | controller |   msg: All assertions passed
2025-10-14 07:41:15.395397 | controller |
2025-10-14 07:41:15.395405 | controller | TASK [Remove generated file] ***************************************************
2025-10-14 07:41:15.395411 | controller | Tuesday 14 October 2025  07:41:15 +0000 (0:00:00.019)       0:00:27.930 *******
2025-10-14 07:41:15.395422 | controller | changed: [instance]
2025-10-14 07:41:15.395448 | controller |
2025-10-14 07:41:15.395455 | controller | PLAY RECAP *********************************************************************
2025-10-14 07:41:15.395462 | controller | instance                   : ok=112  changed=10   unreachable=0    failed=0    skipped=22   rescued=0    ignored=0
2025-10-14 07:41:15.395560 | controller |
2025-10-14 07:41:15.397571 | controller | Tuesday 14 October 2025  07:41:15 +0000 (0:00:00.197)       0:00:28.128 *******
2025-10-14 07:41:15.461582 | controller | ===============================================================================
2025-10-14 07:41:15.461616 | controller | run_hook : Run hook without retry - Run dummy-3 ------------------------- 2.06s
2025-10-14 07:41:15.461624 | controller | run_hook : Run hook without retry - 01 my hook -------------------------- 1.94s
2025-10-14 07:41:15.461629 | controller | run_hook : Run hook without retry - Hook as param ----------------------- 1.93s
2025-10-14 07:41:15.461635 | controller | run_hook : Run hook without retry - Dummy-5 ----------------------------- 1.92s
2025-10-14 07:41:15.461640 | controller | run_hook : Run hook without retry - Run hook with retry ----------------- 1.92s
2025-10-14 07:41:15.461645 | controller | run_hook : Run hook without retry - Run dummy-2 ------------------------- 1.90s
2025-10-14 07:41:15.461651 | controller | run_hook : Run hook without retry - 03 single hook ---------------------- 1.86s
2025-10-14 07:41:15.461656 | controller | Gathering Facts --------------------------------------------------------- 0.80s
2025-10-14 07:41:15.461666 | controller | run_hook : Run hook without retry - 02 Re-run noop ---------------------- 0.61s
2025-10-14 07:41:15.461672 | controller | run_hook : Run hook without retry - 01 Default noop hook ---------------- 0.61s
2025-10-14 07:41:15.461702 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.29s
2025-10-14 07:41:15.461709 | controller | run_hook : Get file stat ------------------------------------------------ 0.28s
2025-10-14 07:41:15.461714 | controller | run_hook : Get parameters files ----------------------------------------- 0.28s
2025-10-14 07:41:15.461720 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.20s
2025-10-14 07:41:15.461725 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.20s
2025-10-14 07:41:15.461730 | controller | Remove generated file --------------------------------------------------- 0.20s
2025-10-14 07:41:15.461736 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.20s
2025-10-14 07:41:15.461741 | controller | run_hook : Check if we have a file -------------------------------------- 0.20s
2025-10-14 07:41:15.461746 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.20s
2025-10-14 07:41:15.461752 | controller | run_hook : Get parameters files ----------------------------------------- 0.20s
2025-10-14 07:41:15.461762 | controller | INFO     Running default > cleanup
2025-10-14 07:41:15.462229 | controller | WARNING  Skipping, cleanup playbook not configured.
2025-10-14 07:41:15.462842 | controller | INFO     Writing /tmp/report.html report.
2025-10-14 07:41:15.733061 | controller | changed
2025-10-14 07:41:15.764762 | 
2025-10-14 07:41:15.764848 | PLAY RECAP
2025-10-14 07:41:15.764888 | controller | ok: 3 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-14 07:41:15.764933 | 
2025-10-14 07:41:15.850422 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-10-14 07:41:15.851330 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-10-14 07:41:16.477873 | 
2025-10-14 07:41:16.477999 | PLAY [Run ci/playbooks/collect-logs.yml]
2025-10-14 07:41:16.498982 | 
2025-10-14 07:41:16.499061 | TASK [Filter out host if needed]
2025-10-14 07:41:16.507834 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2025-10-14 07:41:16.512412 | 
2025-10-14 07:41:16.512480 | TASK [Ensure file is present]
2025-10-14 07:41:16.888027 | controller | ok
2025-10-14 07:41:16.895554 | 
2025-10-14 07:41:16.895629 | TASK [Manage molecule report file]
2025-10-14 07:41:17.423325 | controller | changed
2025-10-14 07:41:17.429240 | 
2025-10-14 07:41:17.429310 | TASK [Check if we get ci-framework-data basedir]
2025-10-14 07:41:17.621560 | controller | ok
2025-10-14 07:41:17.627518 | 
2025-10-14 07:41:17.627601 | TASK [Create ci-framework-data log directory for zuul]
2025-10-14 07:41:17.951673 | controller | changed
2025-10-14 07:41:17.957664 | 
2025-10-14 07:41:17.957751 | TASK [Copy ci-framework interesting files]
2025-10-14 07:41:18.162269 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory
2025-10-14 07:41:18.484751 | controller | changed
2025-10-14 07:41:18.490227 | 
2025-10-14 07:41:18.490351 | TASK [Get SELinux listing]
2025-10-14 07:41:19.014612 | controller | changed
2025-10-14 07:41:19.021245 | 
2025-10-14 07:41:19.021342 | TASK [Generate log index]
2025-10-14 07:41:19.659936 | controller | changed
2025-10-14 07:41:19.665262 | 
2025-10-14 07:41:19.665343 | TASK [Get some env related data]
2025-10-14 07:41:20.195858 | controller | /home/zuul/.local/bin/ansible
2025-10-14 07:41:21.190859 | controller | changed
2025-10-14 07:41:21.196490 | 
2025-10-14 07:41:21.196555 | TASK [Generate list of logs to collect in home directory]
2025-10-14 07:41:21.498721 | controller | ok: All paths examined
2025-10-14 07:41:21.504691 | 
2025-10-14 07:41:21.504783 | LOOP [Copy logs from home directory]
2025-10-14 07:41:21.825775 | controller | changed:
2025-10-14 07:41:21.826133 | controller | {
2025-10-14 07:41:21.826169 | controller |   "atime": 1760427622.3453994,
2025-10-14 07:41:21.826191 | controller |   "ctime": 1760427639.0906055,
2025-10-14 07:41:21.826238 | controller |   "dev": 64513,
2025-10-14 07:41:21.826256 | controller |   "gid": 1000,
2025-10-14 07:41:21.826272 | controller |   "gr_name": "zuul",
2025-10-14 07:41:21.826287 | controller |   "inode": 4428743,
2025-10-14 07:41:21.826302 | controller |   "isblk": false,
2025-10-14 07:41:21.826317 | controller |   "ischr": false,
2025-10-14 07:41:21.826331 | controller |   "isdir": false,
2025-10-14 07:41:21.826345 | controller |   "isfifo": false,
2025-10-14 07:41:21.826359 | controller |   "isgid": false,
2025-10-14 07:41:21.826373 | controller |   "islnk": false,
2025-10-14 07:41:21.826386 | controller |   "isreg": true,
2025-10-14 07:41:21.826399 | controller |   "issock": false,
2025-10-14 07:41:21.826413 | controller |   "isuid": false,
2025-10-14 07:41:21.826427 | controller |   "mode": "0644",
2025-10-14 07:41:21.826441 | controller |   "mtime": 1760427639.0906055,
2025-10-14 07:41:21.826455 | controller |   "nlink": 1,
2025-10-14 07:41:21.826469 | controller |   "path": "/home/zuul/ansible.log",
2025-10-14 07:41:21.826484 | controller |   "pw_name": "zuul",
2025-10-14 07:41:21.826500 | controller |   "rgrp": true,
2025-10-14 07:41:21.826515 | controller |   "roth": true,
2025-10-14 07:41:21.826529 | controller |   "rusr": true,
2025-10-14 07:41:21.826543 | controller |   "size": 6749,
2025-10-14 07:41:21.826556 | controller |   "uid": 1000,
2025-10-14 07:41:21.826569 | controller |   "wgrp": false,
2025-10-14 07:41:21.826582 | controller |   "woth": false,
2025-10-14 07:41:21.826598 | controller |   "wusr": true,
2025-10-14 07:41:21.826613 | controller |   "xgrp": false,
2025-10-14 07:41:21.826627 | controller |   "xoth": false,
2025-10-14 07:41:21.826640 | controller |   "xusr": false
2025-10-14 07:41:21.826655 | controller | }
2025-10-14 07:41:21.840517 | 
2025-10-14 07:41:21.840583 | TASK [Copy crio stats log file]
2025-10-14 07:41:21.854011 | controller | skipping: Conditional result was False
2025-10-14 07:41:21.860462 | 
2025-10-14 07:41:21.860532 | TASK [Get SELinux related data]
2025-10-14 07:41:22.077273 | controller | <no matches>
2025-10-14 07:41:22.398451 | controller | ERROR
2025-10-14 07:41:22.398577 | controller | {
2025-10-14 07:41:22.398610 | controller |   "delta": "0:00:00.008881",
2025-10-14 07:41:22.398631 | controller |   "end": "2025-10-14 07:41:22.078301",
2025-10-14 07:41:22.398648 | controller |   "msg": "non-zero return code",
2025-10-14 07:41:22.398664 | controller |   "rc": 1,
2025-10-14 07:41:22.398680 | controller |   "start": "2025-10-14 07:41:22.069420"
2025-10-14 07:41:22.398695 | controller | }
2025-10-14 07:41:22.398716 | controller | ERROR: Ignoring Errors
2025-10-14 07:41:22.403967 | 
2025-10-14 07:41:22.404035 | TASK [Create system configuration directory]
2025-10-14 07:41:22.595458 | controller | changed
2025-10-14 07:41:22.600851 | 
2025-10-14 07:41:22.600934 | TASK [Get some of the system configurations]
2025-10-14 07:41:23.138434 | controller | changed
2025-10-14 07:41:23.143676 | 
2025-10-14 07:41:23.143743 | TASK [Copy generated documentation if available]
2025-10-14 07:41:23.157222 | controller | skipping: Conditional result was False
2025-10-14 07:41:23.163141 | 
2025-10-14 07:41:23.163222 | TASK [Copy generated AsciiDoc documentation if available]
2025-10-14 07:41:23.176471 | controller | skipping: Conditional result was False
2025-10-14 07:41:23.182261 | 
2025-10-14 07:41:23.182327 | TASK [Compress logs bigger than 2MB]
2025-10-14 07:41:23.708672 | controller | changed
2025-10-14 07:41:23.714160 | 
2025-10-14 07:41:23.714252 | TASK [Copy files from workspace on node]
2025-10-14 07:41:23.732350 | controller | ok
2025-10-14 07:41:23.755515 | 
2025-10-14 07:41:23.755596 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-14 07:41:23.768712 | controller | skipping: Conditional result was False
2025-10-14 07:41:23.774190 | 
2025-10-14 07:41:23.774285 | TASK [fetch-output : Set log path for single node]
2025-10-14 07:41:23.801975 | controller | ok
2025-10-14 07:41:23.808195 | 
2025-10-14 07:41:23.808287 | LOOP [fetch-output : Ensure local output dirs]
2025-10-14 07:41:24.007605 | controller -> localhost | ok: "/var/lib/zuul/builds/0c9d90ba401a4223bf75da6be8e2f3c6/work/logs"
2025-10-14 07:41:24.007853 | controller -> localhost | changed: All items complete
2025-10-14 07:41:24.007882 | 
2025-10-14 07:41:24.192694 | controller -> localhost | changed: "/var/lib/zuul/builds/0c9d90ba401a4223bf75da6be8e2f3c6/work/artifacts"
2025-10-14 07:41:24.382061 | controller -> localhost | changed: "/var/lib/zuul/builds/0c9d90ba401a4223bf75da6be8e2f3c6/work/docs"
2025-10-14 07:41:24.395846 | 
2025-10-14 07:41:24.395962 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-14 07:41:24.966300 | controller | changed:
2025-10-14 07:41:24.966485 | controller | .d..t...... ./
2025-10-14 07:41:24.966516 | controller | >f+++++++++ README.html
2025-10-14 07:41:24.966537 | controller | >f+++++++++ ansible-execution.log
2025-10-14 07:41:24.966559 | controller | >f+++++++++ ansible.log
2025-10-14 07:41:24.966578 | controller | >f+++++++++ dmesg.log
2025-10-14 07:41:24.966595 | controller | >f+++++++++ installed-pkgs.log
2025-10-14 07:41:24.966612 | controller | >f+++++++++ python.log
2025-10-14 07:41:24.966631 | controller | >f+++++++++ registries.conf
2025-10-14 07:41:24.966648 | controller | >f+++++++++ report.html
2025-10-14 07:41:24.966667 | controller | >f+++++++++ selinux-denials.log
2025-10-14 07:41:24.966683 | controller | >f+++++++++ selinux-listing.log
2025-10-14 07:41:24.966700 | controller | cd+++++++++ ci-framework-data/
2025-10-14 07:41:24.966715 | controller | cd+++++++++ ci-framework-data/artifacts/
2025-10-14 07:41:24.966731 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_000_run_hook_without_retry_01.sh
2025-10-14 07:41:24.966747 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_001_run_hook_without_retry_02_re.sh
2025-10-14 07:41:24.966762 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_002_run_hook_without_retry_03.sh
2025-10-14 07:41:24.966777 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_003_run_hook_without_retry_run.sh
2025-10-14 07:41:24.966792 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_004_run_hook_without_retry_run.sh
2025-10-14 07:41:24.966806 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_005_run_hook_without_retry_01_my.sh
2025-10-14 07:41:24.966821 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_006_run_hook_without_retry_dummy.sh
2025-10-14 07:41:24.966835 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_007_run_hook_without_retry_hook.sh
2025-10-14 07:41:24.966849 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_008_run_hook_without_retry_run.sh
2025-10-14 07:41:24.966865 | controller | >f+++++++++ ci-framework-data/artifacts/filtered_hooks_01_my_hook.yml
2025-10-14 07:41:24.966881 | controller | >f+++++++++ ci-framework-data/artifacts/list_hooks_run_dummy-2.yml
2025-10-14 07:41:24.966897 | controller | >f+++++++++ ci-framework-data/artifacts/list_hooks_run_dummy-3.yml
2025-10-14 07:41:24.966942 | controller | >f+++++++++ ci-framework-data/artifacts/no_hook_dummy-5.yml
2025-10-14 07:41:24.966965 | controller | >f+++++++++ ci-framework-data/artifacts/no_hook_hook_as_param.yml
2025-10-14 07:41:24.966982 | controller | >f+++++++++ ci-framework-data/artifacts/run_molecule_03_single_hook.yml
2025-10-14 07:41:24.967000 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2025-10-14 07:41:24.967016 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2025-10-14 07:41:24.967032 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2025-10-14 07:41:24.967048 | controller | cd+++++++++ ci-framework-data/logs/
2025-10-14 07:41:24.967069 | controller | >f+++++++++ ci-framework-data/logs/ci_script_000_run_hook_without_retry_01.log
2025-10-14 07:41:24.967086 | controller | >f+++++++++ ci-framework-data/logs/ci_script_001_run_hook_without_retry_02_re.log
2025-10-14 07:41:24.967102 | controller | >f+++++++++ ci-framework-data/logs/ci_script_002_run_hook_without_retry_03.log
2025-10-14 07:41:24.967117 | controller | >f+++++++++ ci-framework-data/logs/ci_script_003_run_hook_without_retry_run.log
2025-10-14 07:41:24.967132 | controller | >f+++++++++ ci-framework-data/logs/ci_script_004_run_hook_without_retry_run.log
2025-10-14 07:41:24.967147 | controller | >f+++++++++ ci-framework-data/logs/ci_script_005_run_hook_without_retry_01_my.log
2025-10-14 07:41:24.967161 | controller | >f+++++++++ ci-framework-data/logs/ci_script_006_run_hook_without_retry_dummy.log
2025-10-14 07:41:24.967175 | controller | >f+++++++++ ci-framework-data/logs/ci_script_007_run_hook_without_retry_hook.log
2025-10-14 07:41:24.967190 | controller | >f+++++++++ ci-framework-data/logs/ci_script_008_run_hook_without_retry_run.log
2025-10-14 07:41:24.967204 | controller | >f+++++++++ ci-framework-data/logs/filtered_hooks_01_my_hook.log
2025-10-14 07:41:24.967239 | controller | >f+++++++++ ci-framework-data/logs/list_hooks_run_dummy-2.log
2025-10-14 07:41:24.967255 | controller | >f+++++++++ ci-framework-data/logs/list_hooks_run_dummy-3.log
2025-10-14 07:41:24.967270 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2025-10-14 07:41:24.967285 | controller | >f+++++++++ ci-framework-data/logs/no_hook_dummy-5.log
2025-10-14 07:41:24.967300 | controller | >f+++++++++ ci-framework-data/logs/no_hook_hook_as_param.log
2025-10-14 07:41:24.967315 | controller | >f+++++++++ ci-framework-data/logs/retry_hook_run_hook_with_retry.log
2025-10-14 07:41:24.967330 | controller | >f+++++++++ ci-framework-data/logs/run_molecule_01_default_noop_hook.log
2025-10-14 07:41:24.967346 | controller | >f+++++++++ ci-framework-data/logs/run_molecule_02_re-run_noop.log
2025-10-14 07:41:24.967360 | controller | >f+++++++++ ci-framework-data/logs/run_molecule_03_single_hook.log
2025-10-14 07:41:24.967374 | controller | cd+++++++++ registries.conf.d/
2025-10-14 07:41:24.967389 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2025-10-14 07:41:24.967403 | controller | cd+++++++++ system-config/
2025-10-14 07:41:24.967418 | controller | cd+++++++++ system-config/libvirt/
2025-10-14 07:41:24.967432 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2025-10-14 07:41:24.967446 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2025-10-14 07:41:25.344568 | controller | changed: .d..t...... ./
2025-10-14 07:41:25.718743 | controller | changed: .d..t...... ./
2025-10-14 07:41:25.739597 | 
2025-10-14 07:41:25.739691 | TASK [Return artifact to Zuul]
2025-10-14 07:41:25.768435 | controller | ok
2025-10-14 07:41:25.789506 | 
2025-10-14 07:41:25.789590 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2025-10-14 07:41:25.789702 | 
2025-10-14 07:41:25.789738 | PLAY RECAP
2025-10-14 07:41:25.789783 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-10-14 07:41:25.789810 | 
2025-10-14 07:41:25.873782 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-10-14 07:41:25.874548 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-14 07:41:26.488458 | 
2025-10-14 07:41:26.488590 | PLAY [all]
2025-10-14 07:41:26.508972 | 
2025-10-14 07:41:26.509089 | TASK [include_role : fetch-output]
2025-10-14 07:41:26.550433 | controller | ok
2025-10-14 07:41:26.569379 | 
2025-10-14 07:41:26.569509 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-14 07:41:26.613942 | controller | skipping: Conditional result was False
2025-10-14 07:41:26.620974 | 
2025-10-14 07:41:26.621077 | TASK [fetch-output : Set log path for single node]
2025-10-14 07:41:26.650753 | controller | ok
2025-10-14 07:41:26.656193 | 
2025-10-14 07:41:26.656308 | LOOP [fetch-output : Ensure local output dirs]
2025-10-14 07:41:27.007169 | controller -> localhost | ok: "/var/lib/zuul/builds/0c9d90ba401a4223bf75da6be8e2f3c6/work/logs"
2025-10-14 07:41:27.193109 | controller -> localhost | ok: "/var/lib/zuul/builds/0c9d90ba401a4223bf75da6be8e2f3c6/work/artifacts"
2025-10-14 07:41:27.382339 | controller -> localhost | ok: "/var/lib/zuul/builds/0c9d90ba401a4223bf75da6be8e2f3c6/work/docs"
2025-10-14 07:41:27.394176 | 
2025-10-14 07:41:27.394301 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-14 07:41:27.919975 | controller | ok
2025-10-14 07:41:27.920245 | controller | ok: All items complete
2025-10-14 07:41:27.920284 | 
2025-10-14 07:41:28.301653 | controller | ok
2025-10-14 07:41:28.686845 | controller | ok
2025-10-14 07:41:28.699615 | 
2025-10-14 07:41:28.699736 | TASK [include_role : fetch-output-openshift]
2025-10-14 07:41:28.713712 | controller | skipping: Conditional result was False
2025-10-14 07:41:28.719948 | 
2025-10-14 07:41:28.720034 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-14 07:41:29.082679 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.006737
2025-10-14 07:41:29.285157 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.006844
2025-10-14 07:41:29.317960 | 
2025-10-14 07:41:29.318041 | PLAY [all]
2025-10-14 07:41:29.332846 | 
2025-10-14 07:41:29.332957 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-14 07:41:29.738441 | controller | changed
2025-10-14 07:41:29.763159 | 
2025-10-14 07:41:29.763266 | PLAY RECAP
2025-10-14 07:41:29.763317 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-14 07:41:29.763397 | 
2025-10-14 07:41:29.851960 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-14 07:41:29.852762 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-14 07:41:30.460815 | 
2025-10-14 07:41:30.460951 | PLAY [localhost]
2025-10-14 07:41:30.479883 | 
2025-10-14 07:41:30.479984 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-14 07:41:30.811737 | localhost | changed
2025-10-14 07:41:30.816632 | 
2025-10-14 07:41:30.816732 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-14 07:41:30.840743 | localhost | ok
2025-10-14 07:41:30.848978 | 
2025-10-14 07:41:30.849057 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-14 07:41:31.166400 | localhost | changed
2025-10-14 07:41:31.172292 | 
2025-10-14 07:41:31.172379 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-14 07:41:31.727832 | localhost | changed
2025-10-14 07:41:31.733302 | 
2025-10-14 07:41:31.733460 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-14 07:41:32.086450 | localhost | Identity added: /var/lib/zuul/builds/0c9d90ba401a4223bf75da6be8e2f3c6/work/tmp/ansible.v189sq69 (/var/lib/zuul/builds/0c9d90ba401a4223bf75da6be8e2f3c6/work/tmp/ansible.v189sq69)
2025-10-14 07:41:32.086643 | localhost | ok: Runtime: 0:00:00.006475
2025-10-14 07:41:32.091056 | 
2025-10-14 07:41:32.091128 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-14 07:41:32.321145 | localhost | ok: Runtime: 0:00:00.004394
2025-10-14 07:41:32.326036 | 
2025-10-14 07:41:32.326128 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-14 07:41:32.374685 | localhost | changed
2025-10-14 07:41:32.378788 | 
2025-10-14 07:41:32.378861 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-14 07:41:32.710305 | localhost | changed
2025-10-14 07:41:32.730168 | 
2025-10-14 07:41:32.730262 | PLAY [localhost]
2025-10-14 07:41:32.741686 | 
2025-10-14 07:41:32.741755 | TASK [Generate bulk log download script]
2025-10-14 07:41:32.760642 | localhost | ok
2025-10-14 07:41:32.772477 | 
2025-10-14 07:41:32.772556 | TASK [local-log-download : Check API endpoint is defined]
2025-10-14 07:41:32.800175 | localhost | ok: All assertions passed
2025-10-14 07:41:32.804610 | 
2025-10-14 07:41:32.804684 | TASK [local-log-download : Create download script]
2025-10-14 07:41:33.163046 | localhost -> localhost | changed
2025-10-14 07:41:33.172246 | 
2025-10-14 07:41:33.172328 | TASK [Register quick-download link]
2025-10-14 07:41:33.189003 | localhost | ok
2025-10-14 07:41:33.223482 | 
2025-10-14 07:41:33.223559 | PLAY [logserver.rdoproject.org]
2025-10-14 07:41:33.233069 | 
2025-10-14 07:41:33.233128 | TASK [Set zuul-log-path fact]
2025-10-14 07:41:33.248413 | logserver.rdoproject.org | ok
2025-10-14 07:41:33.257758 | 
2025-10-14 07:41:33.257837 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-14 07:41:33.283938 | logserver.rdoproject.org | ok
2025-10-14 07:41:33.289238 | 
2025-10-14 07:41:33.289316 | TASK [upload-logs : Create log directories]
2025-10-14 07:41:35.081367 | logserver.rdoproject.org | changed
2025-10-14 07:41:35.084681 | 
2025-10-14 07:41:35.084753 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-14 07:41:35.321684 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.005079
2025-10-14 07:41:35.326241 | 
2025-10-14 07:41:35.326310 | TASK [upload-logs : Upload logs to log server]
2025-10-14 07:41:36.842558 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-14 07:41:36.845526 | 
2025-10-14 07:41:36.845591 | LOOP [upload-logs : Compress console log and json output]
2025-10-14 07:41:36.884160 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-14 07:41:36.893794 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-14 07:41:36.902658 | 
2025-10-14 07:41:36.902735 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-14 07:41:36.938404 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-14 07:41:36.938619 | 
2025-10-14 07:41:36.941356 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-14 07:41:36.949093 | 
2025-10-14 07:41:36.949164 | LOOP [upload-logs : Upload console log and json output]