2025-10-03 13:37:02.584070 | Job console starting...
2025-10-03 13:37:02.821729 | Updating repositories
2025-10-03 13:37:03.535714 | Preparing job workspace
2025-10-03 13:37:10.504083 | Running Ansible setup...
2025-10-03 13:37:13.743747 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-03 13:37:14.285269 | 
2025-10-03 13:37:14.285362 | PLAY [localhost]
2025-10-03 13:37:14.294003 | 
2025-10-03 13:37:14.294074 | TASK [Gathering Facts]
2025-10-03 13:37:15.211850 | localhost | ok
2025-10-03 13:37:15.227362 | 
2025-10-03 13:37:15.227487 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-03 13:37:15.562126 | localhost -> localhost | changed
2025-10-03 13:37:15.568394 | 
2025-10-03 13:37:15.568489 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-03 13:37:16.329583 | localhost -> localhost | changed
2025-10-03 13:37:16.343719 | 
2025-10-03 13:37:16.343819 | TASK [Setup log path fact]
2025-10-03 13:37:16.360486 | localhost | ok
2025-10-03 13:37:16.375303 | 
2025-10-03 13:37:16.375375 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-03 13:37:16.401790 | localhost | ok
2025-10-03 13:37:16.409450 | 
2025-10-03 13:37:16.409536 | TASK [emit-job-header : Print job information]
2025-10-03 13:37:16.446836 | # Job Information
2025-10-03 13:37:16.447023 | Ansible Version: 2.15.12
2025-10-03 13:37:16.447057 | Job: cifmw-molecule-run_hook
2025-10-03 13:37:16.447081 | Pipeline: github-check
2025-10-03 13:37:16.447101 | Executor: ibm-bm4-ze.softwarefactory-project.io
2025-10-03 13:37:16.447120 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362
2025-10-03 13:37:16.447140 | Log URL (when completed): https://logserver.rdoproject.org/0b8/rdoproject.org/0b811b84cd9d468e82441f3dfc0bfdab/
2025-10-03 13:37:16.447161 | Event ID: f3678040-a05b-11f0-90a2-408975ecafa3
2025-10-03 13:37:16.451783 | 
2025-10-03 13:37:16.451851 | LOOP [emit-job-header : Print node information]
2025-10-03 13:37:16.540292 | localhost | ok:
2025-10-03 13:37:16.540449 | localhost | # Node Information
2025-10-03 13:37:16.540482 | localhost | Inventory Hostname: controller
2025-10-03 13:37:16.540506 | localhost | Hostname: np0005469521
2025-10-03 13:37:16.540528 | localhost | Username: zuul
2025-10-03 13:37:16.540550 | localhost | Distro: CentOS 9
2025-10-03 13:37:16.540568 | localhost | Provider: ibm-bm4-nodepool
2025-10-03 13:37:16.540586 | localhost | Region: regionOne
2025-10-03 13:37:16.540603 | localhost | Label: cloud-centos-9-stream-tripleo-ibm
2025-10-03 13:37:16.540620 | localhost | Product Name: OpenStack Compute
2025-10-03 13:37:16.540638 | localhost | Interface IP: 192.168.26.45
2025-10-03 13:37:16.564857 | 
2025-10-03 13:37:16.564991 | PLAY [all]
2025-10-03 13:37:16.571173 | 
2025-10-03 13:37:16.571238 | TASK [Gather network facts]
2025-10-03 13:37:16.934957 | controller | ok
2025-10-03 13:37:16.950040 | 
2025-10-03 13:37:16.950132 | TASK [include_role : start-zuul-console]
2025-10-03 13:37:16.968525 | controller | ok
2025-10-03 13:37:16.980287 | 
2025-10-03 13:37:16.980383 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-03 13:37:17.293008 | controller | ok
2025-10-03 13:37:17.301522 | 
2025-10-03 13:37:17.301591 | TASK [include_role : add-build-sshkey]
2025-10-03 13:37:17.319347 | controller | ok
2025-10-03 13:37:17.331919 | 
2025-10-03 13:37:17.332006 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-03 13:37:17.547996 | controller -> localhost | ok
2025-10-03 13:37:17.553389 | 
2025-10-03 13:37:17.553580 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-03 13:37:17.582895 | controller | ok
2025-10-03 13:37:17.595817 | controller | included: /var/lib/zuul/builds/0b811b84cd9d468e82441f3dfc0bfdab/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-03 13:37:17.601500 | 
2025-10-03 13:37:17.601567 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-03 13:37:18.102627 | controller -> localhost | Generating public/private rsa key pair.
2025-10-03 13:37:18.102791 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0b811b84cd9d468e82441f3dfc0bfdab/work/0b811b84cd9d468e82441f3dfc0bfdab_id_rsa.
2025-10-03 13:37:18.102827 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0b811b84cd9d468e82441f3dfc0bfdab/work/0b811b84cd9d468e82441f3dfc0bfdab_id_rsa.pub.
2025-10-03 13:37:18.102853 | controller -> localhost | The key fingerprint is:
2025-10-03 13:37:18.102876 | controller -> localhost | SHA256:KqgMMUudw2PacHKwErBF6vJDFICGnWyAI4kUI5MMAh0 zuul-build-sshkey
2025-10-03 13:37:18.102898 | controller -> localhost | The key's randomart image is:
2025-10-03 13:37:18.103156 | controller -> localhost | +---[RSA 3072]----+
2025-10-03 13:37:18.103193 | controller -> localhost | |^&Eo             |
2025-10-03 13:37:18.103219 | controller -> localhost | |&BB.             |
2025-10-03 13:37:18.103242 | controller -> localhost | |*+.              |
2025-10-03 13:37:18.103265 | controller -> localhost | |.o= .            |
2025-10-03 13:37:18.103285 | controller -> localhost | |=*.X    S        |
2025-10-03 13:37:18.103305 | controller -> localhost | |+*O.o  .         |
2025-10-03 13:37:18.103324 | controller -> localhost | |o.+.. .          |
2025-10-03 13:37:18.103346 | controller -> localhost | |o. . .           |
2025-10-03 13:37:18.103366 | controller -> localhost | |..               |
2025-10-03 13:37:18.103386 | controller -> localhost | +----[SHA256]-----+
2025-10-03 13:37:18.103432 | controller -> localhost | ok: Runtime: 0:00:00.108663
2025-10-03 13:37:18.109344 | 
2025-10-03 13:37:18.109411 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-03 13:37:18.128044 | controller | ok
2025-10-03 13:37:18.138037 | controller | included: /var/lib/zuul/builds/0b811b84cd9d468e82441f3dfc0bfdab/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-03 13:37:18.148155 | 
2025-10-03 13:37:18.148223 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-03 13:37:18.162033 | controller | skipping: Conditional result was False
2025-10-03 13:37:18.168467 | 
2025-10-03 13:37:18.168536 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-03 13:37:18.543782 | controller | changed
2025-10-03 13:37:18.549307 | 
2025-10-03 13:37:18.549379 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-03 13:37:18.755473 | controller | ok
2025-10-03 13:37:18.760667 | 
2025-10-03 13:37:18.760779 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-03 13:37:19.337824 | controller | changed
2025-10-03 13:37:19.342835 | 
2025-10-03 13:37:19.342928 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-03 13:37:19.952289 | controller | changed
2025-10-03 13:37:19.958326 | 
2025-10-03 13:37:19.958397 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-03 13:37:19.982260 | controller | skipping: Conditional result was False
2025-10-03 13:37:19.987869 | 
2025-10-03 13:37:19.987953 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-03 13:37:20.335769 | controller -> localhost | changed
2025-10-03 13:37:20.346038 | 
2025-10-03 13:37:20.346207 | TASK [add-build-sshkey : Add back temp key]
2025-10-03 13:37:20.582920 | controller -> localhost | Identity added: /var/lib/zuul/builds/0b811b84cd9d468e82441f3dfc0bfdab/work/0b811b84cd9d468e82441f3dfc0bfdab_id_rsa (zuul-build-sshkey)
2025-10-03 13:37:20.583127 | controller -> localhost | ok: Runtime: 0:00:00.006758
2025-10-03 13:37:20.589003 | 
2025-10-03 13:37:20.589070 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-03 13:37:20.882172 | controller | ok
2025-10-03 13:37:20.888346 | 
2025-10-03 13:37:20.888427 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-03 13:37:20.922697 | controller | skipping: Conditional result was False
2025-10-03 13:37:20.933510 | 
2025-10-03 13:37:20.933591 | TASK [include_role : validate-host]
2025-10-03 13:37:20.952503 | controller | ok
2025-10-03 13:37:20.975145 | 
2025-10-03 13:37:20.975263 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-03 13:37:21.003599 | controller | ok
2025-10-03 13:37:21.008556 | 
2025-10-03 13:37:21.008636 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-03 13:37:21.206807 | controller -> localhost | ok
2025-10-03 13:37:21.212551 | 
2025-10-03 13:37:21.212636 | TASK [validate-host : Collect information about the host]
2025-10-03 13:37:21.832574 | controller | ok
2025-10-03 13:37:21.840689 | 
2025-10-03 13:37:21.840857 | TASK [validate-host : Sanitize hostname]
2025-10-03 13:37:21.918996 | controller | ok
2025-10-03 13:37:21.951339 | 
2025-10-03 13:37:21.951438 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-03 13:37:22.350598 | controller -> localhost | changed
2025-10-03 13:37:22.356111 | 
2025-10-03 13:37:22.356185 | TASK [validate-host : Collect information about zuul worker]
2025-10-03 13:37:22.696267 | controller | ok
2025-10-03 13:37:22.701175 | 
2025-10-03 13:37:22.701271 | TASK [validate-host : Write out all zuul information for each host]
2025-10-03 13:37:23.090171 | controller -> localhost | changed
2025-10-03 13:37:23.099709 | 
2025-10-03 13:37:23.099775 | TASK [include_role : prepare-workspace-openshift]
2025-10-03 13:37:23.112471 | controller | skipping: Conditional result was False
2025-10-03 13:37:23.117385 | 
2025-10-03 13:37:23.117448 | TASK [include_role : remove-zuul-sshkey]
2025-10-03 13:37:23.130145 | controller | skipping: Conditional result was False
2025-10-03 13:37:23.135495 | 
2025-10-03 13:37:23.135559 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-03 13:37:23.332686 | controller | ok: "logs"
2025-10-03 13:37:23.332953 | controller | ok: All items complete
2025-10-03 13:37:23.333006 | 
2025-10-03 13:37:23.500055 | controller | ok: "artifacts"
2025-10-03 13:37:23.673979 | controller | ok: "docs"
2025-10-03 13:37:23.687582 | 
2025-10-03 13:37:23.687686 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-03 13:37:23.890791 | controller | changed: "logs"
2025-10-03 13:37:24.073614 | controller | changed: "artifacts"
2025-10-03 13:37:24.249041 | controller | changed: "docs"
2025-10-03 13:37:24.281070 | 
2025-10-03 13:37:24.281193 | PLAY RECAP
2025-10-03 13:37:24.281244 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-03 13:37:24.281274 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-03 13:37:24.281294 | 
2025-10-03 13:37:24.439512 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-03 13:37:24.440295 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-10-03 13:37:25.052080 | 
2025-10-03 13:37:25.052188 | PLAY [all]
2025-10-03 13:37:25.072591 | 
2025-10-03 13:37:25.072689 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-10-03 13:37:25.137002 | controller | ok
2025-10-03 13:37:25.142222 | 
2025-10-03 13:37:25.142328 | TASK [mirror-info-fork : Create /etc/ci]
2025-10-03 13:37:25.516984 | controller | changed
2025-10-03 13:37:25.522832 | 
2025-10-03 13:37:25.522972 | TASK [mirror-info-fork : Install ci_mirror script]
2025-10-03 13:37:26.353744 | controller | changed
2025-10-03 13:37:26.364978 | 
2025-10-03 13:37:26.365059 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2025-10-03 13:37:26.747895 | controller | changed:
2025-10-03 13:37:26.748105 | controller | {
2025-10-03 13:37:26.748135 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2025-10-03 13:37:26.748165 | controller | }
2025-10-03 13:37:26.967245 | controller | changed:
2025-10-03 13:37:26.968038 | controller | {
2025-10-03 13:37:26.968088 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2025-10-03 13:37:26.968114 | controller | }
2025-10-03 13:37:27.187067 | controller | changed:
2025-10-03 13:37:27.187260 | controller | {
2025-10-03 13:37:27.187299 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com"
2025-10-03 13:37:27.187323 | controller | }
2025-10-03 13:37:27.402722 | controller | changed:
2025-10-03 13:37:27.402826 | controller | {
2025-10-03 13:37:27.402857 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2025-10-03 13:37:27.402880 | controller | }
2025-10-03 13:37:27.615689 | controller | changed:
2025-10-03 13:37:27.615777 | controller | {
2025-10-03 13:37:27.615805 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2025-10-03 13:37:27.615828 | controller | }
2025-10-03 13:37:27.828027 | controller | changed:
2025-10-03 13:37:27.828177 | controller | {
2025-10-03 13:37:27.828210 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2025-10-03 13:37:27.828233 | controller | }
2025-10-03 13:37:28.031457 | controller | changed:
2025-10-03 13:37:28.031607 | controller | {
2025-10-03 13:37:28.031640 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDLOQd4ZLtkZXQGY6UwAr/06ppWQK4fDO3HaqxPk98csyOCBXsliSKK39Bso828+5srIXiW7aI6aC9P5mwi4mUZlGPfJlQbfrcGvY+b/SocuvaGK+1RrHLoJCT52LBhwgrzlXio2jeksZeein8iaTrhsPrOAs7KggIL/rB9hEiB3NaOPWhhoCP4vlW6MEMExGcqB/1FVxXFBPnLkEyW0Lk7ycVflZl2ocRxbfjZi0+tI1Wlinp8PvSQSc/WVrAcDgKjc/mB4ODPOyYy3G8FHgfMsrXSDEyjBKgLKMsdCrAUcqJQWjkqXleXSYOV4q3pzL+9umK+q/e3P/bIoSFQzmJKTU1eDfuvPXmow9F5H54fii/Da7ezlMJ+wPGHJrRAkmzvMbALy7xwswLhZMkOGNtRcPqaKYRmIBKpw3o6bCTtcNUHOtOQnzwY8JzrM2eBWJBXAANYw+9/ho80JIiwhg29CFNpVBuHbql2YxJQNrnl90guN65rYNpDxdIluweyUf8= anbanerj@kaermorhen"
2025-10-03 13:37:28.031664 | controller | }
2025-10-03 13:37:28.246353 | controller | changed:
2025-10-03 13:37:28.246444 | controller | {
2025-10-03 13:37:28.246473 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC3VwV8Im9kRm49lt3tM36hj4Zv27FxGo4C1Q/0jqhzFmHY7RHbmeRr8ObhwWoHjXSozKWg8FL5ER0z3hTwL0W6lez3sL7hUaCmSuZmG5Hnl3x4vTSxDI9JZ/Y65rtYiiWQo2fC5xJhU/4+0e5e/pseCm8cKRSu+SaxhO+sd6FDojA2x1BzOzKiQRDy/1zWGp/cZkxcEuB1wHI5LMzN03c67vmbu+fhZRAUO4dQkvcnj2LrhQtpa+ytvnSjr8icMDosf1OsbSffwZFyHB/hfWGAfe0eIeSA2XPraxiPknXxiPKx2MJsaUTYbsZcm3EjFdHBBMumw5rBI74zLrMRvCO9GwBEmGT4rFng1nP+yw5DB8sn2zqpOsPg1LYRwCPOUveC13P6pgsZZPh812e8v5EKnETct+5XI3dVpdw6CnNiLwAyVAF15DJvBGT/u1k0Myg/bQn+Gv9k2MSj6LvQmf6WbZu2Wgjm30z3FyCneBqTL7mLF19YXzeC0ufHz5pnO1E= dasm@fedora"
2025-10-03 13:37:28.246496 | controller | }
2025-10-03 13:37:28.451582 | controller | changed:
2025-10-03 13:37:28.451670 | controller | {
2025-10-03 13:37:28.451699 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2025-10-03 13:37:28.451721 | controller | }
2025-10-03 13:37:28.662375 | controller | changed:
2025-10-03 13:37:28.662488 | controller | {
2025-10-03 13:37:28.662527 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2025-10-03 13:37:28.662557 | controller | }
2025-10-03 13:37:28.868131 | controller | changed:
2025-10-03 13:37:28.868238 | controller | {
2025-10-03 13:37:28.868415 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2025-10-03 13:37:28.868454 | controller | }
2025-10-03 13:37:29.085223 | controller | changed:
2025-10-03 13:37:29.085330 | controller | {
2025-10-03 13:37:29.085361 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2025-10-03 13:37:29.085384 | controller | }
2025-10-03 13:37:29.286200 | controller | changed:
2025-10-03 13:37:29.286297 | controller | {
2025-10-03 13:37:29.286327 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2025-10-03 13:37:29.286350 | controller | }
2025-10-03 13:37:29.506209 | controller | changed:
2025-10-03 13:37:29.506309 | controller | {
2025-10-03 13:37:29.506337 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2025-10-03 13:37:29.506360 | controller | }
2025-10-03 13:37:29.719994 | controller | changed:
2025-10-03 13:37:29.720092 | controller | {
2025-10-03 13:37:29.720120 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2025-10-03 13:37:29.720142 | controller | }
2025-10-03 13:37:29.933103 | controller | changed:
2025-10-03 13:37:29.933194 | controller | {
2025-10-03 13:37:29.933221 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2025-10-03 13:37:29.933242 | controller | }
2025-10-03 13:37:30.140109 | controller | changed:
2025-10-03 13:37:30.140200 | controller | {
2025-10-03 13:37:30.140228 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQCfNtF7NvKl915TGsGGoseUb06Hj8L/S4toWf0hExeY+F00woL6NvBlJD0nDct+P5a22I4EhvoQCRQ8reaPCm1lybR3uiRIJsj+8zkVvLwby9LXzfZorlNG9ofjd00FEmB09uW/YvTl6Q9XwwwX6tInzIOv3TMqTHHGOL74ibbj8J/FJR0cFEyj0z4WQRvtkh32xAHl83gbuINryMt0sqRI+clj2381NKL55DRLQrVw0gsfqqxiHAnXg21qWmc4J+b9e9kiuAFQjcjwTVkwJCcg3xbPwC/qokYRby/Y5S40UUd7/jEARGXT7RZgpzTuDd1oZiCVrnrqJNPaMNdVv5MLeFdf1B7iIe5aa/fGouX7AO4SdKhZUdnJmCFAGvjC6S3JMZ2wAcUl+OHnssfmdj7XL50cLo27vjuzMtLAgSqi6N99m92WCF2s8J9aVzszX7Xz9OKZCeGsiVJp3/NdABKzSEAyM9xBD/5Vho894Sav+otpySHe3p6RUTgbB5Zu8VyZRZ/UtB3ueXxyo764yrc6qWIDqrehm84Xm9g+/jpIBzGPl07NUNJpdt/6Sgf9RIKXw/7XypO5yZfUcuFNGTxLfqjTNrtgLZNcjfav6sSdVXVcMPL//XNuRdKmVFaO76eV/oGMQGr1fGcCD+N+CpI7+Q+fCNB6VFWG4nZFuI/Iuw== averdagu@redhat.com"
2025-10-03 13:37:30.140249 | controller | }
2025-10-03 13:37:30.354144 | controller | changed:
2025-10-03 13:37:30.354278 | controller | {
2025-10-03 13:37:30.354307 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDq8l27xI+QlQVdS4djp9ogSoyrNE2+Ox6vKPdhSNL1J3PE5w+WCSvMz9A5gnNuH810zwbekEApbxTze/gLQJwBHA52CChfURpXrFaxY7ePXRElwKAL3mJfzBWY/c5jnNL9TCVmFJTGZkFZP3Nh+BMgZvL6xBkt3WKm6Uq18qzd9XeKcZusrA+O+uLv1fVeQnadY9RIqOCyeFYCzLWrUfTyE8x/XG0hAWIM7qpnF2cALQS2h9n4hW5ybiUN790H08wf9hFwEf5nxY9Z9dVkPFQiTSGKNBzmnCXU9skxS/xhpFjJ5duGSZdtAHe9O+nGZm9c67hxgtf8e5PDuqAdXEv2cf6e3VBAt+Bz8EKI3yosTj0oZHfwr42Yzb1l/SKy14Rggsrc9KAQlrGXan6+u2jcQqqx7l+SWmnpFiWTV9u5cWj2IgOhApOitmRBPYqk9rE2usfO0hLn/Pj/R/Nau4803e1/EikdLE7Ps95s9mX5jRDjAoUa2JwFF5RsVFyL910= ashigupt@ashigupt.remote.csb"
2025-10-03 13:37:30.354339 | controller | }
2025-10-03 13:37:30.568987 | controller | changed:
2025-10-03 13:37:30.569118 | controller | {
2025-10-03 13:37:30.569146 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2025-10-03 13:37:30.569168 | controller | }
2025-10-03 13:37:30.788016 | controller | changed:
2025-10-03 13:37:30.788109 | controller | {
2025-10-03 13:37:30.788136 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2025-10-03 13:37:30.788158 | controller | }
2025-10-03 13:37:30.999202 | controller | changed:
2025-10-03 13:37:30.999291 | controller | {
2025-10-03 13:37:30.999319 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2025-10-03 13:37:30.999340 | controller | }
2025-10-03 13:37:31.207108 | controller | changed:
2025-10-03 13:37:31.207244 | controller | {
2025-10-03 13:37:31.207271 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2025-10-03 13:37:31.207291 | controller | }
2025-10-03 13:37:31.417029 | controller | changed:
2025-10-03 13:37:31.417100 | controller | {
2025-10-03 13:37:31.417128 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQDZdI7t1cxYx65heVI24HTV4F7oQLW1zyfxHreL2TIJKxjyrUUKIFEUmTutcBlJRLNT2Eoix6x1sOw9YrchloCLcn//SGfTElr9mSc5jbjb7QXEU+zJMhtxyEJ1Po3CUGnj7ckiIXw7wcawZtrEOAQ9pH3ExYCJcEMiyNjRQZCxT3tPK+S4B95EWh5Fsrz9CkwpjNRPPH7LigCeQTM3Wc7r97utAslBUUvYceDSLA7rMgkitJE38b7rZBeYzsGQ8YYUBjTCtehqQXxCRjizbHWaaZkBU+N3zkKB6n/iCNGIO690NK7A/qb6msTijiz1PeuM8ThOsi9qXnbX5v0PoTpcFSojV7NHAQ71f0XXuS43FhZctT+Dcx44dT8Fb5vJu2cJGrk+qF8ZgJYNpRS7gPg0EG2EqjK7JMf9ULdjSu0r+KlqIAyLvtzT4eOnQipoKlb/WG5D/0ohKv7OMQ352ggfkBFIQsRXyyTCT98Ft9juqPuahi3CAQmP4H9dyE+7+Kz437PEtsxLmfm6naNmWi7Ee1DqWPwS8rEajsm4sNM4wW9gdBboJQtc0uZw0DfLj1I9r3Mc8Ol0jYtz0yNQDSzVLrGCaJlC311trU70tZ+ZkAVV6Mn8lOhSbj1cK0lvSr6ZK4dgqGl3I1eTZJJhbLNdg7UOVaiRx9543+C/p/As7w== brjackma@redhat.com"
2025-10-03 13:37:31.417150 | controller | }
2025-10-03 13:37:31.624041 | controller | changed:
2025-10-03 13:37:31.624118 | controller | {
2025-10-03 13:37:31.624147 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2025-10-03 13:37:31.624170 | controller | }
2025-10-03 13:37:31.841926 | controller | changed:
2025-10-03 13:37:31.842017 | controller | {
2025-10-03 13:37:31.842044 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2025-10-03 13:37:31.842064 | controller | }
2025-10-03 13:37:32.048651 | controller | changed:
2025-10-03 13:37:32.048736 | controller | {
2025-10-03 13:37:32.048763 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2025-10-03 13:37:32.048784 | controller | }
2025-10-03 13:37:32.073426 | 
2025-10-03 13:37:32.073509 | TASK [Set timezone to UTC]
2025-10-03 13:37:32.491046 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2025-10-03 13:37:32.498427 | 
2025-10-03 13:37:32.498494 | TASK [Create nodepool directory]
2025-10-03 13:37:32.715051 | controller | changed
2025-10-03 13:37:32.720555 | 
2025-10-03 13:37:32.720624 | TASK [Create nodepool sub_nodes file]
2025-10-03 13:37:33.252033 | controller | changed
2025-10-03 13:37:33.257077 | 
2025-10-03 13:37:33.257149 | TASK [Create nodepool sub_nodes_private file]
2025-10-03 13:37:33.820244 | controller | changed
2025-10-03 13:37:33.826154 | 
2025-10-03 13:37:33.826234 | LOOP [Populate nodepool sub_nodes file]
2025-10-03 13:37:33.865783 | 
2025-10-03 13:37:33.865942 | LOOP [Populate nodepool sub_nodes_private file]
2025-10-03 13:37:33.894847 | 
2025-10-03 13:37:33.895027 | TASK [Create nodepool primary file]
2025-10-03 13:37:33.918624 | controller | skipping: Conditional result was False
2025-10-03 13:37:33.924216 | 
2025-10-03 13:37:33.924304 | TASK [Create nodepool node_private for this node]
2025-10-03 13:37:34.470343 | controller | changed
2025-10-03 13:37:34.477384 | 
2025-10-03 13:37:34.477452 | LOOP [Copy ssh keys to nodepool directory]
2025-10-03 13:37:34.824457 | controller | ok: Item: id_rsa Runtime: 0:00:00.006071
2025-10-03 13:37:34.824627 | 
2025-10-03 13:37:34.994323 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.004918
2025-10-03 13:37:35.003234 | 
2025-10-03 13:37:35.003336 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2025-10-03 13:37:35.617897 | controller | changed
2025-10-03 13:37:35.627634 | 
2025-10-03 13:37:35.627722 | TASK [Validate sudoers config after edits]
2025-10-03 13:37:35.864564 | controller | /etc/sudoers: parsed OK
2025-10-03 13:37:35.864662 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2025-10-03 13:37:35.864674 | controller | /etc/sudoers.d/zuul: parsed OK
2025-10-03 13:37:35.864680 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2025-10-03 13:37:36.165835 | controller | ok: Runtime: 0:00:00.005777
2025-10-03 13:37:36.172796 | 
2025-10-03 13:37:36.172862 | TASK [Show the environment passed in to job shell scripts]
2025-10-03 13:37:36.391549 | controller | SHELL=/bin/bash
2025-10-03 13:37:36.391598 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2025-10-03 13:37:36.391608 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2025-10-03 13:37:36.391615 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/62/3362/41f2edaa0ac45cd85919f70775e84cf472326a6e
2025-10-03 13:37:36.391621 | controller | PWD=/home/zuul
2025-10-03 13:37:36.391627 | controller | ZUUL_PIPELINE=github-check
2025-10-03 13:37:36.391632 | controller | LOGNAME=zuul
2025-10-03 13:37:36.391638 | controller | XDG_SESSION_TYPE=tty
2025-10-03 13:37:36.391644 | controller | _=/usr/bin/env
2025-10-03 13:37:36.391687 | controller | MOTD_SHOWN=pam
2025-10-03 13:37:36.391696 | controller | HOME=/home/zuul
2025-10-03 13:37:36.391702 | controller | LANG=en_US.UTF-8
2025-10-03 13:37:36.391707 | controller | SSH_CONNECTION=192.168.26.12 59156 192.168.26.45 22
2025-10-03 13:37:36.391713 | controller | TOX_TESTENV_PASSENV=ZUUL_UUID ZUUL_PROJECT ZUUL_SHORT_PROJECT_NAME ZUUL_PIPELINE ZUUL_VOTING WORKSPACE BUILD_TIMEOUT ZUUL_BRANCH ZUUL_CHANGES ZUUL_CHANGE_IDS ZUUL_CHANGE ZUUL_PATCHSET
2025-10-03 13:37:36.391722 | controller | ZUUL_CHANGE_IDS=3362,41f2edaa0ac45cd85919f70775e84cf472326a6e
2025-10-03 13:37:36.391728 | controller | WORKSPACE=/home/zuul/workspace
2025-10-03 13:37:36.391734 | controller | XDG_SESSION_CLASS=user
2025-10-03 13:37:36.391739 | controller | SELINUX_ROLE_REQUESTED=
2025-10-03 13:37:36.391745 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2025-10-03 13:37:36.391750 | controller | USER=zuul
2025-10-03 13:37:36.391756 | controller | ZUUL_VOTING=True
2025-10-03 13:37:36.391778 | controller | BUILD_TIMEOUT=1800000
2025-10-03 13:37:36.391784 | controller | SELINUX_USE_CURRENT_RANGE=
2025-10-03 13:37:36.391789 | controller | SHLVL=1
2025-10-03 13:37:36.391795 | controller | ZUUL_PATCHSET=41f2edaa0ac45cd85919f70775e84cf472326a6e
2025-10-03 13:37:36.391800 | controller | XDG_SESSION_ID=1
2025-10-03 13:37:36.391806 | controller | ZUUL_BRANCH=main
2025-10-03 13:37:36.391811 | controller | XDG_RUNTIME_DIR=/run/user/1000
2025-10-03 13:37:36.391816 | controller | SSH_CLIENT=192.168.26.12 59156 22
2025-10-03 13:37:36.391822 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2025-10-03 13:37:36.391827 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2025-10-03 13:37:36.391835 | controller | which_declare=declare -f
2025-10-03 13:37:36.391841 | controller | PATH=/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2025-10-03 13:37:36.391846 | controller | SELINUX_LEVEL_REQUESTED=
2025-10-03 13:37:36.391852 | controller | ZUUL_CHANGE=3362
2025-10-03 13:37:36.391857 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2025-10-03 13:37:36.391863 | controller | ZUUL_UUID=0b811b84cd9d468e82441f3dfc0bfdab
2025-10-03 13:37:36.391869 | controller | BASH_FUNC_which%%=() {  ( alias;
2025-10-03 13:37:36.391874 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2025-10-03 13:37:36.391880 | controller | }
2025-10-03 13:37:36.702043 | controller | ok: Runtime: 0:00:00.005907
2025-10-03 13:37:36.708039 | 
2025-10-03 13:37:36.708109 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2025-10-03 13:37:36.731611 | controller | skipping: Conditional result was False
2025-10-03 13:37:36.737114 | 
2025-10-03 13:37:36.737199 | TASK [Symlink /home/zuul-worker/workspace]
2025-10-03 13:37:37.263806 | controller | skipping: Conditional result was False
2025-10-03 13:37:37.270879 | 
2025-10-03 13:37:37.271004 | TASK [Ensure legacy workspace directory]
2025-10-03 13:37:37.477673 | controller | changed
2025-10-03 13:37:37.515529 | 
2025-10-03 13:37:37.515606 | PLAY RECAP
2025-10-03 13:37:37.515650 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-03 13:37:37.515673 | 
2025-10-03 13:37:37.603876 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-10-03 13:37:37.606295 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-10-03 13:37:38.247464 | 
2025-10-03 13:37:38.247565 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2025-10-03 13:37:38.275071 | 
2025-10-03 13:37:38.275184 | TASK [Create zuul-output directory]
2025-10-03 13:37:38.601720 | controller | changed
2025-10-03 13:37:38.608493 | 
2025-10-03 13:37:38.608630 | TASK [Slurp Zuul inventory test]
2025-10-03 13:37:38.892156 | controller -> localhost | ok
2025-10-03 13:37:38.899221 | 
2025-10-03 13:37:38.899315 | TASK [Save zuul inventory]
2025-10-03 13:37:39.650131 | controller | changed
2025-10-03 13:37:39.655267 | 
2025-10-03 13:37:39.655339 | TASK [Save zuul vars without the change_message]
2025-10-03 13:37:40.233300 | controller | changed
2025-10-03 13:37:40.257485 | 
2025-10-03 13:37:40.257557 | PLAY RECAP
2025-10-03 13:37:40.257605 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-03 13:37:40.257628 | 
2025-10-03 13:37:40.349117 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-10-03 13:37:40.349848 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-10-03 13:37:40.928183 | 
2025-10-03 13:37:40.928290 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2025-10-03 13:37:40.948803 | 
2025-10-03 13:37:40.948888 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2025-10-03 13:37:40.967735 | controller | ok
2025-10-03 13:37:40.985063 | 
2025-10-03 13:37:40.985169 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-10-03 13:37:41.029310 | controller | skipping: Conditional result was False
2025-10-03 13:37:41.035851 | 
2025-10-03 13:37:41.035967 | TASK [mirror-info-fork : Create /etc/ci]
2025-10-03 13:37:41.369850 | controller | ok
2025-10-03 13:37:41.376699 | 
2025-10-03 13:37:41.376792 | TASK [mirror-info-fork : Install ci_mirror script]
2025-10-03 13:37:42.005057 | controller | ok
2025-10-03 13:37:42.016512 | 
2025-10-03 13:37:42.016611 | TASK [Prepare workspace]
2025-10-03 13:37:42.035779 | controller | ok
2025-10-03 13:37:42.056331 | 
2025-10-03 13:37:42.056427 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-03 13:37:42.371276 | controller | ok
2025-10-03 13:37:42.378836 | 
2025-10-03 13:37:42.378948 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-03 13:37:44.508598 | controller | Output suppressed because no_log was given
2025-10-03 13:37:44.519509 | 
2025-10-03 13:37:44.519626 | LOOP [Create zuul-output directory]
2025-10-03 13:37:44.719867 | controller | changed: "/home/zuul/ci-framework-data/logs"
2025-10-03 13:37:44.895228 | controller | ok: "/home/zuul/zuul-output/logs"
2025-10-03 13:37:44.905584 | 
2025-10-03 13:37:44.905667 | TASK [Install required packages]
2025-10-03 13:38:35.778697 | controller | changed
2025-10-03 13:38:35.784327 | 
2025-10-03 13:38:35.784415 | TASK [Install venv]
2025-10-03 13:39:37.097976 | controller | changed
2025-10-03 13:39:37.124639 | 
2025-10-03 13:39:37.124740 | PLAY RECAP
2025-10-03 13:39:37.124803 | controller | ok: 7 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-03 13:39:37.124830 | 
2025-10-03 13:39:37.219499 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-10-03 13:39:37.220502 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-10-03 13:39:37.803258 | 
2025-10-03 13:39:37.803373 | PLAY [Run ci/playbooks/molecule-test.yml]
2025-10-03 13:39:37.824813 | 
2025-10-03 13:39:37.824896 | TASK [Gather required facts]
2025-10-03 13:39:38.312601 | controller | ok
2025-10-03 13:39:38.318604 | 
2025-10-03 13:39:38.318732 | TASK [Load environment var if instructed to]
2025-10-03 13:39:38.345051 | controller | skipping: Conditional result was False
2025-10-03 13:39:38.353469 | 
2025-10-03 13:39:38.353570 | TASK [Run molecule]
2025-10-03 13:39:39.313783 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2025-10-03 13:39:39.393519 | controller | INFO     Running default > prepare
2025-10-03 13:39:40.056744 | controller |
2025-10-03 13:39:40.056856 | controller | PLAY [Prepare] *****************************************************************
2025-10-03 13:39:40.056953 | controller |
2025-10-03 13:39:40.057439 | controller | TASK [Gathering Facts] *********************************************************
2025-10-03 13:39:40.057553 | controller | Friday 03 October 2025  13:39:40 +0000 (0:00:00.011)       0:00:00.011 ********
2025-10-03 13:39:40.890140 | controller | ok: [instance]
2025-10-03 13:39:40.890226 | controller |
2025-10-03 13:39:40.890371 | controller | TASK [Create dummy env file] ***************************************************
2025-10-03 13:39:40.890495 | controller | Friday 03 October 2025  13:39:40 +0000 (0:00:00.834)       0:00:00.845 ********
2025-10-03 13:39:41.388754 | controller | changed: [instance]
2025-10-03 13:39:41.388844 | controller |
2025-10-03 13:39:41.388957 | controller | TASK [Create dummy playbook] ***************************************************
2025-10-03 13:39:41.389064 | controller | Friday 03 October 2025  13:39:41 +0000 (0:00:00.498)       0:00:01.344 ********
2025-10-03 13:39:43.290430 | controller | changed: [instance] => (item=dummy-1.yml)
2025-10-03 13:39:43.290507 | controller | changed: [instance] => (item=dummy-2.yml)
2025-10-03 13:39:43.290615 | controller | changed: [instance] => (item=dummy-3.yml)
2025-10-03 13:39:43.290732 | controller | changed: [instance] => (item=dummy-4.yml)
2025-10-03 13:39:43.290839 | controller | changed: [instance] => (item=dummy-5.yml)
2025-10-03 13:39:43.290931 | controller | changed: [instance] => (item=dummy-6.yml)
2025-10-03 13:39:43.291024 | controller |
2025-10-03 13:39:43.291127 | controller | TASK [Remove dummy file for retry playbook test] *******************************
2025-10-03 13:39:43.291224 | controller | Friday 03 October 2025  13:39:43 +0000 (0:00:01.901)       0:00:03.245 ********
2025-10-03 13:39:43.568867 | controller | ok: [instance]
2025-10-03 13:39:43.568915 | controller |
2025-10-03 13:39:43.569041 | controller | TASK [Create dummy retry playbook] *********************************************
2025-10-03 13:39:43.569150 | controller | Friday 03 October 2025  13:39:43 +0000 (0:00:00.278)       0:00:03.524 ********
2025-10-03 13:39:43.911647 | controller | changed: [instance]
2025-10-03 13:39:43.911749 | controller |
2025-10-03 13:39:43.911875 | controller | PLAY RECAP *********************************************************************
2025-10-03 13:39:43.911987 | controller | instance                   : ok=5    changed=3    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-10-03 13:39:43.912093 | controller |
2025-10-03 13:39:43.912187 | controller | Friday 03 October 2025  13:39:43 +0000 (0:00:00.343)       0:00:03.867 ********
2025-10-03 13:39:43.912286 | controller | ===============================================================================
2025-10-03 13:39:43.912415 | controller | Create dummy playbook --------------------------------------------------- 1.90s
2025-10-03 13:39:43.912521 | controller | Gathering Facts --------------------------------------------------------- 0.83s
2025-10-03 13:39:43.912637 | controller | Create dummy env file --------------------------------------------------- 0.50s
2025-10-03 13:39:43.912753 | controller | Create dummy retry playbook --------------------------------------------- 0.34s
2025-10-03 13:39:43.912858 | controller | Remove dummy file for retry playbook test ------------------------------- 0.28s
2025-10-03 13:39:43.967583 | controller | INFO     Running default > converge
2025-10-03 13:39:44.398748 | controller |
2025-10-03 13:39:44.399264 | controller | PLAY [Converge] ****************************************************************
2025-10-03 13:39:45.200462 | controller |
2025-10-03 13:39:45.200501 | controller | TASK [Gathering Facts] *********************************************************
2025-10-03 13:39:45.200511 | controller | Friday 03 October 2025  13:39:44 +0000 (0:00:00.016)       0:00:00.016 ********
2025-10-03 13:39:45.200528 | controller | ok: [instance]
2025-10-03 13:39:45.200558 | controller |
2025-10-03 13:39:45.200568 | controller | TASK [No hook] *****************************************************************
2025-10-03 13:39:45.200699 | controller | Friday 03 October 2025  13:39:45 +0000 (0:00:00.802)       0:00:00.818 ********
2025-10-03 13:39:45.230045 | controller |
2025-10-03 13:39:45.287796 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-10-03 13:39:45.287839 | controller | Friday 03 October 2025  13:39:45 +0000 (0:00:00.029)       0:00:00.847 ********
2025-10-03 13:39:45.287852 | controller | ok: [instance]
2025-10-03 13:39:45.361369 | controller |
2025-10-03 13:39:45.361433 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-10-03 13:39:45.361442 | controller | Friday 03 October 2025  13:39:45 +0000 (0:00:00.057)       0:00:00.905 ********
2025-10-03 13:39:45.361453 | controller | ok: [instance]
2025-10-03 13:39:45.436206 | controller |
2025-10-03 13:39:45.436241 | controller | TASK [run_hook : Loop on hooks for no_hook] ************************************
2025-10-03 13:39:45.436252 | controller | Friday 03 October 2025  13:39:45 +0000 (0:00:00.073)       0:00:00.978 ********
2025-10-03 13:39:45.436264 | controller | skipping: [instance]
2025-10-03 13:39:45.436365 | controller |
2025-10-03 13:39:45.436526 | controller | TASK [Ensure we do not have ceph_uuid] *****************************************
2025-10-03 13:39:45.436680 | controller | Friday 03 October 2025  13:39:45 +0000 (0:00:00.075)       0:00:01.054 ********
2025-10-03 13:39:45.459633 | controller | ok: [instance] => changed=false
2025-10-03 13:39:45.459802 | controller |   msg: All assertions passed
2025-10-03 13:39:45.459928 | controller |
2025-10-03 13:39:45.460056 | controller | TASK [Combined hooks] **********************************************************
2025-10-03 13:39:45.460182 | controller | Friday 03 October 2025  13:39:45 +0000 (0:00:00.023)       0:00:01.077 ********
2025-10-03 13:39:45.488850 | controller |
2025-10-03 13:39:45.489000 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-10-03 13:39:45.489124 | controller | Friday 03 October 2025  13:39:45 +0000 (0:00:00.029)       0:00:01.107 ********
2025-10-03 13:39:45.548576 | controller | ok: [instance]
2025-10-03 13:39:45.548728 | controller |
2025-10-03 13:39:45.548864 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-10-03 13:39:45.548992 | controller | Friday 03 October 2025  13:39:45 +0000 (0:00:00.059)       0:00:01.166 ********
2025-10-03 13:39:45.621276 | controller | ok: [instance]
2025-10-03 13:39:45.621432 | controller |
2025-10-03 13:39:45.621573 | controller | TASK [run_hook : Loop on hooks for run_molecule] *******************************
2025-10-03 13:39:45.621717 | controller | Friday 03 October 2025  13:39:45 +0000 (0:00:00.072)       0:00:01.239 ********
2025-10-03 13:39:45.744293 | 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-03 13:39:45.744453 | 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-03 13:39:45.744772 | 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-03 13:39:45.744883 | controller |
2025-10-03 13:39:45.745028 | controller | TASK [run_hook : Set playbook path for 01 Default noop hook] *******************
2025-10-03 13:39:45.745136 | controller | Friday 03 October 2025  13:39:45 +0000 (0:00:00.122)       0:00:01.362 ********
2025-10-03 13:39:45.795294 | controller | ok: [instance]
2025-10-03 13:39:45.795416 | controller |
2025-10-03 13:39:45.795549 | controller | TASK [run_hook : Get file stat] ************************************************
2025-10-03 13:39:45.795688 | controller | Friday 03 October 2025  13:39:45 +0000 (0:00:00.051)       0:00:01.413 ********
2025-10-03 13:39:46.085374 | controller | ok: [instance]
2025-10-03 13:39:46.102909 | controller |
2025-10-03 13:39:46.102931 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-10-03 13:39:46.102944 | controller | Friday 03 October 2025  13:39:46 +0000 (0:00:00.289)       0:00:01.702 ********
2025-10-03 13:39:46.102955 | controller | skipping: [instance]
2025-10-03 13:39:46.384414 | controller |
2025-10-03 13:39:46.384445 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-10-03 13:39:46.384453 | controller | Friday 03 October 2025  13:39:46 +0000 (0:00:00.017)       0:00:01.720 ********
2025-10-03 13:39:46.384471 | controller | ok: [instance]
2025-10-03 13:39:46.384495 | controller |
2025-10-03 13:39:46.384504 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-10-03 13:39:46.384668 | controller | Friday 03 October 2025  13:39:46 +0000 (0:00:00.281)       0:00:02.002 ********
2025-10-03 13:39:46.406192 | controller | ok: [instance]
2025-10-03 13:39:46.696851 | controller |
2025-10-03 13:39:46.696881 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-10-03 13:39:46.696889 | controller | Friday 03 October 2025  13:39:46 +0000 (0:00:00.021)       0:00:02.023 ********
2025-10-03 13:39:46.696900 | controller | ok: [instance]
2025-10-03 13:39:46.882969 | controller |
2025-10-03 13:39:46.883002 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-10-03 13:39:46.883010 | controller | Friday 03 October 2025  13:39:46 +0000 (0:00:00.290)       0:00:02.314 ********
2025-10-03 13:39:46.883020 | controller | ok: [instance]
2025-10-03 13:39:47.473400 | controller |
2025-10-03 13:39:47.473430 | controller | TASK [run_hook : Run hook without retry - 01 Default noop hook] ****************
2025-10-03 13:39:47.473438 | controller | Friday 03 October 2025  13:39:46 +0000 (0:00:00.185)       0:00:02.500 ********
2025-10-03 13:39:47.473448 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_000_run_hook_without_retry_01.log
2025-10-03 13:39:47.473739 | controller | changed: [instance]
2025-10-03 13:39:47.473751 | controller |
2025-10-03 13:39:47.473759 | controller | TASK [run_hook : Run hook with retry - 01 Default noop hook] *******************
2025-10-03 13:39:47.504175 | controller | Friday 03 October 2025  13:39:47 +0000 (0:00:00.590)       0:00:03.091 ********
2025-10-03 13:39:47.504209 | controller | skipping: [instance]
2025-10-03 13:39:47.682952 | controller |
2025-10-03 13:39:47.682982 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-10-03 13:39:47.682991 | controller | Friday 03 October 2025  13:39:47 +0000 (0:00:00.030)       0:00:03.121 ********
2025-10-03 13:39:47.683001 | controller | ok: [instance]
2025-10-03 13:39:47.701345 | controller |
2025-10-03 13:39:47.701373 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-10-03 13:39:47.701380 | controller | Friday 03 October 2025  13:39:47 +0000 (0:00:00.178)       0:00:03.300 ********
2025-10-03 13:39:47.701391 | controller | skipping: [instance]
2025-10-03 13:39:47.749462 | controller |
2025-10-03 13:39:47.749500 | controller | TASK [run_hook : Set playbook path for 02 Re-run noop] *************************
2025-10-03 13:39:47.749511 | controller | Friday 03 October 2025  13:39:47 +0000 (0:00:00.018)       0:00:03.319 ********
2025-10-03 13:39:47.749523 | controller | ok: [instance]
2025-10-03 13:39:47.749551 | controller |
2025-10-03 13:39:47.749561 | controller | TASK [run_hook : Get file stat] ************************************************
2025-10-03 13:39:47.749703 | controller | Friday 03 October 2025  13:39:47 +0000 (0:00:00.048)       0:00:03.367 ********
2025-10-03 13:39:47.943638 | controller | ok: [instance]
2025-10-03 13:39:47.960759 | controller |
2025-10-03 13:39:47.960788 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-10-03 13:39:47.960796 | controller | Friday 03 October 2025  13:39:47 +0000 (0:00:00.193)       0:00:03.561 ********
2025-10-03 13:39:47.960807 | controller | skipping: [instance]
2025-10-03 13:39:48.163650 | controller |
2025-10-03 13:39:48.163681 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-10-03 13:39:48.163689 | controller | Friday 03 October 2025  13:39:47 +0000 (0:00:00.017)       0:00:03.578 ********
2025-10-03 13:39:48.163699 | controller | ok: [instance]
2025-10-03 13:39:48.183962 | controller |
2025-10-03 13:39:48.183990 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-10-03 13:39:48.183998 | controller | Friday 03 October 2025  13:39:48 +0000 (0:00:00.202)       0:00:03.781 ********
2025-10-03 13:39:48.184008 | controller | ok: [instance]
2025-10-03 13:39:48.380007 | controller |
2025-10-03 13:39:48.380037 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-10-03 13:39:48.380052 | controller | Friday 03 October 2025  13:39:48 +0000 (0:00:00.020)       0:00:03.801 ********
2025-10-03 13:39:48.380062 | controller | ok: [instance]
2025-10-03 13:39:48.580440 | controller |
2025-10-03 13:39:48.580487 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-10-03 13:39:48.580497 | controller | Friday 03 October 2025  13:39:48 +0000 (0:00:00.196)       0:00:03.997 ********
2025-10-03 13:39:48.580508 | controller | ok: [instance]
2025-10-03 13:39:48.580526 | controller |
2025-10-03 13:39:48.580534 | controller | TASK [run_hook : Run hook without retry - 02 Re-run noop] **********************
2025-10-03 13:39:48.580557 | controller | Friday 03 October 2025  13:39:48 +0000 (0:00:00.200)       0:00:04.198 ********
2025-10-03 13:39:49.192940 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_001_run_hook_without_retry_02_re.log
2025-10-03 13:39:49.222083 | controller | changed: [instance]
2025-10-03 13:39:49.222112 | controller |
2025-10-03 13:39:49.222120 | controller | TASK [run_hook : Run hook with retry - 02 Re-run noop] *************************
2025-10-03 13:39:49.222126 | controller | Friday 03 October 2025  13:39:49 +0000 (0:00:00.612)       0:00:04.810 ********
2025-10-03 13:39:49.222136 | controller | skipping: [instance]
2025-10-03 13:39:49.396261 | controller |
2025-10-03 13:39:49.396288 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-10-03 13:39:49.396296 | controller | Friday 03 October 2025  13:39:49 +0000 (0:00:00.029)       0:00:04.839 ********
2025-10-03 13:39:49.396306 | controller | ok: [instance]
2025-10-03 13:39:49.413377 | controller |
2025-10-03 13:39:49.413402 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-10-03 13:39:49.413410 | controller | Friday 03 October 2025  13:39:49 +0000 (0:00:00.174)       0:00:05.014 ********
2025-10-03 13:39:49.413420 | controller | skipping: [instance]
2025-10-03 13:39:49.413635 | controller |
2025-10-03 13:39:49.413649 | controller | TASK [run_hook : Set playbook path for 03 single hook] *************************
2025-10-03 13:39:49.461732 | controller | Friday 03 October 2025  13:39:49 +0000 (0:00:00.017)       0:00:05.031 ********
2025-10-03 13:39:49.461766 | controller | ok: [instance]
2025-10-03 13:39:49.649722 | controller |
2025-10-03 13:39:49.649752 | controller | TASK [run_hook : Get file stat] ************************************************
2025-10-03 13:39:49.649760 | controller | Friday 03 October 2025  13:39:49 +0000 (0:00:00.047)       0:00:05.079 ********
2025-10-03 13:39:49.649770 | controller | ok: [instance]
2025-10-03 13:39:49.666273 | controller |
2025-10-03 13:39:49.666299 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-10-03 13:39:49.666307 | controller | Friday 03 October 2025  13:39:49 +0000 (0:00:00.187)       0:00:05.267 ********
2025-10-03 13:39:49.666334 | controller | skipping: [instance]
2025-10-03 13:39:49.859978 | controller |
2025-10-03 13:39:49.860009 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-10-03 13:39:49.860017 | controller | Friday 03 October 2025  13:39:49 +0000 (0:00:00.016)       0:00:05.284 ********
2025-10-03 13:39:49.860027 | controller | ok: [instance]
2025-10-03 13:39:49.878669 | controller |
2025-10-03 13:39:49.878699 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-10-03 13:39:49.878709 | controller | Friday 03 October 2025  13:39:49 +0000 (0:00:00.193)       0:00:05.477 ********
2025-10-03 13:39:49.878720 | controller | ok: [instance]
2025-10-03 13:39:50.074222 | controller |
2025-10-03 13:39:50.074253 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-10-03 13:39:50.074261 | controller | Friday 03 October 2025  13:39:49 +0000 (0:00:00.018)       0:00:05.496 ********
2025-10-03 13:39:50.074270 | controller | ok: [instance]
2025-10-03 13:39:50.259997 | controller |
2025-10-03 13:39:50.260027 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-10-03 13:39:50.260036 | controller | Friday 03 October 2025  13:39:50 +0000 (0:00:00.195)       0:00:05.691 ********
2025-10-03 13:39:50.260047 | controller | ok: [instance]
2025-10-03 13:39:52.164992 | controller |
2025-10-03 13:39:52.165022 | controller | TASK [run_hook : Run hook without retry - 03 single hook] **********************
2025-10-03 13:39:52.165030 | controller | Friday 03 October 2025  13:39:50 +0000 (0:00:00.185)       0:00:05.877 ********
2025-10-03 13:39:52.165041 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_002_run_hook_without_retry_03.log
2025-10-03 13:39:52.192337 | controller | changed: [instance]
2025-10-03 13:39:52.192374 | controller |
2025-10-03 13:39:52.192384 | controller | TASK [run_hook : Run hook with retry - 03 single hook] *************************
2025-10-03 13:39:52.192392 | controller | Friday 03 October 2025  13:39:52 +0000 (0:00:01.904)       0:00:07.782 ********
2025-10-03 13:39:52.192403 | controller | skipping: [instance]
2025-10-03 13:39:52.377386 | controller |
2025-10-03 13:39:52.377416 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-10-03 13:39:52.377424 | controller | Friday 03 October 2025  13:39:52 +0000 (0:00:00.027)       0:00:07.810 ********
2025-10-03 13:39:52.377445 | controller | ok: [instance]
2025-10-03 13:39:52.377465 | controller |
2025-10-03 13:39:52.377494 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-10-03 13:39:52.377588 | controller | Friday 03 October 2025  13:39:52 +0000 (0:00:00.185)       0:00:07.995 ********
2025-10-03 13:39:52.403348 | controller | ok: [instance]
2025-10-03 13:39:52.426959 | controller |
2025-10-03 13:39:52.426987 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-10-03 13:39:52.426995 | controller | Friday 03 October 2025  13:39:52 +0000 (0:00:00.025)       0:00:08.021 ********
2025-10-03 13:39:52.427004 | controller | ok: [instance] => changed=false
2025-10-03 13:39:52.457442 | controller |   msg: All assertions passed
2025-10-03 13:39:52.457481 | controller |
2025-10-03 13:39:52.457493 | controller | TASK [Only listed hooks] *******************************************************
2025-10-03 13:39:52.457500 | controller | Friday 03 October 2025  13:39:52 +0000 (0:00:00.023)       0:00:08.044 ********
2025-10-03 13:39:52.457509 | controller |
2025-10-03 13:39:52.515261 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-10-03 13:39:52.515291 | controller | Friday 03 October 2025  13:39:52 +0000 (0:00:00.030)       0:00:08.075 ********
2025-10-03 13:39:52.515303 | controller | ok: [instance]
2025-10-03 13:39:52.588503 | controller |
2025-10-03 13:39:52.588530 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-10-03 13:39:52.588540 | controller | Friday 03 October 2025  13:39:52 +0000 (0:00:00.057)       0:00:08.132 ********
2025-10-03 13:39:52.588551 | controller | ok: [instance]
2025-10-03 13:39:52.588728 | controller |
2025-10-03 13:39:52.588904 | controller | TASK [run_hook : Loop on hooks for list_hooks] *********************************
2025-10-03 13:39:52.589076 | controller | Friday 03 October 2025  13:39:52 +0000 (0:00:00.073)       0:00:08.206 ********
2025-10-03 13:39:52.696608 | 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-03 13:39:52.696832 | 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-03 13:39:52.696999 | controller |
2025-10-03 13:39:52.697172 | controller | TASK [run_hook : Set playbook path for Run dummy-2] ****************************
2025-10-03 13:39:52.697384 | controller | Friday 03 October 2025  13:39:52 +0000 (0:00:00.107)       0:00:08.314 ********
2025-10-03 13:39:52.745933 | controller | ok: [instance]
2025-10-03 13:39:52.935947 | controller |
2025-10-03 13:39:52.935975 | controller | TASK [run_hook : Get file stat] ************************************************
2025-10-03 13:39:52.935983 | controller | Friday 03 October 2025  13:39:52 +0000 (0:00:00.049)       0:00:08.363 ********
2025-10-03 13:39:52.935993 | controller | ok: [instance]
2025-10-03 13:39:52.952790 | controller |
2025-10-03 13:39:52.952814 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-10-03 13:39:52.952822 | controller | Friday 03 October 2025  13:39:52 +0000 (0:00:00.189)       0:00:08.553 ********
2025-10-03 13:39:52.952831 | controller | skipping: [instance]
2025-10-03 13:39:53.140764 | controller |
2025-10-03 13:39:53.140793 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-10-03 13:39:53.140801 | controller | Friday 03 October 2025  13:39:52 +0000 (0:00:00.017)       0:00:08.570 ********
2025-10-03 13:39:53.140811 | controller | ok: [instance]
2025-10-03 13:39:53.160131 | controller |
2025-10-03 13:39:53.160154 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-10-03 13:39:53.160162 | controller | Friday 03 October 2025  13:39:53 +0000 (0:00:00.187)       0:00:08.758 ********
2025-10-03 13:39:53.160171 | controller | ok: [instance]
2025-10-03 13:39:53.358566 | controller |
2025-10-03 13:39:53.358596 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-10-03 13:39:53.358605 | controller | Friday 03 October 2025  13:39:53 +0000 (0:00:00.019)       0:00:08.778 ********
2025-10-03 13:39:53.358615 | controller | ok: [instance]
2025-10-03 13:39:53.550583 | controller |
2025-10-03 13:39:53.550614 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-10-03 13:39:53.550623 | controller | Friday 03 October 2025  13:39:53 +0000 (0:00:00.198)       0:00:08.976 ********
2025-10-03 13:39:53.550633 | controller | ok: [instance]
2025-10-03 13:39:55.475339 | controller |
2025-10-03 13:39:55.475369 | controller | TASK [run_hook : Run hook without retry - Run dummy-2] *************************
2025-10-03 13:39:55.475376 | controller | Friday 03 October 2025  13:39:53 +0000 (0:00:00.192)       0:00:09.168 ********
2025-10-03 13:39:55.475399 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_003_run_hook_without_retry_run.log
2025-10-03 13:39:55.505478 | controller | changed: [instance]
2025-10-03 13:39:55.505506 | controller |
2025-10-03 13:39:55.505514 | controller | TASK [run_hook : Run hook with retry - Run dummy-2] ****************************
2025-10-03 13:39:55.505520 | controller | Friday 03 October 2025  13:39:55 +0000 (0:00:01.924)       0:00:11.092 ********
2025-10-03 13:39:55.505529 | controller | skipping: [instance]
2025-10-03 13:39:55.686943 | controller |
2025-10-03 13:39:55.686972 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-10-03 13:39:55.686985 | controller | Friday 03 October 2025  13:39:55 +0000 (0:00:00.030)       0:00:11.123 ********
2025-10-03 13:39:55.686995 | controller | ok: [instance]
2025-10-03 13:39:55.709397 | controller |
2025-10-03 13:39:55.709424 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-10-03 13:39:55.709431 | controller | Friday 03 October 2025  13:39:55 +0000 (0:00:00.181)       0:00:11.304 ********
2025-10-03 13:39:55.709441 | controller | ok: [instance]
2025-10-03 13:39:55.758434 | controller |
2025-10-03 13:39:55.758465 | controller | TASK [run_hook : Set playbook path for Run dummy-3] ****************************
2025-10-03 13:39:55.758474 | controller | Friday 03 October 2025  13:39:55 +0000 (0:00:00.022)       0:00:11.327 ********
2025-10-03 13:39:55.758486 | controller | ok: [instance]
2025-10-03 13:39:55.758512 | controller |
2025-10-03 13:39:55.758522 | controller | TASK [run_hook : Get file stat] ************************************************
2025-10-03 13:39:55.758645 | controller | Friday 03 October 2025  13:39:55 +0000 (0:00:00.049)       0:00:11.376 ********
2025-10-03 13:39:55.961792 | controller | ok: [instance]
2025-10-03 13:39:55.979071 | controller |
2025-10-03 13:39:55.979101 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-10-03 13:39:55.979110 | controller | Friday 03 October 2025  13:39:55 +0000 (0:00:00.203)       0:00:11.579 ********
2025-10-03 13:39:55.979122 | controller | skipping: [instance]
2025-10-03 13:39:56.170076 | controller |
2025-10-03 13:39:56.170105 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-10-03 13:39:56.170113 | controller | Friday 03 October 2025  13:39:55 +0000 (0:00:00.017)       0:00:11.596 ********
2025-10-03 13:39:56.170124 | controller | ok: [instance]
2025-10-03 13:39:56.191231 | controller |
2025-10-03 13:39:56.191257 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-10-03 13:39:56.191264 | controller | Friday 03 October 2025  13:39:56 +0000 (0:00:00.190)       0:00:11.787 ********
2025-10-03 13:39:56.191274 | controller | ok: [instance]
2025-10-03 13:39:56.394999 | controller |
2025-10-03 13:39:56.395028 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-10-03 13:39:56.395036 | controller | Friday 03 October 2025  13:39:56 +0000 (0:00:00.021)       0:00:11.809 ********
2025-10-03 13:39:56.395046 | controller | ok: [instance]
2025-10-03 13:39:56.583368 | controller |
2025-10-03 13:39:56.583399 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-10-03 13:39:56.583414 | controller | Friday 03 October 2025  13:39:56 +0000 (0:00:00.203)       0:00:12.012 ********
2025-10-03 13:39:56.583425 | controller | ok: [instance]
2025-10-03 13:39:58.495416 | controller |
2025-10-03 13:39:58.495448 | controller | TASK [run_hook : Run hook without retry - Run dummy-3] *************************
2025-10-03 13:39:58.495456 | controller | Friday 03 October 2025  13:39:56 +0000 (0:00:00.188)       0:00:12.201 ********
2025-10-03 13:39:58.495467 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_004_run_hook_without_retry_run.log
2025-10-03 13:39:58.495491 | controller | changed: [instance]
2025-10-03 13:39:58.495850 | controller |
2025-10-03 13:39:58.524893 | controller | TASK [run_hook : Run hook with retry - Run dummy-3] ****************************
2025-10-03 13:39:58.524921 | controller | Friday 03 October 2025  13:39:58 +0000 (0:00:01.912)       0:00:14.113 ********
2025-10-03 13:39:58.524934 | controller | skipping: [instance]
2025-10-03 13:39:58.714398 | controller |
2025-10-03 13:39:58.714430 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-10-03 13:39:58.714439 | controller | Friday 03 October 2025  13:39:58 +0000 (0:00:00.029)       0:00:14.142 ********
2025-10-03 13:39:58.714449 | controller | ok: [instance]
2025-10-03 13:39:58.714651 | controller |
2025-10-03 13:39:58.714686 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-10-03 13:39:58.740542 | controller | Friday 03 October 2025  13:39:58 +0000 (0:00:00.189)       0:00:14.332 ********
2025-10-03 13:39:58.740577 | controller | ok: [instance]
2025-10-03 13:39:58.765241 | controller |
2025-10-03 13:39:58.765265 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-10-03 13:39:58.765274 | controller | Friday 03 October 2025  13:39:58 +0000 (0:00:00.025)       0:00:14.358 ********
2025-10-03 13:39:58.765285 | controller | ok: [instance] => changed=false
2025-10-03 13:39:58.798988 | controller |   msg: All assertions passed
2025-10-03 13:39:58.799013 | controller |
2025-10-03 13:39:58.799023 | controller | TASK [Only filtered hooks] *****************************************************
2025-10-03 13:39:58.799030 | controller | Friday 03 October 2025  13:39:58 +0000 (0:00:00.024)       0:00:14.382 ********
2025-10-03 13:39:58.799039 | controller |
2025-10-03 13:39:58.855430 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-10-03 13:39:58.855466 | controller | Friday 03 October 2025  13:39:58 +0000 (0:00:00.033)       0:00:14.416 ********
2025-10-03 13:39:58.855485 | controller | ok: [instance]
2025-10-03 13:39:58.929426 | controller |
2025-10-03 13:39:58.929460 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-10-03 13:39:58.929468 | controller | Friday 03 October 2025  13:39:58 +0000 (0:00:00.056)       0:00:14.473 ********
2025-10-03 13:39:58.929478 | controller | ok: [instance]
2025-10-03 13:39:58.929503 | controller |
2025-10-03 13:39:58.929511 | controller | TASK [run_hook : Loop on hooks for filtered_hooks] *****************************
2025-10-03 13:39:58.929644 | controller | Friday 03 October 2025  13:39:58 +0000 (0:00:00.074)       0:00:14.547 ********
2025-10-03 13:39:59.022962 | 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-03 13:39:59.071436 | controller |
2025-10-03 13:39:59.071477 | controller | TASK [run_hook : Set playbook path for 01 my hook] *****************************
2025-10-03 13:39:59.071486 | controller | Friday 03 October 2025  13:39:59 +0000 (0:00:00.093)       0:00:14.640 ********
2025-10-03 13:39:59.071496 | controller | ok: [instance]
2025-10-03 13:39:59.071515 | controller |
2025-10-03 13:39:59.071747 | controller | TASK [run_hook : Get file stat] ************************************************
2025-10-03 13:39:59.259245 | controller | Friday 03 October 2025  13:39:59 +0000 (0:00:00.048)       0:00:14.689 ********
2025-10-03 13:39:59.259277 | controller | ok: [instance]
2025-10-03 13:39:59.277254 | controller |
2025-10-03 13:39:59.277276 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-10-03 13:39:59.277301 | controller | Friday 03 October 2025  13:39:59 +0000 (0:00:00.187)       0:00:14.876 ********
2025-10-03 13:39:59.277311 | controller | skipping: [instance]
2025-10-03 13:39:59.463829 | controller |
2025-10-03 13:39:59.463859 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-10-03 13:39:59.463867 | controller | Friday 03 October 2025  13:39:59 +0000 (0:00:00.018)       0:00:14.895 ********
2025-10-03 13:39:59.463877 | controller | ok: [instance]
2025-10-03 13:39:59.483951 | controller |
2025-10-03 13:39:59.483981 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-10-03 13:39:59.483989 | controller | Friday 03 October 2025  13:39:59 +0000 (0:00:00.186)       0:00:15.081 ********
2025-10-03 13:39:59.483999 | controller | ok: [instance]
2025-10-03 13:39:59.677635 | controller |
2025-10-03 13:39:59.677666 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-10-03 13:39:59.677674 | controller | Friday 03 October 2025  13:39:59 +0000 (0:00:00.020)       0:00:15.101 ********
2025-10-03 13:39:59.677684 | controller | ok: [instance]
2025-10-03 13:39:59.861841 | controller |
2025-10-03 13:39:59.861875 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-10-03 13:39:59.861884 | controller | Friday 03 October 2025  13:39:59 +0000 (0:00:00.193)       0:00:15.295 ********
2025-10-03 13:39:59.861894 | controller | ok: [instance]
2025-10-03 13:40:01.781383 | controller |
2025-10-03 13:40:01.781415 | controller | TASK [run_hook : Run hook without retry - 01 my hook] **************************
2025-10-03 13:40:01.781423 | controller | Friday 03 October 2025  13:39:59 +0000 (0:00:00.184)       0:00:15.479 ********
2025-10-03 13:40:01.781433 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_005_run_hook_without_retry_01_my.log
2025-10-03 13:40:01.781777 | controller | changed: [instance]
2025-10-03 13:40:01.781792 | controller |
2025-10-03 13:40:01.814091 | controller | TASK [run_hook : Run hook with retry - 01 my hook] *****************************
2025-10-03 13:40:01.814122 | controller | Friday 03 October 2025  13:40:01 +0000 (0:00:01.919)       0:00:17.399 ********
2025-10-03 13:40:01.814134 | controller | skipping: [instance]
2025-10-03 13:40:02.016614 | controller |
2025-10-03 13:40:02.016645 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-10-03 13:40:02.016653 | controller | Friday 03 October 2025  13:40:01 +0000 (0:00:00.032)       0:00:17.431 ********
2025-10-03 13:40:02.016663 | controller | ok: [instance]
2025-10-03 13:40:02.043866 | controller |
2025-10-03 13:40:02.043891 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-10-03 13:40:02.043899 | controller | Friday 03 October 2025  13:40:02 +0000 (0:00:00.202)       0:00:17.634 ********
2025-10-03 13:40:02.043908 | controller | ok: [instance]
2025-10-03 13:40:02.070241 | controller |
2025-10-03 13:40:02.070272 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-10-03 13:40:02.070280 | controller | Friday 03 October 2025  13:40:02 +0000 (0:00:00.027)       0:00:17.661 ********
2025-10-03 13:40:02.070290 | controller | ok: [instance] => changed=false
2025-10-03 13:40:02.109819 | controller |   msg: All assertions passed
2025-10-03 13:40:02.109851 | controller |
2025-10-03 13:40:02.109860 | controller | TASK [Direct hooks] ************************************************************
2025-10-03 13:40:02.109866 | controller | Friday 03 October 2025  13:40:02 +0000 (0:00:00.026)       0:00:17.687 ********
2025-10-03 13:40:02.109876 | controller |
2025-10-03 13:40:02.169910 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-10-03 13:40:02.169946 | controller | Friday 03 October 2025  13:40:02 +0000 (0:00:00.039)       0:00:17.727 ********
2025-10-03 13:40:02.169958 | controller | ok: [instance]
2025-10-03 13:40:02.244404 | controller |
2025-10-03 13:40:02.244487 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-10-03 13:40:02.244497 | controller | Friday 03 October 2025  13:40:02 +0000 (0:00:00.060)       0:00:17.787 ********
2025-10-03 13:40:02.244512 | controller | ok: [instance]
2025-10-03 13:40:02.339452 | controller |
2025-10-03 13:40:02.339489 | controller | TASK [run_hook : Loop on hooks for no_hook] ************************************
2025-10-03 13:40:02.339497 | controller | Friday 03 October 2025  13:40:02 +0000 (0:00:00.074)       0:00:17.862 ********
2025-10-03 13:40:02.339508 | 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-03 13:40:02.339722 | controller |
2025-10-03 13:40:02.339759 | controller | TASK [run_hook : Set playbook path for Dummy-5] ********************************
2025-10-03 13:40:02.388785 | controller | Friday 03 October 2025  13:40:02 +0000 (0:00:00.095)       0:00:17.957 ********
2025-10-03 13:40:02.388821 | controller | ok: [instance]
2025-10-03 13:40:02.582791 | controller |
2025-10-03 13:40:02.582821 | controller | TASK [run_hook : Get file stat] ************************************************
2025-10-03 13:40:02.582829 | controller | Friday 03 October 2025  13:40:02 +0000 (0:00:00.049)       0:00:18.006 ********
2025-10-03 13:40:02.582839 | controller | ok: [instance]
2025-10-03 13:40:02.600478 | controller |
2025-10-03 13:40:02.600505 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-10-03 13:40:02.600514 | controller | Friday 03 October 2025  13:40:02 +0000 (0:00:00.193)       0:00:18.200 ********
2025-10-03 13:40:02.600525 | controller | skipping: [instance]
2025-10-03 13:40:02.793886 | controller |
2025-10-03 13:40:02.793917 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-10-03 13:40:02.793925 | controller | Friday 03 October 2025  13:40:02 +0000 (0:00:00.017)       0:00:18.218 ********
2025-10-03 13:40:02.793935 | controller | ok: [instance]
2025-10-03 13:40:02.814394 | controller |
2025-10-03 13:40:02.814423 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-10-03 13:40:02.814431 | controller | Friday 03 October 2025  13:40:02 +0000 (0:00:00.193)       0:00:18.411 ********
2025-10-03 13:40:02.814441 | controller | ok: [instance]
2025-10-03 13:40:03.009822 | controller |
2025-10-03 13:40:03.009854 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-10-03 13:40:03.009868 | controller | Friday 03 October 2025  13:40:02 +0000 (0:00:00.020)       0:00:18.432 ********
2025-10-03 13:40:03.009879 | controller | ok: [instance]
2025-10-03 13:40:03.009897 | controller |
2025-10-03 13:40:03.010154 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-10-03 13:40:03.201926 | controller | Friday 03 October 2025  13:40:03 +0000 (0:00:00.195)       0:00:18.627 ********
2025-10-03 13:40:03.201960 | controller | ok: [instance]
2025-10-03 13:40:05.142862 | controller |
2025-10-03 13:40:05.142894 | controller | TASK [run_hook : Run hook without retry - Dummy-5] *****************************
2025-10-03 13:40:05.142902 | controller | Friday 03 October 2025  13:40:03 +0000 (0:00:00.191)       0:00:18.819 ********
2025-10-03 13:40:05.142912 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_006_run_hook_without_retry_dummy.log
2025-10-03 13:40:05.172420 | controller | changed: [instance]
2025-10-03 13:40:05.172452 | controller |
2025-10-03 13:40:05.172462 | controller | TASK [run_hook : Run hook with retry - Dummy-5] ********************************
2025-10-03 13:40:05.172469 | controller | Friday 03 October 2025  13:40:05 +0000 (0:00:01.940)       0:00:20.760 ********
2025-10-03 13:40:05.172481 | controller | skipping: [instance]
2025-10-03 13:40:05.172675 | controller |
2025-10-03 13:40:05.172696 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-10-03 13:40:05.353941 | controller | Friday 03 October 2025  13:40:05 +0000 (0:00:00.029)       0:00:20.790 ********
2025-10-03 13:40:05.353975 | controller | ok: [instance]
2025-10-03 13:40:05.380456 | controller |
2025-10-03 13:40:05.380492 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-10-03 13:40:05.380502 | controller | Friday 03 October 2025  13:40:05 +0000 (0:00:00.181)       0:00:20.971 ********
2025-10-03 13:40:05.380515 | controller | ok: [instance]
2025-10-03 13:40:05.380542 | controller |
2025-10-03 13:40:05.380552 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-10-03 13:40:05.380664 | controller | Friday 03 October 2025  13:40:05 +0000 (0:00:00.026)       0:00:20.998 ********
2025-10-03 13:40:05.406031 | controller | ok: [instance] => changed=false
2025-10-03 13:40:05.445907 | controller |   msg: All assertions passed
2025-10-03 13:40:05.445941 | controller |
2025-10-03 13:40:05.445950 | controller | TASK [Direct hooks as param] ***************************************************
2025-10-03 13:40:05.445958 | controller | Friday 03 October 2025  13:40:05 +0000 (0:00:00.025)       0:00:21.023 ********
2025-10-03 13:40:05.445983 | controller |
2025-10-03 13:40:05.545715 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-10-03 13:40:05.545745 | controller | Friday 03 October 2025  13:40:05 +0000 (0:00:00.039)       0:00:21.063 ********
2025-10-03 13:40:05.545756 | controller | ok: [instance]
2025-10-03 13:40:05.545914 | controller |
2025-10-03 13:40:05.546062 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-10-03 13:40:05.546224 | controller | Friday 03 October 2025  13:40:05 +0000 (0:00:00.100)       0:00:21.163 ********
2025-10-03 13:40:05.620219 | controller | ok: [instance]
2025-10-03 13:40:05.620450 | controller |
2025-10-03 13:40:05.620620 | controller | TASK [run_hook : Loop on hooks for no_hook] ************************************
2025-10-03 13:40:05.620765 | controller | Friday 03 October 2025  13:40:05 +0000 (0:00:00.074)       0:00:21.238 ********
2025-10-03 13:40:05.714918 | 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-03 13:40:05.715140 | controller |
2025-10-03 13:40:05.715352 | controller | TASK [run_hook : Set playbook path for Hook as param] **************************
2025-10-03 13:40:05.715552 | controller | Friday 03 October 2025  13:40:05 +0000 (0:00:00.094)       0:00:21.332 ********
2025-10-03 13:40:05.765154 | controller | ok: [instance]
2025-10-03 13:40:05.765340 | controller |
2025-10-03 13:40:05.765502 | controller | TASK [run_hook : Get file stat] ************************************************
2025-10-03 13:40:05.765656 | controller | Friday 03 October 2025  13:40:05 +0000 (0:00:00.050)       0:00:21.383 ********
2025-10-03 13:40:05.956256 | controller | ok: [instance]
2025-10-03 13:40:05.974003 | controller |
2025-10-03 13:40:05.974033 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-10-03 13:40:05.974043 | controller | Friday 03 October 2025  13:40:05 +0000 (0:00:00.190)       0:00:21.573 ********
2025-10-03 13:40:05.974055 | controller | skipping: [instance]
2025-10-03 13:40:06.171805 | controller |
2025-10-03 13:40:06.171835 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-10-03 13:40:06.171913 | controller | Friday 03 October 2025  13:40:05 +0000 (0:00:00.017)       0:00:21.591 ********
2025-10-03 13:40:06.171925 | controller | ok: [instance]
2025-10-03 13:40:06.171973 | controller |
2025-10-03 13:40:06.171992 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-10-03 13:40:06.192295 | controller | Friday 03 October 2025  13:40:06 +0000 (0:00:00.197)       0:00:21.789 ********
2025-10-03 13:40:06.192355 | controller | ok: [instance]
2025-10-03 13:40:06.396855 | controller |
2025-10-03 13:40:06.396885 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-10-03 13:40:06.396894 | controller | Friday 03 October 2025  13:40:06 +0000 (0:00:00.020)       0:00:21.810 ********
2025-10-03 13:40:06.396904 | controller | ok: [instance]
2025-10-03 13:40:06.585885 | controller |
2025-10-03 13:40:06.585914 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-10-03 13:40:06.585922 | controller | Friday 03 October 2025  13:40:06 +0000 (0:00:00.204)       0:00:22.014 ********
2025-10-03 13:40:06.585932 | controller | ok: [instance]
2025-10-03 13:40:08.525775 | controller |
2025-10-03 13:40:08.525806 | controller | TASK [run_hook : Run hook without retry - Hook as param] ***********************
2025-10-03 13:40:08.525815 | controller | Friday 03 October 2025  13:40:06 +0000 (0:00:00.189)       0:00:22.203 ********
2025-10-03 13:40:08.525825 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_007_run_hook_without_retry_hook.log
2025-10-03 13:40:08.556807 | controller | changed: [instance]
2025-10-03 13:40:08.556837 | controller |
2025-10-03 13:40:08.556847 | controller | TASK [run_hook : Run hook with retry - Hook as param] **************************
2025-10-03 13:40:08.556854 | controller | Friday 03 October 2025  13:40:08 +0000 (0:00:01.939)       0:00:24.143 ********
2025-10-03 13:40:08.556866 | controller | skipping: [instance]
2025-10-03 13:40:08.756412 | controller |
2025-10-03 13:40:08.756455 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-10-03 13:40:08.756472 | controller | Friday 03 October 2025  13:40:08 +0000 (0:00:00.031)       0:00:24.174 ********
2025-10-03 13:40:08.756488 | controller | ok: [instance]
2025-10-03 13:40:08.756509 | controller |
2025-10-03 13:40:08.756736 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-10-03 13:40:08.784430 | controller | Friday 03 October 2025  13:40:08 +0000 (0:00:00.199)       0:00:24.374 ********
2025-10-03 13:40:08.784467 | controller | ok: [instance]
2025-10-03 13:40:08.784495 | controller |
2025-10-03 13:40:08.784731 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-10-03 13:40:08.810411 | controller | Friday 03 October 2025  13:40:08 +0000 (0:00:00.028)       0:00:24.402 ********
2025-10-03 13:40:08.810440 | controller | ok: [instance] => changed=false
2025-10-03 13:40:08.810759 | controller |   msg: All assertions passed
2025-10-03 13:40:08.810787 | controller |
2025-10-03 13:40:08.845936 | controller | TASK [Ensure we have the test_list variable now] *******************************
2025-10-03 13:40:08.845968 | controller | Friday 03 October 2025  13:40:08 +0000 (0:00:00.025)       0:00:24.428 ********
2025-10-03 13:40:08.845980 | controller | ok: [instance] => changed=false
2025-10-03 13:40:08.872367 | controller |   msg: All assertions passed
2025-10-03 13:40:08.872392 | controller |
2025-10-03 13:40:08.872401 | controller | TASK [Run hook with retry] *****************************************************
2025-10-03 13:40:08.872408 | controller | Friday 03 October 2025  13:40:08 +0000 (0:00:00.035)       0:00:24.463 ********
2025-10-03 13:40:08.872419 | controller |
2025-10-03 13:40:08.931104 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-10-03 13:40:08.931131 | controller | Friday 03 October 2025  13:40:08 +0000 (0:00:00.026)       0:00:24.490 ********
2025-10-03 13:40:08.931142 | controller | ok: [instance]
2025-10-03 13:40:09.006343 | controller |
2025-10-03 13:40:09.006371 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-10-03 13:40:09.006379 | controller | Friday 03 October 2025  13:40:08 +0000 (0:00:00.058)       0:00:24.548 ********
2025-10-03 13:40:09.006389 | controller | ok: [instance]
2025-10-03 13:40:09.099462 | controller |
2025-10-03 13:40:09.099505 | controller | TASK [run_hook : Loop on hooks for retry_hook] *********************************
2025-10-03 13:40:09.099515 | controller | Friday 03 October 2025  13:40:09 +0000 (0:00:00.075)       0:00:24.624 ********
2025-10-03 13:40:09.099529 | 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-03 13:40:09.099558 | controller |
2025-10-03 13:40:09.099568 | controller | TASK [run_hook : Set playbook path for Run hook with retry] ********************
2025-10-03 13:40:09.099730 | controller | Friday 03 October 2025  13:40:09 +0000 (0:00:00.093)       0:00:24.717 ********
2025-10-03 13:40:09.148286 | controller | ok: [instance]
2025-10-03 13:40:09.337216 | controller |
2025-10-03 13:40:09.337245 | controller | TASK [run_hook : Get file stat] ************************************************
2025-10-03 13:40:09.337253 | controller | Friday 03 October 2025  13:40:09 +0000 (0:00:00.048)       0:00:24.766 ********
2025-10-03 13:40:09.337263 | controller | ok: [instance]
2025-10-03 13:40:09.354415 | controller |
2025-10-03 13:40:09.354451 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-10-03 13:40:09.354460 | controller | Friday 03 October 2025  13:40:09 +0000 (0:00:00.188)       0:00:24.954 ********
2025-10-03 13:40:09.354470 | controller | skipping: [instance]
2025-10-03 13:40:09.539798 | controller |
2025-10-03 13:40:09.539828 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-10-03 13:40:09.539836 | controller | Friday 03 October 2025  13:40:09 +0000 (0:00:00.017)       0:00:24.972 ********
2025-10-03 13:40:09.539846 | controller | ok: [instance]
2025-10-03 13:40:09.560424 | controller |
2025-10-03 13:40:09.560461 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-10-03 13:40:09.560471 | controller | Friday 03 October 2025  13:40:09 +0000 (0:00:00.185)       0:00:25.157 ********
2025-10-03 13:40:09.560483 | controller | ok: [instance]
2025-10-03 13:40:09.560513 | controller |
2025-10-03 13:40:09.560767 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-10-03 13:40:09.754557 | controller | Friday 03 October 2025  13:40:09 +0000 (0:00:00.020)       0:00:25.178 ********
2025-10-03 13:40:09.754590 | controller | ok: [instance]
2025-10-03 13:40:09.948852 | controller |
2025-10-03 13:40:09.948882 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-10-03 13:40:09.948890 | controller | Friday 03 October 2025  13:40:09 +0000 (0:00:00.193)       0:00:25.372 ********
2025-10-03 13:40:09.948899 | controller | ok: [instance]
2025-10-03 13:40:11.868424 | controller |
2025-10-03 13:40:11.868455 | controller | TASK [run_hook : Run hook without retry - Run hook with retry] *****************
2025-10-03 13:40:11.868464 | controller | Friday 03 October 2025  13:40:09 +0000 (0:00:00.194)       0:00:25.566 ********
2025-10-03 13:40:11.868475 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_008_run_hook_without_retry_run.log
2025-10-03 13:40:11.896358 | controller | changed: [instance]
2025-10-03 13:40:11.896392 | controller |
2025-10-03 13:40:11.896400 | controller | TASK [run_hook : Run hook with retry - Run hook with retry] ********************
2025-10-03 13:40:11.896407 | controller | Friday 03 October 2025  13:40:11 +0000 (0:00:01.919)       0:00:27.486 ********
2025-10-03 13:40:11.896416 | controller | skipping: [instance]
2025-10-03 13:40:12.067022 | controller |
2025-10-03 13:40:12.067054 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-10-03 13:40:12.067062 | controller | Friday 03 October 2025  13:40:11 +0000 (0:00:00.028)       0:00:27.514 ********
2025-10-03 13:40:12.067072 | controller | ok: [instance]
2025-10-03 13:40:12.087274 | controller |
2025-10-03 13:40:12.087303 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-10-03 13:40:12.087313 | controller | Friday 03 October 2025  13:40:12 +0000 (0:00:00.170)       0:00:27.684 ********
2025-10-03 13:40:12.087356 | controller | skipping: [instance]
2025-10-03 13:40:12.269004 | controller |
2025-10-03 13:40:12.269034 | controller | TASK [Check if fake file exists for retry playbook] ****************************
2025-10-03 13:40:12.269043 | controller | Friday 03 October 2025  13:40:12 +0000 (0:00:00.020)       0:00:27.705 ********
2025-10-03 13:40:12.269053 | controller | ok: [instance]
2025-10-03 13:40:12.289873 | controller |
2025-10-03 13:40:12.289900 | controller | TASK [Ensure file exists and was created on retry] *****************************
2025-10-03 13:40:12.289908 | controller | Friday 03 October 2025  13:40:12 +0000 (0:00:00.181)       0:00:27.886 ********
2025-10-03 13:40:12.289918 | controller | ok: [instance] => changed=false
2025-10-03 13:40:12.479396 | controller |   msg: All assertions passed
2025-10-03 13:40:12.479427 | controller |
2025-10-03 13:40:12.479435 | controller | TASK [Remove generated file] ***************************************************
2025-10-03 13:40:12.479441 | controller | Friday 03 October 2025  13:40:12 +0000 (0:00:00.020)       0:00:27.907 ********
2025-10-03 13:40:12.479451 | controller | changed: [instance]
2025-10-03 13:40:12.480365 | controller |
2025-10-03 13:40:12.480378 | controller | PLAY RECAP *********************************************************************
2025-10-03 13:40:12.480384 | controller | instance                   : ok=112  changed=10   unreachable=0    failed=0    skipped=22   rescued=0    ignored=0
2025-10-03 13:40:12.480390 | controller |
2025-10-03 13:40:12.480396 | controller | Friday 03 October 2025  13:40:12 +0000 (0:00:00.188)       0:00:28.096 ********
2025-10-03 13:40:12.480401 | controller | ===============================================================================
2025-10-03 13:40:12.480409 | controller | run_hook : Run hook without retry - Dummy-5 ----------------------------- 1.94s
2025-10-03 13:40:12.481392 | controller | run_hook : Run hook without retry - Hook as param ----------------------- 1.94s
2025-10-03 13:40:12.481424 | controller | run_hook : Run hook without retry - Run dummy-2 ------------------------- 1.92s
2025-10-03 13:40:12.481432 | controller | run_hook : Run hook without retry - 01 my hook -------------------------- 1.92s
2025-10-03 13:40:12.481438 | controller | run_hook : Run hook without retry - Run hook with retry ----------------- 1.92s
2025-10-03 13:40:12.481443 | controller | run_hook : Run hook without retry - Run dummy-3 ------------------------- 1.91s
2025-10-03 13:40:12.481449 | controller | run_hook : Run hook without retry - 03 single hook ---------------------- 1.90s
2025-10-03 13:40:12.481454 | controller | Gathering Facts --------------------------------------------------------- 0.80s
2025-10-03 13:40:12.481466 | controller | run_hook : Run hook without retry - 02 Re-run noop ---------------------- 0.61s
2025-10-03 13:40:12.481472 | controller | run_hook : Run hook without retry - 01 Default noop hook ---------------- 0.59s
2025-10-03 13:40:12.481482 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.29s
2025-10-03 13:40:12.542540 | controller | run_hook : Get file stat ------------------------------------------------ 0.29s
2025-10-03 13:40:12.542572 | controller | run_hook : Get parameters files ----------------------------------------- 0.28s
2025-10-03 13:40:12.542580 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.20s
2025-10-03 13:40:12.542585 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.20s
2025-10-03 13:40:12.542591 | controller | run_hook : Get file stat ------------------------------------------------ 0.20s
2025-10-03 13:40:12.542596 | controller | run_hook : Get parameters files ----------------------------------------- 0.20s
2025-10-03 13:40:12.542601 | controller | run_hook : Check if we have a file -------------------------------------- 0.20s
2025-10-03 13:40:12.542607 | controller | run_hook : Ensure artifacts directory exists ---------------------------- 0.20s
2025-10-03 13:40:12.542612 | controller | run_hook : Check if we have a file -------------------------------------- 0.20s
2025-10-03 13:40:12.542622 | controller | INFO     Running default > cleanup
2025-10-03 13:40:12.543100 | controller | WARNING  Skipping, cleanup playbook not configured.
2025-10-03 13:40:12.543692 | controller | INFO     Writing /tmp/report.html report.
2025-10-03 13:40:12.922788 | controller | changed
2025-10-03 13:40:12.948423 | 
2025-10-03 13:40:12.948498 | PLAY RECAP
2025-10-03 13:40:12.948540 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-03 13:40:12.948562 | 
2025-10-03 13:40:13.031891 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-10-03 13:40:13.032855 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-10-03 13:40:13.598989 | 
2025-10-03 13:40:13.599107 | PLAY [Run ci/playbooks/collect-logs.yml]
2025-10-03 13:40:13.621168 | 
2025-10-03 13:40:13.621294 | TASK [Filter out host if needed]
2025-10-03 13:40:13.630285 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2025-10-03 13:40:13.634848 | 
2025-10-03 13:40:13.635082 | TASK [Ensure file is present]
2025-10-03 13:40:13.979321 | controller | ok
2025-10-03 13:40:13.986415 | 
2025-10-03 13:40:13.986503 | TASK [Manage molecule report file]
2025-10-03 13:40:14.512180 | controller | changed
2025-10-03 13:40:14.518687 | 
2025-10-03 13:40:14.518795 | TASK [Check if we get ci-framework-data basedir]
2025-10-03 13:40:14.720026 | controller | ok
2025-10-03 13:40:14.725605 | 
2025-10-03 13:40:14.725671 | TASK [Create ci-framework-data log directory for zuul]
2025-10-03 13:40:15.048548 | controller | changed
2025-10-03 13:40:15.054262 | 
2025-10-03 13:40:15.054332 | TASK [Copy ci-framework interesting files]
2025-10-03 13:40:15.245698 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory
2025-10-03 13:40:15.580230 | controller | changed
2025-10-03 13:40:15.586022 | 
2025-10-03 13:40:15.586093 | TASK [Get SELinux listing]
2025-10-03 13:40:16.123732 | controller | changed
2025-10-03 13:40:16.129833 | 
2025-10-03 13:40:16.129946 | TASK [Generate log index]
2025-10-03 13:40:16.801746 | controller | changed
2025-10-03 13:40:16.807338 | 
2025-10-03 13:40:16.807417 | TASK [Get some env related data]
2025-10-03 13:40:17.357947 | controller | /home/zuul/.local/bin/ansible
2025-10-03 13:40:18.340260 | controller | changed
2025-10-03 13:40:18.346608 | 
2025-10-03 13:40:18.346697 | TASK [Generate list of logs to collect in home directory]
2025-10-03 13:40:18.670239 | controller | ok: All paths examined
2025-10-03 13:40:18.675786 | 
2025-10-03 13:40:18.675869 | LOOP [Copy logs from home directory]
2025-10-03 13:40:19.037115 | controller | changed:
2025-10-03 13:40:19.037238 | controller | {
2025-10-03 13:40:19.037265 | controller |   "atime": 1759498760.894575,
2025-10-03 13:40:19.037285 | controller |   "ctime": 1759498776.6713192,
2025-10-03 13:40:19.037302 | controller |   "dev": 64513,
2025-10-03 13:40:19.037319 | controller |   "gid": 1000,
2025-10-03 13:40:19.037334 | controller |   "gr_name": "zuul",
2025-10-03 13:40:19.037353 | controller |   "inode": 4452770,
2025-10-03 13:40:19.037369 | controller |   "isblk": false,
2025-10-03 13:40:19.037385 | controller |   "ischr": false,
2025-10-03 13:40:19.037400 | controller |   "isdir": false,
2025-10-03 13:40:19.037415 | controller |   "isfifo": false,
2025-10-03 13:40:19.037431 | controller |   "isgid": false,
2025-10-03 13:40:19.037446 | controller |   "islnk": false,
2025-10-03 13:40:19.037462 | controller |   "isreg": true,
2025-10-03 13:40:19.037477 | controller |   "issock": false,
2025-10-03 13:40:19.037491 | controller |   "isuid": false,
2025-10-03 13:40:19.037506 | controller |   "mode": "0644",
2025-10-03 13:40:19.037521 | controller |   "mtime": 1759498776.6713192,
2025-10-03 13:40:19.037536 | controller |   "nlink": 1,
2025-10-03 13:40:19.037551 | controller |   "path": "/home/zuul/ansible.log",
2025-10-03 13:40:19.037567 | controller |   "pw_name": "zuul",
2025-10-03 13:40:19.037583 | controller |   "rgrp": true,
2025-10-03 13:40:19.037598 | controller |   "roth": true,
2025-10-03 13:40:19.037613 | controller |   "rusr": true,
2025-10-03 13:40:19.037626 | controller |   "size": 6749,
2025-10-03 13:40:19.037640 | controller |   "uid": 1000,
2025-10-03 13:40:19.037653 | controller |   "wgrp": false,
2025-10-03 13:40:19.037666 | controller |   "woth": false,
2025-10-03 13:40:19.037682 | controller |   "wusr": true,
2025-10-03 13:40:19.037697 | controller |   "xgrp": false,
2025-10-03 13:40:19.037725 | controller |   "xoth": false,
2025-10-03 13:40:19.037741 | controller |   "xusr": false
2025-10-03 13:40:19.037757 | controller | }
2025-10-03 13:40:19.048126 | 
2025-10-03 13:40:19.048253 | TASK [Copy crio stats log file]
2025-10-03 13:40:19.106586 | controller | skipping: Conditional result was False
2025-10-03 13:40:19.112955 | 
2025-10-03 13:40:19.113042 | TASK [Get SELinux related data]
2025-10-03 13:40:19.341682 | controller | <no matches>
2025-10-03 13:40:19.662413 | controller | ERROR
2025-10-03 13:40:19.662558 | controller | {
2025-10-03 13:40:19.662591 | controller |   "delta": "0:00:00.008796",
2025-10-03 13:40:19.662614 | controller |   "end": "2025-10-03 13:40:19.342301",
2025-10-03 13:40:19.662635 | controller |   "msg": "non-zero return code",
2025-10-03 13:40:19.662655 | controller |   "rc": 1,
2025-10-03 13:40:19.662674 | controller |   "start": "2025-10-03 13:40:19.333505"
2025-10-03 13:40:19.662729 | controller | }
2025-10-03 13:40:19.662761 | controller | ERROR: Ignoring Errors
2025-10-03 13:40:19.668650 | 
2025-10-03 13:40:19.668733 | TASK [Create system configuration directory]
2025-10-03 13:40:19.891944 | controller | changed
2025-10-03 13:40:19.904322 | 
2025-10-03 13:40:19.904438 | TASK [Get some of the system configurations]
2025-10-03 13:40:20.432212 | controller | changed
2025-10-03 13:40:20.438090 | 
2025-10-03 13:40:20.438170 | TASK [Copy generated documentation if available]
2025-10-03 13:40:20.464406 | controller | skipping: Conditional result was False
2025-10-03 13:40:20.470825 | 
2025-10-03 13:40:20.470983 | TASK [Copy generated AsciiDoc documentation if available]
2025-10-03 13:40:20.497058 | controller | skipping: Conditional result was False
2025-10-03 13:40:20.505821 | 
2025-10-03 13:40:20.505999 | TASK [Compress logs bigger than 2MB]
2025-10-03 13:40:21.037738 | controller | changed
2025-10-03 13:40:21.044250 | 
2025-10-03 13:40:21.044374 | TASK [Copy files from workspace on node]
2025-10-03 13:40:21.064546 | controller | ok
2025-10-03 13:40:21.089513 | 
2025-10-03 13:40:21.089660 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-03 13:40:21.114495 | controller | skipping: Conditional result was False
2025-10-03 13:40:21.121374 | 
2025-10-03 13:40:21.121513 | TASK [fetch-output : Set log path for single node]
2025-10-03 13:40:21.154848 | controller | ok
2025-10-03 13:40:21.160447 | 
2025-10-03 13:40:21.160580 | LOOP [fetch-output : Ensure local output dirs]
2025-10-03 13:40:21.423824 | controller -> localhost | ok: "/var/lib/zuul/builds/0b811b84cd9d468e82441f3dfc0bfdab/work/logs"
2025-10-03 13:40:21.424085 | controller -> localhost | changed: All items complete
2025-10-03 13:40:21.424117 | 
2025-10-03 13:40:21.632307 | controller -> localhost | changed: "/var/lib/zuul/builds/0b811b84cd9d468e82441f3dfc0bfdab/work/artifacts"
2025-10-03 13:40:22.012758 | controller -> localhost | changed: "/var/lib/zuul/builds/0b811b84cd9d468e82441f3dfc0bfdab/work/docs"
2025-10-03 13:40:22.023430 | 
2025-10-03 13:40:22.023521 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-03 13:40:22.859072 | controller | changed:
2025-10-03 13:40:22.859260 | controller | .d..t...... ./
2025-10-03 13:40:22.859292 | controller | >f+++++++++ README.html
2025-10-03 13:40:22.859315 | controller | >f+++++++++ ansible-execution.log
2025-10-03 13:40:22.859336 | controller | >f+++++++++ ansible.log
2025-10-03 13:40:22.859356 | controller | >f+++++++++ dmesg.log
2025-10-03 13:40:22.859375 | controller | >f+++++++++ installed-pkgs.log
2025-10-03 13:40:22.859397 | controller | >f+++++++++ python.log
2025-10-03 13:40:22.859416 | controller | >f+++++++++ registries.conf
2025-10-03 13:40:22.859434 | controller | >f+++++++++ report.html
2025-10-03 13:40:22.859454 | controller | >f+++++++++ selinux-denials.log
2025-10-03 13:40:22.859473 | controller | >f+++++++++ selinux-listing.log
2025-10-03 13:40:22.859491 | controller | cd+++++++++ ci-framework-data/
2025-10-03 13:40:22.859510 | controller | cd+++++++++ ci-framework-data/artifacts/
2025-10-03 13:40:22.859527 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_000_run_hook_without_retry_01.sh
2025-10-03 13:40:22.859545 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_001_run_hook_without_retry_02_re.sh
2025-10-03 13:40:22.859563 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_002_run_hook_without_retry_03.sh
2025-10-03 13:40:22.859579 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_003_run_hook_without_retry_run.sh
2025-10-03 13:40:22.859596 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_004_run_hook_without_retry_run.sh
2025-10-03 13:40:22.859612 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_005_run_hook_without_retry_01_my.sh
2025-10-03 13:40:22.859628 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_006_run_hook_without_retry_dummy.sh
2025-10-03 13:40:22.859645 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_007_run_hook_without_retry_hook.sh
2025-10-03 13:40:22.859666 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_008_run_hook_without_retry_run.sh
2025-10-03 13:40:22.859684 | controller | >f+++++++++ ci-framework-data/artifacts/filtered_hooks_01_my_hook.yml
2025-10-03 13:40:22.859720 | controller | >f+++++++++ ci-framework-data/artifacts/list_hooks_run_dummy-2.yml
2025-10-03 13:40:22.859739 | controller | >f+++++++++ ci-framework-data/artifacts/list_hooks_run_dummy-3.yml
2025-10-03 13:40:22.859756 | controller | >f+++++++++ ci-framework-data/artifacts/no_hook_dummy-5.yml
2025-10-03 13:40:22.859773 | controller | >f+++++++++ ci-framework-data/artifacts/no_hook_hook_as_param.yml
2025-10-03 13:40:22.859789 | controller | >f+++++++++ ci-framework-data/artifacts/run_molecule_03_single_hook.yml
2025-10-03 13:40:22.859805 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2025-10-03 13:40:22.859821 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2025-10-03 13:40:22.859837 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2025-10-03 13:40:22.859852 | controller | cd+++++++++ ci-framework-data/logs/
2025-10-03 13:40:22.859868 | controller | >f+++++++++ ci-framework-data/logs/ci_script_000_run_hook_without_retry_01.log
2025-10-03 13:40:22.859883 | controller | >f+++++++++ ci-framework-data/logs/ci_script_001_run_hook_without_retry_02_re.log
2025-10-03 13:40:22.859899 | controller | >f+++++++++ ci-framework-data/logs/ci_script_002_run_hook_without_retry_03.log
2025-10-03 13:40:22.860000 | controller | >f+++++++++ ci-framework-data/logs/ci_script_003_run_hook_without_retry_run.log
2025-10-03 13:40:22.860030 | controller | >f+++++++++ ci-framework-data/logs/ci_script_004_run_hook_without_retry_run.log
2025-10-03 13:40:22.860051 | controller | >f+++++++++ ci-framework-data/logs/ci_script_005_run_hook_without_retry_01_my.log
2025-10-03 13:40:22.860070 | controller | >f+++++++++ ci-framework-data/logs/ci_script_006_run_hook_without_retry_dummy.log
2025-10-03 13:40:22.860088 | controller | >f+++++++++ ci-framework-data/logs/ci_script_007_run_hook_without_retry_hook.log
2025-10-03 13:40:22.860106 | controller | >f+++++++++ ci-framework-data/logs/ci_script_008_run_hook_without_retry_run.log
2025-10-03 13:40:22.860124 | controller | >f+++++++++ ci-framework-data/logs/filtered_hooks_01_my_hook.log
2025-10-03 13:40:22.860141 | controller | >f+++++++++ ci-framework-data/logs/list_hooks_run_dummy-2.log
2025-10-03 13:40:22.860157 | controller | >f+++++++++ ci-framework-data/logs/list_hooks_run_dummy-3.log
2025-10-03 13:40:22.860173 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2025-10-03 13:40:22.860190 | controller | >f+++++++++ ci-framework-data/logs/no_hook_dummy-5.log
2025-10-03 13:40:22.860206 | controller | >f+++++++++ ci-framework-data/logs/no_hook_hook_as_param.log
2025-10-03 13:40:22.860222 | controller | >f+++++++++ ci-framework-data/logs/retry_hook_run_hook_with_retry.log
2025-10-03 13:40:22.860239 | controller | >f+++++++++ ci-framework-data/logs/run_molecule_01_default_noop_hook.log
2025-10-03 13:40:22.860256 | controller | >f+++++++++ ci-framework-data/logs/run_molecule_02_re-run_noop.log
2025-10-03 13:40:22.860273 | controller | >f+++++++++ ci-framework-data/logs/run_molecule_03_single_hook.log
2025-10-03 13:40:22.860290 | controller | cd+++++++++ registries.conf.d/
2025-10-03 13:40:22.860308 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2025-10-03 13:40:22.860325 | controller | cd+++++++++ system-config/
2025-10-03 13:40:22.860342 | controller | cd+++++++++ system-config/libvirt/
2025-10-03 13:40:22.860359 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2025-10-03 13:40:22.860376 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2025-10-03 13:40:23.269116 | controller | changed: .d..t...... ./
2025-10-03 13:40:23.700128 | controller | changed: .d..t...... ./
2025-10-03 13:40:23.715377 | 
2025-10-03 13:40:23.715485 | TASK [Return artifact to Zuul]
2025-10-03 13:40:23.765642 | controller | ok
2025-10-03 13:40:23.795057 | 
2025-10-03 13:40:23.795153 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2025-10-03 13:40:23.795264 | 
2025-10-03 13:40:23.795292 | PLAY RECAP
2025-10-03 13:40:23.795329 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-10-03 13:40:23.795350 | 
2025-10-03 13:40:23.934771 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-10-03 13:40:23.935615 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-03 13:40:24.517086 | 
2025-10-03 13:40:24.517208 | PLAY [all]
2025-10-03 13:40:24.536733 | 
2025-10-03 13:40:24.536838 | TASK [include_role : fetch-output]
2025-10-03 13:40:24.581837 | controller | ok
2025-10-03 13:40:24.609512 | 
2025-10-03 13:40:24.609644 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-03 13:40:24.653827 | controller | skipping: Conditional result was False
2025-10-03 13:40:24.659896 | 
2025-10-03 13:40:24.660020 | TASK [fetch-output : Set log path for single node]
2025-10-03 13:40:24.698418 | controller | ok
2025-10-03 13:40:24.703656 | 
2025-10-03 13:40:24.703766 | LOOP [fetch-output : Ensure local output dirs]
2025-10-03 13:40:25.101053 | controller -> localhost | ok: "/var/lib/zuul/builds/0b811b84cd9d468e82441f3dfc0bfdab/work/logs"
2025-10-03 13:40:25.310804 | controller -> localhost | ok: "/var/lib/zuul/builds/0b811b84cd9d468e82441f3dfc0bfdab/work/artifacts"
2025-10-03 13:40:25.509185 | controller -> localhost | ok: "/var/lib/zuul/builds/0b811b84cd9d468e82441f3dfc0bfdab/work/docs"
2025-10-03 13:40:25.519851 | 
2025-10-03 13:40:25.519981 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-03 13:40:26.074104 | controller | ok
2025-10-03 13:40:26.074306 | controller | ok: All items complete
2025-10-03 13:40:26.074336 | 
2025-10-03 13:40:26.466992 | controller | ok
2025-10-03 13:40:26.898781 | controller | ok
2025-10-03 13:40:26.916370 | 
2025-10-03 13:40:26.916481 | TASK [include_role : fetch-output-openshift]
2025-10-03 13:40:26.961873 | controller | skipping: Conditional result was False
2025-10-03 13:40:26.967776 | 
2025-10-03 13:40:26.967870 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-03 13:40:27.544323 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.006521
2025-10-03 13:40:27.779044 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.008932
2025-10-03 13:40:27.826363 | 
2025-10-03 13:40:27.826451 | PLAY [all]
2025-10-03 13:40:27.846461 | 
2025-10-03 13:40:27.846532 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-03 13:40:28.264303 | controller | changed
2025-10-03 13:40:28.288482 | 
2025-10-03 13:40:28.288577 | PLAY RECAP
2025-10-03 13:40:28.288625 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-03 13:40:28.288649 | 
2025-10-03 13:40:28.370208 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-03 13:40:28.370971 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-03 13:40:29.022867 | 
2025-10-03 13:40:29.023001 | PLAY [localhost]
2025-10-03 13:40:29.042180 | 
2025-10-03 13:40:29.042282 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-03 13:40:29.404296 | localhost | changed
2025-10-03 13:40:29.409000 | 
2025-10-03 13:40:29.409078 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-03 13:40:29.437233 | localhost | ok
2025-10-03 13:40:29.445900 | 
2025-10-03 13:40:29.446026 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-03 13:40:29.777951 | localhost | changed
2025-10-03 13:40:29.783468 | 
2025-10-03 13:40:29.783541 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-03 13:40:30.378490 | localhost | changed
2025-10-03 13:40:30.383634 | 
2025-10-03 13:40:30.383714 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-03 13:40:30.756949 | localhost | Identity added: /var/lib/zuul/builds/0b811b84cd9d468e82441f3dfc0bfdab/work/tmp/ansible.m54lss_e (/var/lib/zuul/builds/0b811b84cd9d468e82441f3dfc0bfdab/work/tmp/ansible.m54lss_e)
2025-10-03 13:40:30.757162 | localhost | ok: Runtime: 0:00:00.006518
2025-10-03 13:40:30.764130 | 
2025-10-03 13:40:30.764211 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-03 13:40:31.008189 | localhost | ok: Runtime: 0:00:00.004540
2025-10-03 13:40:31.013994 | 
2025-10-03 13:40:31.014085 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-03 13:40:31.073778 | localhost | changed
2025-10-03 13:40:31.079333 | 
2025-10-03 13:40:31.079422 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-03 13:40:31.462522 | localhost | changed
2025-10-03 13:40:31.498002 | 
2025-10-03 13:40:31.498109 | PLAY [localhost]
2025-10-03 13:40:31.517168 | 
2025-10-03 13:40:31.517240 | TASK [Generate bulk log download script]
2025-10-03 13:40:31.545727 | localhost | ok
2025-10-03 13:40:31.558620 | 
2025-10-03 13:40:31.558722 | TASK [local-log-download : Check API endpoint is defined]
2025-10-03 13:40:31.591553 | localhost | ok: All assertions passed
2025-10-03 13:40:31.596082 | 
2025-10-03 13:40:31.596152 | TASK [local-log-download : Create download script]
2025-10-03 13:40:32.017277 | localhost -> localhost | changed
2025-10-03 13:40:32.028011 | 
2025-10-03 13:40:32.028126 | TASK [Register quick-download link]
2025-10-03 13:40:32.046185 | localhost | ok
2025-10-03 13:40:32.085347 | 
2025-10-03 13:40:32.085444 | PLAY [logserver.rdoproject.org]
2025-10-03 13:40:32.095955 | 
2025-10-03 13:40:32.096021 | TASK [Set zuul-log-path fact]
2025-10-03 13:40:32.112204 | logserver.rdoproject.org | ok
2025-10-03 13:40:32.124698 | 
2025-10-03 13:40:32.124773 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-03 13:40:32.150785 | logserver.rdoproject.org | ok
2025-10-03 13:40:32.156982 | 
2025-10-03 13:40:32.157056 | TASK [upload-logs : Create log directories]
2025-10-03 13:40:33.827553 | logserver.rdoproject.org | changed
2025-10-03 13:40:33.831021 | 
2025-10-03 13:40:33.831092 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-03 13:40:34.077980 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.005219
2025-10-03 13:40:34.082789 | 
2025-10-03 13:40:34.082865 | TASK [upload-logs : Upload logs to log server]
2025-10-03 13:40:35.573609 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-03 13:40:35.576519 | 
2025-10-03 13:40:35.576589 | LOOP [upload-logs : Compress console log and json output]
2025-10-03 13:40:35.615700 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 13:40:35.629621 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 13:40:35.637578 | 
2025-10-03 13:40:35.637725 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-03 13:40:35.674931 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 13:40:35.675176 | 
2025-10-03 13:40:35.679758 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 13:40:35.685448 | 
2025-10-03 13:40:35.685576 | LOOP [upload-logs : Upload console log and json output]