2025-12-08 06:36:29.397169 | Job console starting...
2025-12-08 06:36:29.611548 | Updating repositories
2025-12-08 06:36:30.341942 | Preparing job workspace
2025-12-08 06:36:38.952302 | Running Ansible setup...
2025-12-08 06:36:41.983450 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-08 06:36:42.616615 | 
2025-12-08 06:36:42.616710 | PLAY [localhost]
2025-12-08 06:36:42.625485 | 
2025-12-08 06:36:42.625558 | TASK [Gathering Facts]
2025-12-08 06:36:43.484972 | localhost | ok
2025-12-08 06:36:43.499880 | 
2025-12-08 06:36:43.500030 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-08 06:36:43.839270 | localhost -> localhost | changed
2025-12-08 06:36:43.846507 | 
2025-12-08 06:36:43.846595 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-08 06:36:44.600893 | localhost -> localhost | changed
2025-12-08 06:36:44.608972 | 
2025-12-08 06:36:44.609144 | TASK [Setup log path fact]
2025-12-08 06:36:44.626785 | localhost | ok
2025-12-08 06:36:44.637534 | 
2025-12-08 06:36:44.637603 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-08 06:36:44.663801 | localhost | ok
2025-12-08 06:36:44.671078 | 
2025-12-08 06:36:44.671146 | TASK [emit-job-header : Print job information]
2025-12-08 06:36:44.718798 | # Job Information
2025-12-08 06:36:44.718933 | Ansible Version: 2.15.12
2025-12-08 06:36:44.718970 | Job: cifmw-molecule-run_hook
2025-12-08 06:36:44.718997 | Pipeline: github-check
2025-12-08 06:36:44.719020 | Executor: ibm-bm4-ze.softwarefactory-project.io
2025-12-08 06:36:44.719041 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3533
2025-12-08 06:36:44.719063 | Log URL (when completed): https://logserver.rdoproject.org/c8a/rdoproject.org/c8a8de4fe48c4950991f041df900c43e/
2025-12-08 06:36:44.719083 | Event ID: 0ec2c7a0-d400-11f0-9e04-bffec31d901e
2025-12-08 06:36:44.722701 | 
2025-12-08 06:36:44.722766 | LOOP [emit-job-header : Print node information]
2025-12-08 06:36:44.806621 | localhost | ok:
2025-12-08 06:36:44.806783 | localhost | # Node Information
2025-12-08 06:36:44.806815 | localhost | Inventory Hostname: controller
2025-12-08 06:36:44.806841 | localhost | Hostname: np0005549981
2025-12-08 06:36:44.806863 | localhost | Username: zuul
2025-12-08 06:36:44.806885 | localhost | Distro: CentOS 9
2025-12-08 06:36:44.806904 | localhost | Provider: ibm-bm4-nodepool
2025-12-08 06:36:44.806948 | localhost | Region: regionOne
2025-12-08 06:36:44.806971 | localhost | Label: cloud-centos-9-stream-tripleo-ibm
2025-12-08 06:36:44.806990 | localhost | Product Name: OpenStack Compute
2025-12-08 06:36:44.807131 | localhost | Interface IP: 192.168.26.189
2025-12-08 06:36:44.835320 | 
2025-12-08 06:36:44.835388 | PLAY [all]
2025-12-08 06:36:44.841408 | 
2025-12-08 06:36:44.841472 | TASK [Gather network facts]
2025-12-08 06:36:45.184760 | controller | ok
2025-12-08 06:36:45.200021 | 
2025-12-08 06:36:45.200152 | TASK [include_role : start-zuul-console]
2025-12-08 06:36:45.217526 | controller | ok
2025-12-08 06:36:45.229025 | 
2025-12-08 06:36:45.229090 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-08 06:36:45.529426 | controller | ok
2025-12-08 06:36:45.537472 | 
2025-12-08 06:36:45.537536 | TASK [include_role : add-build-sshkey]
2025-12-08 06:36:45.556557 | controller | ok
2025-12-08 06:36:45.569066 | 
2025-12-08 06:36:45.569134 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-08 06:36:45.767367 | controller -> localhost | ok
2025-12-08 06:36:45.772636 | 
2025-12-08 06:36:45.772708 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-08 06:36:45.790280 | controller | ok
2025-12-08 06:36:45.803512 | controller | included: /var/lib/zuul/builds/c8a8de4fe48c4950991f041df900c43e/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-08 06:36:45.808966 | 
2025-12-08 06:36:45.809035 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-08 06:36:46.260077 | controller -> localhost | Generating public/private rsa key pair.
2025-12-08 06:36:46.260281 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/c8a8de4fe48c4950991f041df900c43e/work/c8a8de4fe48c4950991f041df900c43e_id_rsa.
2025-12-08 06:36:46.260318 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/c8a8de4fe48c4950991f041df900c43e/work/c8a8de4fe48c4950991f041df900c43e_id_rsa.pub.
2025-12-08 06:36:46.260345 | controller -> localhost | The key fingerprint is:
2025-12-08 06:36:46.260368 | controller -> localhost | SHA256:AWrAWIxB17sy+uKpcLGgQpXr9u/3Vc5yR83V0Xyre8U zuul-build-sshkey
2025-12-08 06:36:46.260390 | controller -> localhost | The key's randomart image is:
2025-12-08 06:36:46.260410 | controller -> localhost | +---[RSA 3072]----+
2025-12-08 06:36:46.260430 | controller -> localhost | |oOo.. .        o.|
2025-12-08 06:36:46.260450 | controller -> localhost | |o +..o .        *|
2025-12-08 06:36:46.260470 | controller -> localhost | |   oo . .       =|
2025-12-08 06:36:46.260491 | controller -> localhost | |  ....   .     oo|
2025-12-08 06:36:46.260511 | controller -> localhost | |....  . S     .o+|
2025-12-08 06:36:46.260530 | controller -> localhost | |o..= .       .+.E|
2025-12-08 06:36:46.260548 | controller -> localhost | |+ +oo        o.+o|
2025-12-08 06:36:46.260567 | controller -> localhost | |o+o .    .  ..o..|
2025-12-08 06:36:46.260585 | controller -> localhost | |+oo. .oo. ..  .  |
2025-12-08 06:36:46.260603 | controller -> localhost | +----[SHA256]-----+
2025-12-08 06:36:46.260654 | controller -> localhost | ok: Runtime: 0:00:00.118070
2025-12-08 06:36:46.266334 | 
2025-12-08 06:36:46.266401 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-08 06:36:46.294124 | controller | ok
2025-12-08 06:36:46.303397 | controller | included: /var/lib/zuul/builds/c8a8de4fe48c4950991f041df900c43e/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-08 06:36:46.321228 | 
2025-12-08 06:36:46.321326 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-08 06:36:46.365086 | controller | skipping: Conditional result was False
2025-12-08 06:36:46.370567 | 
2025-12-08 06:36:46.370646 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-08 06:36:46.736230 | controller | changed
2025-12-08 06:36:46.744347 | 
2025-12-08 06:36:46.744435 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-08 06:36:46.942382 | controller | ok
2025-12-08 06:36:46.947183 | 
2025-12-08 06:36:46.947251 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-08 06:36:47.451977 | controller | changed
2025-12-08 06:36:47.456887 | 
2025-12-08 06:36:47.456977 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-08 06:36:47.950575 | controller | changed
2025-12-08 06:36:47.955565 | 
2025-12-08 06:36:47.955640 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-08 06:36:47.969550 | controller | skipping: Conditional result was False
2025-12-08 06:36:47.975855 | 
2025-12-08 06:36:47.975941 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-08 06:36:48.283966 | controller -> localhost | changed
2025-12-08 06:36:48.293068 | 
2025-12-08 06:36:48.293134 | TASK [add-build-sshkey : Add back temp key]
2025-12-08 06:36:48.521866 | controller -> localhost | Identity added: /var/lib/zuul/builds/c8a8de4fe48c4950991f041df900c43e/work/c8a8de4fe48c4950991f041df900c43e_id_rsa (zuul-build-sshkey)
2025-12-08 06:36:48.522066 | controller -> localhost | ok: Runtime: 0:00:00.007245
2025-12-08 06:36:48.527579 | 
2025-12-08 06:36:48.527639 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-08 06:36:48.801078 | controller | ok
2025-12-08 06:36:48.805545 | 
2025-12-08 06:36:48.805617 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-08 06:36:48.828933 | controller | skipping: Conditional result was False
2025-12-08 06:36:48.837899 | 
2025-12-08 06:36:48.837982 | TASK [include_role : validate-host]
2025-12-08 06:36:48.854872 | controller | ok
2025-12-08 06:36:48.892650 | 
2025-12-08 06:36:48.892732 | TASK [validate-host : Define zuul_info_dir fact]
2025-12-08 06:36:48.920931 | controller | ok
2025-12-08 06:36:48.925503 | 
2025-12-08 06:36:48.925568 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-12-08 06:36:49.131597 | controller -> localhost | ok
2025-12-08 06:36:49.137311 | 
2025-12-08 06:36:49.137395 | TASK [validate-host : Collect information about the host]
2025-12-08 06:36:49.689380 | controller | ok
2025-12-08 06:36:49.698806 | 
2025-12-08 06:36:49.698929 | TASK [validate-host : Sanitize hostname]
2025-12-08 06:36:49.771038 | controller | ok
2025-12-08 06:36:49.776466 | 
2025-12-08 06:36:49.776533 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-12-08 06:36:50.170098 | controller -> localhost | changed
2025-12-08 06:36:50.194775 | 
2025-12-08 06:36:50.194860 | TASK [validate-host : Collect information about zuul worker]
2025-12-08 06:36:50.495681 | controller | ok
2025-12-08 06:36:50.500288 | 
2025-12-08 06:36:50.500368 | TASK [validate-host : Write out all zuul information for each host]
2025-12-08 06:36:50.890990 | controller -> localhost | changed
2025-12-08 06:36:50.900026 | 
2025-12-08 06:36:50.900110 | TASK [include_role : prepare-workspace-openshift]
2025-12-08 06:36:50.913519 | controller | skipping: Conditional result was False
2025-12-08 06:36:50.918371 | 
2025-12-08 06:36:50.918445 | TASK [include_role : remove-zuul-sshkey]
2025-12-08 06:36:50.936761 | controller | skipping: Conditional result was False
2025-12-08 06:36:50.941776 | 
2025-12-08 06:36:50.941867 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-08 06:36:51.138964 | controller | ok: "logs"
2025-12-08 06:36:51.139179 | controller | ok: All items complete
2025-12-08 06:36:51.139211 | 
2025-12-08 06:36:51.298356 | controller | ok: "artifacts"
2025-12-08 06:36:51.449121 | controller | ok: "docs"
2025-12-08 06:36:51.463854 | 
2025-12-08 06:36:51.463956 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-08 06:36:51.652583 | controller | changed: "logs"
2025-12-08 06:36:51.810224 | controller | changed: "artifacts"
2025-12-08 06:36:51.971611 | controller | changed: "docs"
2025-12-08 06:36:51.998712 | 
2025-12-08 06:36:51.998776 | PLAY RECAP
2025-12-08 06:36:51.998821 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-12-08 06:36:51.998849 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-08 06:36:51.998869 | 
2025-12-08 06:36:52.069957 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-08 06:36:52.070765 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-12-08 06:36:52.643512 | 
2025-12-08 06:36:52.643618 | PLAY [all]
2025-12-08 06:36:52.663092 | 
2025-12-08 06:36:52.663171 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-12-08 06:36:52.712184 | controller | ok
2025-12-08 06:36:52.717330 | 
2025-12-08 06:36:52.717421 | TASK [mirror-info-fork : Create /etc/ci]
2025-12-08 06:36:53.038619 | controller | changed
2025-12-08 06:36:53.044594 | 
2025-12-08 06:36:53.044682 | TASK [mirror-info-fork : Install ci_mirror script]
2025-12-08 06:36:53.816658 | controller | changed
2025-12-08 06:36:53.826025 | 
2025-12-08 06:36:53.826103 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2025-12-08 06:36:54.175711 | controller | changed:
2025-12-08 06:36:54.175871 | controller | {
2025-12-08 06:36:54.175903 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2025-12-08 06:36:54.175955 | controller | }
2025-12-08 06:36:54.368635 | controller | changed:
2025-12-08 06:36:54.368719 | controller | {
2025-12-08 06:36:54.368751 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2025-12-08 06:36:54.368775 | controller | }
2025-12-08 06:36:54.564261 | controller | changed:
2025-12-08 06:36:54.564337 | controller | {
2025-12-08 06:36:54.564367 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com"
2025-12-08 06:36:54.564390 | controller | }
2025-12-08 06:36:54.758683 | controller | changed:
2025-12-08 06:36:54.758885 | controller | {
2025-12-08 06:36:54.758959 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2025-12-08 06:36:54.758988 | controller | }
2025-12-08 06:36:54.952926 | controller | changed:
2025-12-08 06:36:54.953011 | controller | {
2025-12-08 06:36:54.953039 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2025-12-08 06:36:54.953217 | controller | }
2025-12-08 06:36:55.146221 | controller | changed:
2025-12-08 06:36:55.146312 | controller | {
2025-12-08 06:36:55.146343 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2025-12-08 06:36:55.146367 | controller | }
2025-12-08 06:36:55.339394 | controller | changed:
2025-12-08 06:36:55.339478 | controller | {
2025-12-08 06:36:55.339508 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDLOQd4ZLtkZXQGY6UwAr/06ppWQK4fDO3HaqxPk98csyOCBXsliSKK39Bso828+5srIXiW7aI6aC9P5mwi4mUZlGPfJlQbfrcGvY+b/SocuvaGK+1RrHLoJCT52LBhwgrzlXio2jeksZeein8iaTrhsPrOAs7KggIL/rB9hEiB3NaOPWhhoCP4vlW6MEMExGcqB/1FVxXFBPnLkEyW0Lk7ycVflZl2ocRxbfjZi0+tI1Wlinp8PvSQSc/WVrAcDgKjc/mB4ODPOyYy3G8FHgfMsrXSDEyjBKgLKMsdCrAUcqJQWjkqXleXSYOV4q3pzL+9umK+q/e3P/bIoSFQzmJKTU1eDfuvPXmow9F5H54fii/Da7ezlMJ+wPGHJrRAkmzvMbALy7xwswLhZMkOGNtRcPqaKYRmIBKpw3o6bCTtcNUHOtOQnzwY8JzrM2eBWJBXAANYw+9/ho80JIiwhg29CFNpVBuHbql2YxJQNrnl90guN65rYNpDxdIluweyUf8= anbanerj@kaermorhen"
2025-12-08 06:36:55.339531 | controller | }
2025-12-08 06:36:55.539105 | controller | changed:
2025-12-08 06:36:55.539189 | controller | {
2025-12-08 06:36:55.539218 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC3VwV8Im9kRm49lt3tM36hj4Zv27FxGo4C1Q/0jqhzFmHY7RHbmeRr8ObhwWoHjXSozKWg8FL5ER0z3hTwL0W6lez3sL7hUaCmSuZmG5Hnl3x4vTSxDI9JZ/Y65rtYiiWQo2fC5xJhU/4+0e5e/pseCm8cKRSu+SaxhO+sd6FDojA2x1BzOzKiQRDy/1zWGp/cZkxcEuB1wHI5LMzN03c67vmbu+fhZRAUO4dQkvcnj2LrhQtpa+ytvnSjr8icMDosf1OsbSffwZFyHB/hfWGAfe0eIeSA2XPraxiPknXxiPKx2MJsaUTYbsZcm3EjFdHBBMumw5rBI74zLrMRvCO9GwBEmGT4rFng1nP+yw5DB8sn2zqpOsPg1LYRwCPOUveC13P6pgsZZPh812e8v5EKnETct+5XI3dVpdw6CnNiLwAyVAF15DJvBGT/u1k0Myg/bQn+Gv9k2MSj6LvQmf6WbZu2Wgjm30z3FyCneBqTL7mLF19YXzeC0ufHz5pnO1E= dasm@fedora"
2025-12-08 06:36:55.539256 | controller | }
2025-12-08 06:36:55.734164 | controller | changed:
2025-12-08 06:36:55.734259 | controller | {
2025-12-08 06:36:55.734288 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2025-12-08 06:36:55.734308 | controller | }
2025-12-08 06:36:55.931343 | controller | changed:
2025-12-08 06:36:55.931422 | controller | {
2025-12-08 06:36:55.931448 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2025-12-08 06:36:55.931468 | controller | }
2025-12-08 06:36:56.125584 | controller | changed:
2025-12-08 06:36:56.125660 | controller | {
2025-12-08 06:36:56.125688 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2025-12-08 06:36:56.125709 | controller | }
2025-12-08 06:36:56.341442 | controller | changed:
2025-12-08 06:36:56.341522 | controller | {
2025-12-08 06:36:56.341550 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2025-12-08 06:36:56.341572 | controller | }
2025-12-08 06:36:56.516572 | controller | changed:
2025-12-08 06:36:56.516656 | controller | {
2025-12-08 06:36:56.516684 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2025-12-08 06:36:56.516704 | controller | }
2025-12-08 06:36:56.713189 | controller | changed:
2025-12-08 06:36:56.713282 | controller | {
2025-12-08 06:36:56.713312 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2025-12-08 06:36:56.713333 | controller | }
2025-12-08 06:36:56.913095 | controller | changed:
2025-12-08 06:36:56.913179 | controller | {
2025-12-08 06:36:56.913208 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2025-12-08 06:36:56.913229 | controller | }
2025-12-08 06:36:57.108971 | controller | changed:
2025-12-08 06:36:57.109052 | controller | {
2025-12-08 06:36:57.109078 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2025-12-08 06:36:57.109097 | controller | }
2025-12-08 06:36:57.304800 | controller | changed:
2025-12-08 06:36:57.304888 | controller | {
2025-12-08 06:36:57.304935 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQCfNtF7NvKl915TGsGGoseUb06Hj8L/S4toWf0hExeY+F00woL6NvBlJD0nDct+P5a22I4EhvoQCRQ8reaPCm1lybR3uiRIJsj+8zkVvLwby9LXzfZorlNG9ofjd00FEmB09uW/YvTl6Q9XwwwX6tInzIOv3TMqTHHGOL74ibbj8J/FJR0cFEyj0z4WQRvtkh32xAHl83gbuINryMt0sqRI+clj2381NKL55DRLQrVw0gsfqqxiHAnXg21qWmc4J+b9e9kiuAFQjcjwTVkwJCcg3xbPwC/qokYRby/Y5S40UUd7/jEARGXT7RZgpzTuDd1oZiCVrnrqJNPaMNdVv5MLeFdf1B7iIe5aa/fGouX7AO4SdKhZUdnJmCFAGvjC6S3JMZ2wAcUl+OHnssfmdj7XL50cLo27vjuzMtLAgSqi6N99m92WCF2s8J9aVzszX7Xz9OKZCeGsiVJp3/NdABKzSEAyM9xBD/5Vho894Sav+otpySHe3p6RUTgbB5Zu8VyZRZ/UtB3ueXxyo764yrc6qWIDqrehm84Xm9g+/jpIBzGPl07NUNJpdt/6Sgf9RIKXw/7XypO5yZfUcuFNGTxLfqjTNrtgLZNcjfav6sSdVXVcMPL//XNuRdKmVFaO76eV/oGMQGr1fGcCD+N+CpI7+Q+fCNB6VFWG4nZFuI/Iuw== averdagu@redhat.com"
2025-12-08 06:36:57.304961 | controller | }
2025-12-08 06:36:57.505664 | controller | changed:
2025-12-08 06:36:57.505752 | controller | {
2025-12-08 06:36:57.505781 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDq8l27xI+QlQVdS4djp9ogSoyrNE2+Ox6vKPdhSNL1J3PE5w+WCSvMz9A5gnNuH810zwbekEApbxTze/gLQJwBHA52CChfURpXrFaxY7ePXRElwKAL3mJfzBWY/c5jnNL9TCVmFJTGZkFZP3Nh+BMgZvL6xBkt3WKm6Uq18qzd9XeKcZusrA+O+uLv1fVeQnadY9RIqOCyeFYCzLWrUfTyE8x/XG0hAWIM7qpnF2cALQS2h9n4hW5ybiUN790H08wf9hFwEf5nxY9Z9dVkPFQiTSGKNBzmnCXU9skxS/xhpFjJ5duGSZdtAHe9O+nGZm9c67hxgtf8e5PDuqAdXEv2cf6e3VBAt+Bz8EKI3yosTj0oZHfwr42Yzb1l/SKy14Rggsrc9KAQlrGXan6+u2jcQqqx7l+SWmnpFiWTV9u5cWj2IgOhApOitmRBPYqk9rE2usfO0hLn/Pj/R/Nau4803e1/EikdLE7Ps95s9mX5jRDjAoUa2JwFF5RsVFyL910= ashigupt@ashigupt.remote.csb"
2025-12-08 06:36:57.505812 | controller | }
2025-12-08 06:36:57.702508 | controller | changed:
2025-12-08 06:36:57.702596 | controller | {
2025-12-08 06:36:57.702624 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2025-12-08 06:36:57.702645 | controller | }
2025-12-08 06:36:57.900037 | controller | changed:
2025-12-08 06:36:57.900127 | controller | {
2025-12-08 06:36:57.900155 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2025-12-08 06:36:57.900178 | controller | }
2025-12-08 06:36:58.100465 | controller | changed:
2025-12-08 06:36:58.100624 | controller | {
2025-12-08 06:36:58.100661 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2025-12-08 06:36:58.100684 | controller | }
2025-12-08 06:36:58.296303 | controller | changed:
2025-12-08 06:36:58.296396 | controller | {
2025-12-08 06:36:58.296424 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2025-12-08 06:36:58.296446 | controller | }
2025-12-08 06:36:58.493639 | controller | changed:
2025-12-08 06:36:58.493724 | controller | {
2025-12-08 06:36:58.493752 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQDZdI7t1cxYx65heVI24HTV4F7oQLW1zyfxHreL2TIJKxjyrUUKIFEUmTutcBlJRLNT2Eoix6x1sOw9YrchloCLcn//SGfTElr9mSc5jbjb7QXEU+zJMhtxyEJ1Po3CUGnj7ckiIXw7wcawZtrEOAQ9pH3ExYCJcEMiyNjRQZCxT3tPK+S4B95EWh5Fsrz9CkwpjNRPPH7LigCeQTM3Wc7r97utAslBUUvYceDSLA7rMgkitJE38b7rZBeYzsGQ8YYUBjTCtehqQXxCRjizbHWaaZkBU+N3zkKB6n/iCNGIO690NK7A/qb6msTijiz1PeuM8ThOsi9qXnbX5v0PoTpcFSojV7NHAQ71f0XXuS43FhZctT+Dcx44dT8Fb5vJu2cJGrk+qF8ZgJYNpRS7gPg0EG2EqjK7JMf9ULdjSu0r+KlqIAyLvtzT4eOnQipoKlb/WG5D/0ohKv7OMQ352ggfkBFIQsRXyyTCT98Ft9juqPuahi3CAQmP4H9dyE+7+Kz437PEtsxLmfm6naNmWi7Ee1DqWPwS8rEajsm4sNM4wW9gdBboJQtc0uZw0DfLj1I9r3Mc8Ol0jYtz0yNQDSzVLrGCaJlC311trU70tZ+ZkAVV6Mn8lOhSbj1cK0lvSr6ZK4dgqGl3I1eTZJJhbLNdg7UOVaiRx9543+C/p/As7w== brjackma@redhat.com"
2025-12-08 06:36:58.493775 | controller | }
2025-12-08 06:36:58.689798 | controller | changed:
2025-12-08 06:36:58.689872 | controller | {
2025-12-08 06:36:58.689898 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2025-12-08 06:36:58.689940 | controller | }
2025-12-08 06:36:58.891397 | controller | changed:
2025-12-08 06:36:58.891482 | controller | {
2025-12-08 06:36:58.891510 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2025-12-08 06:36:58.891531 | controller | }
2025-12-08 06:36:59.087159 | controller | changed:
2025-12-08 06:36:59.087257 | controller | {
2025-12-08 06:36:59.087287 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2025-12-08 06:36:59.087310 | controller | }
2025-12-08 06:36:59.125878 | 
2025-12-08 06:36:59.125992 | TASK [Set timezone to UTC]
2025-12-08 06:36:59.491314 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2025-12-08 06:36:59.497841 | 
2025-12-08 06:36:59.497945 | TASK [Create nodepool directory]
2025-12-08 06:36:59.730716 | controller | changed
2025-12-08 06:36:59.746038 | 
2025-12-08 06:36:59.746140 | TASK [Create nodepool sub_nodes file]
2025-12-08 06:37:00.258439 | controller | changed
2025-12-08 06:37:00.263717 | 
2025-12-08 06:37:00.263804 | TASK [Create nodepool sub_nodes_private file]
2025-12-08 06:37:00.747454 | controller | changed
2025-12-08 06:37:00.753030 | 
2025-12-08 06:37:00.753111 | LOOP [Populate nodepool sub_nodes file]
2025-12-08 06:37:00.782440 | 
2025-12-08 06:37:00.782568 | LOOP [Populate nodepool sub_nodes_private file]
2025-12-08 06:37:00.811295 | 
2025-12-08 06:37:00.811427 | TASK [Create nodepool primary file]
2025-12-08 06:37:00.834845 | controller | skipping: Conditional result was False
2025-12-08 06:37:00.840355 | 
2025-12-08 06:37:00.840433 | TASK [Create nodepool node_private for this node]
2025-12-08 06:37:01.365669 | controller | changed
2025-12-08 06:37:01.371171 | 
2025-12-08 06:37:01.371274 | LOOP [Copy ssh keys to nodepool directory]
2025-12-08 06:37:01.709614 | controller | ok: Item: id_rsa Runtime: 0:00:00.004482
2025-12-08 06:37:01.709789 | 
2025-12-08 06:37:01.878273 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.004423
2025-12-08 06:37:01.888235 | 
2025-12-08 06:37:01.888342 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2025-12-08 06:37:02.424974 | controller | changed
2025-12-08 06:37:02.429904 | 
2025-12-08 06:37:02.429992 | TASK [Validate sudoers config after edits]
2025-12-08 06:37:02.679756 | controller | /etc/sudoers: parsed OK
2025-12-08 06:37:02.679800 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2025-12-08 06:37:02.679809 | controller | /etc/sudoers.d/zuul: parsed OK
2025-12-08 06:37:02.679815 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2025-12-08 06:37:02.973093 | controller | ok: Runtime: 0:00:00.005309
2025-12-08 06:37:02.978851 | 
2025-12-08 06:37:02.978947 | TASK [Show the environment passed in to job shell scripts]
2025-12-08 06:37:03.193664 | controller | SHELL=/bin/bash
2025-12-08 06:37:03.193718 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2025-12-08 06:37:03.193764 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2025-12-08 06:37:03.193773 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/34/3534/1088d6d967ec40daf4d458b96d952747a4005ed9^openstack-k8s-operators/ci-framework:main:refs/changes/33/3533/04826bcadcfb4679a4764897bf49af7ab47a0408
2025-12-08 06:37:03.193782 | controller | PWD=/home/zuul
2025-12-08 06:37:03.193787 | controller | ZUUL_PIPELINE=github-check
2025-12-08 06:37:03.193793 | controller | LOGNAME=zuul
2025-12-08 06:37:03.193800 | controller | XDG_SESSION_TYPE=tty
2025-12-08 06:37:03.193805 | controller | _=/usr/bin/env
2025-12-08 06:37:03.193811 | controller | MOTD_SHOWN=pam
2025-12-08 06:37:03.193816 | controller | HOME=/home/zuul
2025-12-08 06:37:03.193822 | controller | LANG=en_US.UTF-8
2025-12-08 06:37:03.193827 | controller | SSH_CONNECTION=192.168.26.12 38970 192.168.26.189 22
2025-12-08 06:37:03.193833 | controller | TOX_TESTENV_PASSENV=ZUUL_UUID ZUUL_PROJECT ZUUL_SHORT_PROJECT_NAME ZUUL_PIPELINE ZUUL_VOTING WORKSPACE BUILD_TIMEOUT ZUUL_BRANCH ZUUL_CHANGES ZUUL_CHANGE_IDS ZUUL_CHANGE ZUUL_PATCHSET
2025-12-08 06:37:03.193838 | controller | ZUUL_CHANGE_IDS=3534,1088d6d967ec40daf4d458b96d952747a4005ed9 3533,04826bcadcfb4679a4764897bf49af7ab47a0408
2025-12-08 06:37:03.193844 | controller | WORKSPACE=/home/zuul/workspace
2025-12-08 06:37:03.193849 | controller | XDG_SESSION_CLASS=user
2025-12-08 06:37:03.193855 | controller | SELINUX_ROLE_REQUESTED=
2025-12-08 06:37:03.193860 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2025-12-08 06:37:03.193866 | controller | USER=zuul
2025-12-08 06:37:03.193871 | controller | ZUUL_VOTING=True
2025-12-08 06:37:03.193877 | controller | BUILD_TIMEOUT=1800000
2025-12-08 06:37:03.193882 | controller | SELINUX_USE_CURRENT_RANGE=
2025-12-08 06:37:03.193887 | controller | SHLVL=1
2025-12-08 06:37:03.193892 | controller | ZUUL_PATCHSET=04826bcadcfb4679a4764897bf49af7ab47a0408
2025-12-08 06:37:03.193898 | controller | XDG_SESSION_ID=1
2025-12-08 06:37:03.193903 | controller | ZUUL_BRANCH=main
2025-12-08 06:37:03.193909 | controller | XDG_RUNTIME_DIR=/run/user/1000
2025-12-08 06:37:03.193914 | controller | SSH_CLIENT=192.168.26.12 38970 22
2025-12-08 06:37:03.193919 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2025-12-08 06:37:03.193925 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2025-12-08 06:37:03.193930 | controller | which_declare=declare -f
2025-12-08 06:37:03.193936 | controller | PATH=/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2025-12-08 06:37:03.193942 | controller | SELINUX_LEVEL_REQUESTED=
2025-12-08 06:37:03.193947 | controller | ZUUL_CHANGE=3533
2025-12-08 06:37:03.193953 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2025-12-08 06:37:03.193958 | controller | ZUUL_UUID=c8a8de4fe48c4950991f041df900c43e
2025-12-08 06:37:03.193963 | controller | BASH_FUNC_which%%=() {  ( alias;
2025-12-08 06:37:03.193970 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2025-12-08 06:37:03.193975 | controller | }
2025-12-08 06:37:03.505721 | controller | ok: Runtime: 0:00:00.005126
2025-12-08 06:37:03.511046 | 
2025-12-08 06:37:03.511110 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2025-12-08 06:37:03.525069 | controller | skipping: Conditional result was False
2025-12-08 06:37:03.531631 | 
2025-12-08 06:37:03.531748 | TASK [Symlink /home/zuul-worker/workspace]
2025-12-08 06:37:04.056967 | controller | skipping: Conditional result was False
2025-12-08 06:37:04.062762 | 
2025-12-08 06:37:04.062828 | TASK [Ensure legacy workspace directory]
2025-12-08 06:37:04.244790 | controller | changed
2025-12-08 06:37:04.267020 | 
2025-12-08 06:37:04.267091 | PLAY RECAP
2025-12-08 06:37:04.267138 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-12-08 06:37:04.267163 | 
2025-12-08 06:37:04.354040 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-12-08 06:37:04.354791 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-12-08 06:37:04.967170 | 
2025-12-08 06:37:04.967283 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2025-12-08 06:37:04.988073 | 
2025-12-08 06:37:04.988164 | TASK [Create zuul-output directory]
2025-12-08 06:37:05.329051 | controller | changed
2025-12-08 06:37:05.334537 | 
2025-12-08 06:37:05.334640 | TASK [Slurp Zuul inventory test]
2025-12-08 06:37:05.616033 | controller -> localhost | ok
2025-12-08 06:37:05.627770 | 
2025-12-08 06:37:05.627944 | TASK [Save zuul inventory]
2025-12-08 06:37:06.356033 | controller | changed
2025-12-08 06:37:06.360782 | 
2025-12-08 06:37:06.360848 | TASK [Save zuul vars without the change_message]
2025-12-08 06:37:06.906885 | controller | changed
2025-12-08 06:37:06.923849 | 
2025-12-08 06:37:06.923931 | PLAY RECAP
2025-12-08 06:37:06.923982 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-08 06:37:06.924007 | 
2025-12-08 06:37:06.992893 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-12-08 06:37:06.993682 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-12-08 06:37:07.548864 | 
2025-12-08 06:37:07.548986 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2025-12-08 06:37:07.569098 | 
2025-12-08 06:37:07.569175 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2025-12-08 06:37:07.600184 | controller | ok
2025-12-08 06:37:07.616476 | 
2025-12-08 06:37:07.616563 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-12-08 06:37:07.649763 | controller | skipping: Conditional result was False
2025-12-08 06:37:07.655129 | 
2025-12-08 06:37:07.655214 | TASK [mirror-info-fork : Create /etc/ci]
2025-12-08 06:37:07.976286 | controller | ok
2025-12-08 06:37:07.981806 | 
2025-12-08 06:37:07.981874 | TASK [mirror-info-fork : Install ci_mirror script]
2025-12-08 06:37:08.575944 | controller | ok
2025-12-08 06:37:08.585862 | 
2025-12-08 06:37:08.585975 | TASK [Prepare workspace]
2025-12-08 06:37:08.604153 | controller | ok
2025-12-08 06:37:08.620357 | 
2025-12-08 06:37:08.620429 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-08 06:37:08.911796 | controller | ok
2025-12-08 06:37:08.917658 | 
2025-12-08 06:37:08.917735 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-08 06:37:11.272336 | controller | Output suppressed because no_log was given
2025-12-08 06:37:11.281616 | 
2025-12-08 06:37:11.281684 | LOOP [Create zuul-output directory]
2025-12-08 06:37:11.462414 | controller | changed: "/home/zuul/ci-framework-data/logs"
2025-12-08 06:37:11.614270 | controller | ok: "/home/zuul/zuul-output/logs"
2025-12-08 06:37:11.626570 | 
2025-12-08 06:37:11.626672 | TASK [Install required packages]
2025-12-08 06:38:01.421533 | controller | changed
2025-12-08 06:38:01.426466 | 
2025-12-08 06:38:01.426526 | TASK [Install venv]
2025-12-08 06:39:04.836199 | controller | changed
2025-12-08 06:39:04.860487 | 
2025-12-08 06:39:04.860550 | PLAY RECAP
2025-12-08 06:39:04.860596 | controller | ok: 7 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-12-08 06:39:04.860620 | 
2025-12-08 06:39:04.934744 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-12-08 06:39:04.935586 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-12-08 06:39:05.489903 | 
2025-12-08 06:39:05.490030 | PLAY [Run ci/playbooks/molecule-test.yml]
2025-12-08 06:39:05.510472 | 
2025-12-08 06:39:05.510552 | TASK [Gather required facts]
2025-12-08 06:39:05.996201 | controller | ok
2025-12-08 06:39:06.001607 | 
2025-12-08 06:39:06.001684 | TASK [Load environment var if instructed to]
2025-12-08 06:39:06.025595 | controller | skipping: Conditional result was False
2025-12-08 06:39:06.030803 | 
2025-12-08 06:39:06.030884 | TASK [Ensure group_vars dir exists]
2025-12-08 06:39:06.333068 | controller | ok
2025-12-08 06:39:06.339056 | 
2025-12-08 06:39:06.339140 | TASK [Print related variables]
2025-12-08 06:39:06.368045 | controller | ok:
2025-12-08 06:39:06.368160 | controller | mol_config_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config_local.yml
2025-12-08 06:39:06.368191 | controller | roles_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/run_hook
2025-12-08 06:39:06.373278 | 
2025-12-08 06:39:06.373344 | TASK [Run molecule]
2025-12-08 06:39:07.371622 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2025-12-08 06:39:07.449623 | controller | INFO     Running default > prepare
2025-12-08 06:39:08.153566 | controller |
2025-12-08 06:39:08.153653 | controller | PLAY [Prepare] *****************************************************************
2025-12-08 06:39:08.153744 | controller |
2025-12-08 06:39:08.154279 | controller | TASK [Gathering Facts] *********************************************************
2025-12-08 06:39:08.154394 | controller | Monday 08 December 2025  06:39:08 +0000 (0:00:00.012)       0:00:00.012 *******
2025-12-08 06:39:09.054112 | controller | ok: [instance]
2025-12-08 06:39:09.054175 | controller |
2025-12-08 06:39:09.054281 | controller | TASK [Create dummy env file] ***************************************************
2025-12-08 06:39:09.054386 | controller | Monday 08 December 2025  06:39:09 +0000 (0:00:00.901)       0:00:00.913 *******
2025-12-08 06:39:09.630140 | controller | changed: [instance]
2025-12-08 06:39:09.630192 | controller |
2025-12-08 06:39:09.630311 | controller | TASK [Create dummy playbook] ***************************************************
2025-12-08 06:39:09.630423 | controller | Monday 08 December 2025  06:39:09 +0000 (0:00:00.575)       0:00:01.489 *******
2025-12-08 06:39:11.604913 | controller | changed: [instance] => (item=dummy-1.yml)
2025-12-08 06:39:11.604997 | controller | changed: [instance] => (item=dummy-2.yml)
2025-12-08 06:39:11.605103 | controller | changed: [instance] => (item=dummy-3.yml)
2025-12-08 06:39:11.605210 | controller | changed: [instance] => (item=dummy-4.yml)
2025-12-08 06:39:11.605323 | controller | changed: [instance] => (item=dummy-5.yml)
2025-12-08 06:39:11.605451 | controller | changed: [instance] => (item=dummy-6.yml)
2025-12-08 06:39:11.605544 | controller |
2025-12-08 06:39:11.605647 | controller | TASK [Remove dummy file for retry playbook test] *******************************
2025-12-08 06:39:11.605748 | controller | Monday 08 December 2025  06:39:11 +0000 (0:00:01.974)       0:00:03.463 *******
2025-12-08 06:39:11.889443 | controller | ok: [instance]
2025-12-08 06:39:11.889519 | controller |
2025-12-08 06:39:11.889627 | controller | TASK [Create dummy retry playbook] *********************************************
2025-12-08 06:39:11.889734 | controller | Monday 08 December 2025  06:39:11 +0000 (0:00:00.284)       0:00:03.748 *******
2025-12-08 06:39:12.240706 | controller | changed: [instance]
2025-12-08 06:39:12.240764 | controller |
2025-12-08 06:39:12.240860 | controller | PLAY RECAP *********************************************************************
2025-12-08 06:39:12.240987 | controller | instance                   : ok=5    changed=3    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-12-08 06:39:12.241083 | controller |
2025-12-08 06:39:12.241177 | controller | Monday 08 December 2025  06:39:12 +0000 (0:00:00.351)       0:00:04.100 *******
2025-12-08 06:39:12.241266 | controller | ===============================================================================
2025-12-08 06:39:12.241359 | controller | Create dummy playbook --------------------------------------------------- 1.97s
2025-12-08 06:39:12.241478 | controller | Gathering Facts --------------------------------------------------------- 0.90s
2025-12-08 06:39:12.241571 | controller | Create dummy env file --------------------------------------------------- 0.58s
2025-12-08 06:39:12.241663 | controller | Create dummy retry playbook --------------------------------------------- 0.35s
2025-12-08 06:39:12.241756 | controller | Remove dummy file for retry playbook test ------------------------------- 0.28s
2025-12-08 06:39:12.308104 | controller | INFO     Running default > converge
2025-12-08 06:39:12.750516 | controller |
2025-12-08 06:39:12.750962 | controller | PLAY [Converge] ****************************************************************
2025-12-08 06:39:13.570156 | controller |
2025-12-08 06:39:13.570192 | controller | TASK [Gathering Facts] *********************************************************
2025-12-08 06:39:13.570204 | controller | Monday 08 December 2025  06:39:12 +0000 (0:00:00.016)       0:00:00.016 *******
2025-12-08 06:39:13.570215 | controller | ok: [instance]
2025-12-08 06:39:13.601953 | controller |
2025-12-08 06:39:13.601987 | controller | TASK [No hook] *****************************************************************
2025-12-08 06:39:13.601996 | controller | Monday 08 December 2025  06:39:13 +0000 (0:00:00.819)       0:00:00.835 *******
2025-12-08 06:39:13.602006 | controller |
2025-12-08 06:39:13.663627 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-12-08 06:39:13.663677 | controller | Monday 08 December 2025  06:39:13 +0000 (0:00:00.032)       0:00:00.867 *******
2025-12-08 06:39:13.663690 | controller | ok: [instance]
2025-12-08 06:39:13.745381 | controller |
2025-12-08 06:39:13.745433 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-12-08 06:39:13.745445 | controller | Monday 08 December 2025  06:39:13 +0000 (0:00:00.061)       0:00:00.929 *******
2025-12-08 06:39:13.745456 | controller | ok: [instance]
2025-12-08 06:39:13.824576 | controller |
2025-12-08 06:39:13.824605 | controller | TASK [run_hook : Loop on hooks for no_hook] ************************************
2025-12-08 06:39:13.824613 | controller | Monday 08 December 2025  06:39:13 +0000 (0:00:00.081)       0:00:01.011 *******
2025-12-08 06:39:13.824624 | controller | skipping: [instance]
2025-12-08 06:39:13.849487 | controller |
2025-12-08 06:39:13.849552 | controller | TASK [Ensure we do not have ceph_uuid] *****************************************
2025-12-08 06:39:13.849572 | controller | Monday 08 December 2025  06:39:13 +0000 (0:00:00.079)       0:00:01.090 *******
2025-12-08 06:39:13.849587 | controller | ok: [instance] => changed=false
2025-12-08 06:39:13.880993 | controller |   msg: All assertions passed
2025-12-08 06:39:13.881029 | controller |
2025-12-08 06:39:13.881039 | controller | TASK [Combined hooks] **********************************************************
2025-12-08 06:39:13.881047 | controller | Monday 08 December 2025  06:39:13 +0000 (0:00:00.024)       0:00:01.115 *******
2025-12-08 06:39:13.881059 | controller |
2025-12-08 06:39:13.940339 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-12-08 06:39:13.940375 | controller | Monday 08 December 2025  06:39:13 +0000 (0:00:00.031)       0:00:01.147 *******
2025-12-08 06:39:13.940388 | controller | ok: [instance]
2025-12-08 06:39:14.018221 | controller |
2025-12-08 06:39:14.018254 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-12-08 06:39:14.018263 | controller | Monday 08 December 2025  06:39:13 +0000 (0:00:00.058)       0:00:01.206 *******
2025-12-08 06:39:14.018274 | controller | ok: [instance]
2025-12-08 06:39:14.146487 | controller |
2025-12-08 06:39:14.146529 | controller | TASK [run_hook : Loop on hooks for run_molecule] *******************************
2025-12-08 06:39:14.146540 | controller | Monday 08 December 2025  06:39:14 +0000 (0:00:00.078)       0:00:01.284 *******
2025-12-08 06:39:14.146557 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/run_hook/tasks/playbook.yml for instance => (item={'name': '01 Default noop hook', 'source': 'noop.yml', 'type': 'playbook'})
2025-12-08 06:39:14.146762 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/run_hook/tasks/playbook.yml for instance => (item={'name': '02 Re-run noop', 'source': 'noop.yml', 'type': 'playbook'})
2025-12-08 06:39:14.146950 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/run_hook/tasks/playbook.yml for instance => (item={'source': '/tmp/dummy-1.yml', 'type': 'playbook', 'extra_vars': {'foo': 'bar', 'file': '/tmp/dummy-env.yml'}, 'name': '03 single hook'})
2025-12-08 06:39:14.147085 | controller |
2025-12-08 06:39:14.147222 | controller | TASK [run_hook : Set playbook path for 01 Default noop hook] *******************
2025-12-08 06:39:14.147356 | controller | Monday 08 December 2025  06:39:14 +0000 (0:00:00.128)       0:00:01.412 *******
2025-12-08 06:39:14.198181 | controller | ok: [instance]
2025-12-08 06:39:14.198372 | controller |
2025-12-08 06:39:14.198581 | controller | TASK [run_hook : Get file stat] ************************************************
2025-12-08 06:39:14.198757 | controller | Monday 08 December 2025  06:39:14 +0000 (0:00:00.052)       0:00:01.464 *******
2025-12-08 06:39:14.492242 | controller | ok: [instance]
2025-12-08 06:39:14.509508 | controller |
2025-12-08 06:39:14.509539 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-12-08 06:39:14.509550 | controller | Monday 08 December 2025  06:39:14 +0000 (0:00:00.293)       0:00:01.758 *******
2025-12-08 06:39:14.509561 | controller | skipping: [instance]
2025-12-08 06:39:14.797077 | controller |
2025-12-08 06:39:14.797110 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-12-08 06:39:14.797119 | controller | Monday 08 December 2025  06:39:14 +0000 (0:00:00.017)       0:00:01.775 *******
2025-12-08 06:39:14.797137 | controller | ok: [instance]
2025-12-08 06:39:14.816541 | controller |
2025-12-08 06:39:14.816579 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-12-08 06:39:14.816588 | controller | Monday 08 December 2025  06:39:14 +0000 (0:00:00.287)       0:00:02.063 *******
2025-12-08 06:39:14.816599 | controller | ok: [instance]
2025-12-08 06:39:14.816625 | controller |
2025-12-08 06:39:14.816888 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-12-08 06:39:15.115327 | controller | Monday 08 December 2025  06:39:14 +0000 (0:00:00.019)       0:00:02.082 *******
2025-12-08 06:39:15.115366 | controller | ok: [instance]
2025-12-08 06:39:15.305384 | controller |
2025-12-08 06:39:15.305443 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-12-08 06:39:15.305452 | controller | Monday 08 December 2025  06:39:15 +0000 (0:00:00.298)       0:00:02.381 *******
2025-12-08 06:39:15.305463 | controller | ok: [instance]
2025-12-08 06:39:15.912505 | controller |
2025-12-08 06:39:15.912546 | controller | TASK [run_hook : Run hook without retry - 01 Default noop hook] ****************
2025-12-08 06:39:15.912555 | controller | Monday 08 December 2025  06:39:15 +0000 (0:00:00.189)       0:00:02.571 *******
2025-12-08 06:39:15.912567 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_000_run_hook_without_retry_01.log
2025-12-08 06:39:15.912594 | controller | changed: [instance]
2025-12-08 06:39:15.912905 | controller |
2025-12-08 06:39:15.943904 | controller | TASK [run_hook : Run hook with retry - 01 Default noop hook] *******************
2025-12-08 06:39:15.943938 | controller | Monday 08 December 2025  06:39:15 +0000 (0:00:00.607)       0:00:03.178 *******
2025-12-08 06:39:15.943950 | controller | skipping: [instance]
2025-12-08 06:39:16.122950 | controller |
2025-12-08 06:39:16.122983 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-12-08 06:39:16.122991 | controller | Monday 08 December 2025  06:39:15 +0000 (0:00:00.031)       0:00:03.210 *******
2025-12-08 06:39:16.123003 | controller | ok: [instance]
2025-12-08 06:39:16.142478 | controller |
2025-12-08 06:39:16.142505 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-12-08 06:39:16.142513 | controller | Monday 08 December 2025  06:39:16 +0000 (0:00:00.178)       0:00:03.388 *******
2025-12-08 06:39:16.142525 | controller | skipping: [instance]
2025-12-08 06:39:16.142548 | controller |
2025-12-08 06:39:16.142556 | controller | TASK [run_hook : Set playbook path for 02 Re-run noop] *************************
2025-12-08 06:39:16.142632 | controller | Monday 08 December 2025  06:39:16 +0000 (0:00:00.020)       0:00:03.408 *******
2025-12-08 06:39:16.192467 | controller | ok: [instance]
2025-12-08 06:39:16.192486 | controller |
2025-12-08 06:39:16.192493 | controller | TASK [run_hook : Get file stat] ************************************************
2025-12-08 06:39:16.192501 | controller | Monday 08 December 2025  06:39:16 +0000 (0:00:00.049)       0:00:03.458 *******
2025-12-08 06:39:16.389483 | controller | ok: [instance]
2025-12-08 06:39:16.389581 | controller |
2025-12-08 06:39:16.389598 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-12-08 06:39:16.389609 | controller | Monday 08 December 2025  06:39:16 +0000 (0:00:00.196)       0:00:03.655 *******
2025-12-08 06:39:16.409060 | controller | skipping: [instance]
2025-12-08 06:39:16.600189 | controller |
2025-12-08 06:39:16.600221 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-12-08 06:39:16.600230 | controller | Monday 08 December 2025  06:39:16 +0000 (0:00:00.019)       0:00:03.675 *******
2025-12-08 06:39:16.600240 | controller | ok: [instance]
2025-12-08 06:39:16.622259 | controller |
2025-12-08 06:39:16.622287 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-12-08 06:39:16.622297 | controller | Monday 08 December 2025  06:39:16 +0000 (0:00:00.190)       0:00:03.866 *******
2025-12-08 06:39:16.622310 | controller | ok: [instance]
2025-12-08 06:39:16.824781 | controller |
2025-12-08 06:39:16.824820 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-12-08 06:39:16.824829 | controller | Monday 08 December 2025  06:39:16 +0000 (0:00:00.022)       0:00:03.888 *******
2025-12-08 06:39:16.824840 | controller | ok: [instance]
2025-12-08 06:39:16.825210 | controller |
2025-12-08 06:39:17.030740 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-12-08 06:39:17.030776 | controller | Monday 08 December 2025  06:39:16 +0000 (0:00:00.202)       0:00:04.090 *******
2025-12-08 06:39:17.030789 | controller | ok: [instance]
2025-12-08 06:39:17.636187 | controller |
2025-12-08 06:39:17.636223 | controller | TASK [run_hook : Run hook without retry - 02 Re-run noop] **********************
2025-12-08 06:39:17.636231 | controller | Monday 08 December 2025  06:39:17 +0000 (0:00:00.206)       0:00:04.296 *******
2025-12-08 06:39:17.636242 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_001_run_hook_without_retry_02_re.log
2025-12-08 06:39:17.667033 | controller | changed: [instance]
2025-12-08 06:39:17.667058 | controller |
2025-12-08 06:39:17.667066 | controller | TASK [run_hook : Run hook with retry - 02 Re-run noop] *************************
2025-12-08 06:39:17.667072 | controller | Monday 08 December 2025  06:39:17 +0000 (0:00:00.605)       0:00:04.902 *******
2025-12-08 06:39:17.667082 | controller | skipping: [instance]
2025-12-08 06:39:17.848567 | controller |
2025-12-08 06:39:17.848604 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-12-08 06:39:17.848613 | controller | Monday 08 December 2025  06:39:17 +0000 (0:00:00.031)       0:00:04.933 *******
2025-12-08 06:39:17.848623 | controller | ok: [instance]
2025-12-08 06:39:17.870138 | controller |
2025-12-08 06:39:17.870164 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-12-08 06:39:17.870175 | controller | Monday 08 December 2025  06:39:17 +0000 (0:00:00.181)       0:00:05.114 *******
2025-12-08 06:39:17.870187 | controller | skipping: [instance]
2025-12-08 06:39:17.923555 | controller |
2025-12-08 06:39:17.923604 | controller | TASK [run_hook : Set playbook path for 03 single hook] *************************
2025-12-08 06:39:17.923615 | controller | Monday 08 December 2025  06:39:17 +0000 (0:00:00.021)       0:00:05.136 *******
2025-12-08 06:39:17.923633 | controller | ok: [instance]
2025-12-08 06:39:17.923664 | controller |
2025-12-08 06:39:17.923675 | controller | TASK [run_hook : Get file stat] ************************************************
2025-12-08 06:39:17.923758 | controller | Monday 08 December 2025  06:39:17 +0000 (0:00:00.053)       0:00:05.190 *******
2025-12-08 06:39:18.120839 | controller | ok: [instance]
2025-12-08 06:39:18.141294 | controller |
2025-12-08 06:39:18.141325 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-12-08 06:39:18.141333 | controller | Monday 08 December 2025  06:39:18 +0000 (0:00:00.196)       0:00:05.386 *******
2025-12-08 06:39:18.141344 | controller | skipping: [instance]
2025-12-08 06:39:18.335024 | controller |
2025-12-08 06:39:18.335058 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-12-08 06:39:18.335066 | controller | Monday 08 December 2025  06:39:18 +0000 (0:00:00.020)       0:00:05.407 *******
2025-12-08 06:39:18.335077 | controller | ok: [instance]
2025-12-08 06:39:18.357495 | controller |
2025-12-08 06:39:18.357532 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-12-08 06:39:18.357540 | controller | Monday 08 December 2025  06:39:18 +0000 (0:00:00.193)       0:00:05.600 *******
2025-12-08 06:39:18.357551 | controller | ok: [instance]
2025-12-08 06:39:18.561874 | controller |
2025-12-08 06:39:18.561910 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-12-08 06:39:18.561919 | controller | Monday 08 December 2025  06:39:18 +0000 (0:00:00.022)       0:00:05.623 *******
2025-12-08 06:39:18.561929 | controller | ok: [instance]
2025-12-08 06:39:18.754209 | controller |
2025-12-08 06:39:18.754244 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-12-08 06:39:18.754252 | controller | Monday 08 December 2025  06:39:18 +0000 (0:00:00.204)       0:00:05.827 *******
2025-12-08 06:39:18.754263 | controller | ok: [instance]
2025-12-08 06:39:20.768820 | controller |
2025-12-08 06:39:20.768857 | controller | TASK [run_hook : Run hook without retry - 03 single hook] **********************
2025-12-08 06:39:20.768880 | controller | Monday 08 December 2025  06:39:18 +0000 (0:00:00.192)       0:00:06.020 *******
2025-12-08 06:39:20.768891 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_002_run_hook_without_retry_03.log
2025-12-08 06:39:20.799142 | controller | changed: [instance]
2025-12-08 06:39:20.799199 | controller |
2025-12-08 06:39:20.799208 | controller | TASK [run_hook : Run hook with retry - 03 single hook] *************************
2025-12-08 06:39:20.799215 | controller | Monday 08 December 2025  06:39:20 +0000 (0:00:02.014)       0:00:08.034 *******
2025-12-08 06:39:20.799225 | controller | skipping: [instance]
2025-12-08 06:39:20.990318 | controller |
2025-12-08 06:39:20.990348 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-12-08 06:39:20.990362 | controller | Monday 08 December 2025  06:39:20 +0000 (0:00:00.030)       0:00:08.065 *******
2025-12-08 06:39:20.990372 | controller | ok: [instance]
2025-12-08 06:39:21.019135 | controller |
2025-12-08 06:39:21.019157 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-12-08 06:39:21.019165 | controller | Monday 08 December 2025  06:39:20 +0000 (0:00:00.190)       0:00:08.256 *******
2025-12-08 06:39:21.019177 | controller | ok: [instance]
2025-12-08 06:39:21.046570 | controller |
2025-12-08 06:39:21.046591 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-12-08 06:39:21.046598 | controller | Monday 08 December 2025  06:39:21 +0000 (0:00:00.028)       0:00:08.285 *******
2025-12-08 06:39:21.046608 | controller | ok: [instance] => changed=false
2025-12-08 06:39:21.080579 | controller |   msg: All assertions passed
2025-12-08 06:39:21.080622 | controller |
2025-12-08 06:39:21.080633 | controller | TASK [Only listed hooks] *******************************************************
2025-12-08 06:39:21.080641 | controller | Monday 08 December 2025  06:39:21 +0000 (0:00:00.027)       0:00:08.312 *******
2025-12-08 06:39:21.080654 | controller |
2025-12-08 06:39:21.080661 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-12-08 06:39:21.080670 | controller | Monday 08 December 2025  06:39:21 +0000 (0:00:00.034)       0:00:08.346 *******
2025-12-08 06:39:21.142329 | controller | ok: [instance]
2025-12-08 06:39:21.222118 | controller |
2025-12-08 06:39:21.222150 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-12-08 06:39:21.222158 | controller | Monday 08 December 2025  06:39:21 +0000 (0:00:00.061)       0:00:08.408 *******
2025-12-08 06:39:21.222168 | controller | ok: [instance]
2025-12-08 06:39:21.336238 | controller |
2025-12-08 06:39:21.336273 | controller | TASK [run_hook : Loop on hooks for list_hooks] *********************************
2025-12-08 06:39:21.336283 | controller | Monday 08 December 2025  06:39:21 +0000 (0:00:00.079)       0:00:08.488 *******
2025-12-08 06:39:21.336296 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/run_hook/tasks/playbook.yml for instance => (item={'name': 'Run dummy-2', 'source': '/tmp/dummy-2.yml', 'type': 'playbook', 'extra_vars': {'foo': 'bar', 'file': '/tmp/dummy-env.yml'}})
2025-12-08 06:39:21.387310 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/run_hook/tasks/playbook.yml for instance => (item={'name': 'Run dummy-3', 'source': '/tmp/dummy-3.yml', 'type': 'playbook', 'extra_vars': {'foo': 'bar', 'file': '/tmp/dummy-env.yml'}})
2025-12-08 06:39:21.387339 | controller |
2025-12-08 06:39:21.387349 | controller | TASK [run_hook : Set playbook path for Run dummy-2] ****************************
2025-12-08 06:39:21.387357 | controller | Monday 08 December 2025  06:39:21 +0000 (0:00:00.113)       0:00:08.601 *******
2025-12-08 06:39:21.387368 | controller | ok: [instance]
2025-12-08 06:39:21.584122 | controller |
2025-12-08 06:39:21.584155 | controller | TASK [run_hook : Get file stat] ************************************************
2025-12-08 06:39:21.584163 | controller | Monday 08 December 2025  06:39:21 +0000 (0:00:00.051)       0:00:08.653 *******
2025-12-08 06:39:21.584175 | controller | ok: [instance]
2025-12-08 06:39:21.603888 | controller |
2025-12-08 06:39:21.603906 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-12-08 06:39:21.603913 | controller | Monday 08 December 2025  06:39:21 +0000 (0:00:00.196)       0:00:08.849 *******
2025-12-08 06:39:21.603922 | controller | skipping: [instance]
2025-12-08 06:39:21.799523 | controller |
2025-12-08 06:39:21.799565 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-12-08 06:39:21.799575 | controller | Monday 08 December 2025  06:39:21 +0000 (0:00:00.019)       0:00:08.869 *******
2025-12-08 06:39:21.799588 | controller | ok: [instance]
2025-12-08 06:39:21.799628 | controller |
2025-12-08 06:39:21.799639 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-12-08 06:39:21.799757 | controller | Monday 08 December 2025  06:39:21 +0000 (0:00:00.195)       0:00:09.065 *******
2025-12-08 06:39:21.822505 | controller | ok: [instance]
2025-12-08 06:39:22.028465 | controller |
2025-12-08 06:39:22.028497 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-12-08 06:39:22.028506 | controller | Monday 08 December 2025  06:39:21 +0000 (0:00:00.023)       0:00:09.088 *******
2025-12-08 06:39:22.028517 | controller | ok: [instance]
2025-12-08 06:39:22.222204 | controller |
2025-12-08 06:39:22.222239 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-12-08 06:39:22.222248 | controller | Monday 08 December 2025  06:39:22 +0000 (0:00:00.205)       0:00:09.294 *******
2025-12-08 06:39:22.222259 | controller | ok: [instance]
2025-12-08 06:39:24.174489 | controller |
2025-12-08 06:39:24.174523 | controller | TASK [run_hook : Run hook without retry - Run dummy-2] *************************
2025-12-08 06:39:24.174532 | controller | Monday 08 December 2025  06:39:22 +0000 (0:00:00.193)       0:00:09.488 *******
2025-12-08 06:39:24.174543 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_003_run_hook_without_retry_run.log
2025-12-08 06:39:24.174565 | controller | changed: [instance]
2025-12-08 06:39:24.174572 | controller |
2025-12-08 06:39:24.174579 | controller | TASK [run_hook : Run hook with retry - Run dummy-2] ****************************
2025-12-08 06:39:24.174599 | controller | Monday 08 December 2025  06:39:24 +0000 (0:00:01.952)       0:00:11.440 *******
2025-12-08 06:39:24.204307 | controller | skipping: [instance]
2025-12-08 06:39:24.399262 | controller |
2025-12-08 06:39:24.399301 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-12-08 06:39:24.399310 | controller | Monday 08 December 2025  06:39:24 +0000 (0:00:00.029)       0:00:11.470 *******
2025-12-08 06:39:24.399327 | controller | ok: [instance]
2025-12-08 06:39:24.424276 | controller |
2025-12-08 06:39:24.424297 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-12-08 06:39:24.424305 | controller | Monday 08 December 2025  06:39:24 +0000 (0:00:00.194)       0:00:11.665 *******
2025-12-08 06:39:24.424315 | controller | ok: [instance]
2025-12-08 06:39:24.474807 | controller |
2025-12-08 06:39:24.474826 | controller | TASK [run_hook : Set playbook path for Run dummy-3] ****************************
2025-12-08 06:39:24.474833 | controller | Monday 08 December 2025  06:39:24 +0000 (0:00:00.025)       0:00:11.690 *******
2025-12-08 06:39:24.474842 | controller | ok: [instance]
2025-12-08 06:39:24.670994 | controller |
2025-12-08 06:39:24.671028 | controller | TASK [run_hook : Get file stat] ************************************************
2025-12-08 06:39:24.671037 | controller | Monday 08 December 2025  06:39:24 +0000 (0:00:00.050)       0:00:11.741 *******
2025-12-08 06:39:24.671048 | controller | ok: [instance]
2025-12-08 06:39:24.691239 | controller |
2025-12-08 06:39:24.691265 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-12-08 06:39:24.691274 | controller | Monday 08 December 2025  06:39:24 +0000 (0:00:00.195)       0:00:11.936 *******
2025-12-08 06:39:24.691285 | controller | skipping: [instance]
2025-12-08 06:39:24.901858 | controller |
2025-12-08 06:39:24.901893 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-12-08 06:39:24.901901 | controller | Monday 08 December 2025  06:39:24 +0000 (0:00:00.020)       0:00:11.957 *******
2025-12-08 06:39:24.901912 | controller | ok: [instance]
2025-12-08 06:39:24.923488 | controller |
2025-12-08 06:39:24.923527 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-12-08 06:39:24.923535 | controller | Monday 08 December 2025  06:39:24 +0000 (0:00:00.210)       0:00:12.167 *******
2025-12-08 06:39:24.923546 | controller | ok: [instance]
2025-12-08 06:39:24.923569 | controller |
2025-12-08 06:39:24.923577 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-12-08 06:39:24.923709 | controller | Monday 08 December 2025  06:39:24 +0000 (0:00:00.021)       0:00:12.189 *******
2025-12-08 06:39:25.119494 | controller | ok: [instance]
2025-12-08 06:39:25.119549 | controller |
2025-12-08 06:39:25.119558 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-12-08 06:39:25.119574 | controller | Monday 08 December 2025  06:39:25 +0000 (0:00:00.195)       0:00:12.385 *******
2025-12-08 06:39:25.305520 | controller | ok: [instance]
2025-12-08 06:39:27.246481 | controller |
2025-12-08 06:39:27.246513 | controller | TASK [run_hook : Run hook without retry - Run dummy-3] *************************
2025-12-08 06:39:27.246521 | controller | Monday 08 December 2025  06:39:25 +0000 (0:00:00.185)       0:00:12.571 *******
2025-12-08 06:39:27.246531 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_004_run_hook_without_retry_run.log
2025-12-08 06:39:27.246998 | controller | changed: [instance]
2025-12-08 06:39:27.282855 | controller |
2025-12-08 06:39:27.282889 | controller | TASK [run_hook : Run hook with retry - Run dummy-3] ****************************
2025-12-08 06:39:27.282897 | controller | Monday 08 December 2025  06:39:27 +0000 (0:00:01.941)       0:00:14.512 *******
2025-12-08 06:39:27.282908 | controller | skipping: [instance]
2025-12-08 06:39:27.467214 | controller |
2025-12-08 06:39:27.467246 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-12-08 06:39:27.467255 | controller | Monday 08 December 2025  06:39:27 +0000 (0:00:00.035)       0:00:14.548 *******
2025-12-08 06:39:27.467265 | controller | ok: [instance]
2025-12-08 06:39:27.495344 | controller |
2025-12-08 06:39:27.495372 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-12-08 06:39:27.495381 | controller | Monday 08 December 2025  06:39:27 +0000 (0:00:00.184)       0:00:14.733 *******
2025-12-08 06:39:27.495393 | controller | ok: [instance]
2025-12-08 06:39:27.521532 | controller |
2025-12-08 06:39:27.521559 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-12-08 06:39:27.521568 | controller | Monday 08 December 2025  06:39:27 +0000 (0:00:00.028)       0:00:14.761 *******
2025-12-08 06:39:27.521579 | controller | ok: [instance] => changed=false
2025-12-08 06:39:27.557131 | controller |   msg: All assertions passed
2025-12-08 06:39:27.557150 | controller |
2025-12-08 06:39:27.557157 | controller | TASK [Only filtered hooks] *****************************************************
2025-12-08 06:39:27.557163 | controller | Monday 08 December 2025  06:39:27 +0000 (0:00:00.026)       0:00:14.787 *******
2025-12-08 06:39:27.557173 | controller |
2025-12-08 06:39:27.616383 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-12-08 06:39:27.616428 | controller | Monday 08 December 2025  06:39:27 +0000 (0:00:00.035)       0:00:14.823 *******
2025-12-08 06:39:27.616443 | controller | ok: [instance]
2025-12-08 06:39:27.695697 | controller |
2025-12-08 06:39:27.695732 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-12-08 06:39:27.695742 | controller | Monday 08 December 2025  06:39:27 +0000 (0:00:00.059)       0:00:14.882 *******
2025-12-08 06:39:27.695754 | controller | ok: [instance]
2025-12-08 06:39:27.695945 | controller |
2025-12-08 06:39:27.696137 | controller | TASK [run_hook : Loop on hooks for filtered_hooks] *****************************
2025-12-08 06:39:27.696311 | controller | Monday 08 December 2025  06:39:27 +0000 (0:00:00.079)       0:00:14.962 *******
2025-12-08 06:39:27.800538 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/run_hook/tasks/playbook.yml for instance => (item={'source': '/tmp/dummy-4.yml', 'type': 'playbook', 'extra_vars': {'foo': 'bar', 'file': '/tmp/dummy-env.yml'}, 'name': '01 my hook'})
2025-12-08 06:39:27.800952 | controller |
2025-12-08 06:39:27.801096 | controller | TASK [run_hook : Set playbook path for 01 my hook] *****************************
2025-12-08 06:39:27.801232 | controller | Monday 08 December 2025  06:39:27 +0000 (0:00:00.104)       0:00:15.066 *******
2025-12-08 06:39:27.849117 | controller | ok: [instance]
2025-12-08 06:39:27.849273 | controller |
2025-12-08 06:39:27.849429 | controller | TASK [run_hook : Get file stat] ************************************************
2025-12-08 06:39:27.849587 | controller | Monday 08 December 2025  06:39:27 +0000 (0:00:00.048)       0:00:15.115 *******
2025-12-08 06:39:28.043498 | controller | ok: [instance]
2025-12-08 06:39:28.043730 | controller |
2025-12-08 06:39:28.043744 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-12-08 06:39:28.061908 | controller | Monday 08 December 2025  06:39:28 +0000 (0:00:00.194)       0:00:15.309 *******
2025-12-08 06:39:28.061932 | controller | skipping: [instance]
2025-12-08 06:39:28.249237 | controller |
2025-12-08 06:39:28.249270 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-12-08 06:39:28.249279 | controller | Monday 08 December 2025  06:39:28 +0000 (0:00:00.018)       0:00:15.328 *******
2025-12-08 06:39:28.249289 | controller | ok: [instance]
2025-12-08 06:39:28.270297 | controller |
2025-12-08 06:39:28.270320 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-12-08 06:39:28.270329 | controller | Monday 08 December 2025  06:39:28 +0000 (0:00:00.187)       0:00:15.515 *******
2025-12-08 06:39:28.270340 | controller | ok: [instance]
2025-12-08 06:39:28.460876 | controller |
2025-12-08 06:39:28.460908 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-12-08 06:39:28.460916 | controller | Monday 08 December 2025  06:39:28 +0000 (0:00:00.021)       0:00:15.536 *******
2025-12-08 06:39:28.460927 | controller | ok: [instance]
2025-12-08 06:39:28.645955 | controller |
2025-12-08 06:39:28.645986 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-12-08 06:39:28.645994 | controller | Monday 08 December 2025  06:39:28 +0000 (0:00:00.190)       0:00:15.726 *******
2025-12-08 06:39:28.646004 | controller | ok: [instance]
2025-12-08 06:39:30.553838 | controller |
2025-12-08 06:39:30.553884 | controller | TASK [run_hook : Run hook without retry - 01 my hook] **************************
2025-12-08 06:39:30.553893 | controller | Monday 08 December 2025  06:39:28 +0000 (0:00:00.185)       0:00:15.912 *******
2025-12-08 06:39:30.553904 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_005_run_hook_without_retry_01_my.log
2025-12-08 06:39:30.583018 | controller | changed: [instance]
2025-12-08 06:39:30.583039 | controller |
2025-12-08 06:39:30.583048 | controller | TASK [run_hook : Run hook with retry - 01 my hook] *****************************
2025-12-08 06:39:30.583054 | controller | Monday 08 December 2025  06:39:30 +0000 (0:00:01.907)       0:00:17.819 *******
2025-12-08 06:39:30.583063 | controller | skipping: [instance]
2025-12-08 06:39:30.767233 | controller |
2025-12-08 06:39:30.767263 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-12-08 06:39:30.767272 | controller | Monday 08 December 2025  06:39:30 +0000 (0:00:00.029)       0:00:17.849 *******
2025-12-08 06:39:30.767281 | controller | ok: [instance]
2025-12-08 06:39:30.792799 | controller |
2025-12-08 06:39:30.792820 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-12-08 06:39:30.792829 | controller | Monday 08 December 2025  06:39:30 +0000 (0:00:00.184)       0:00:18.033 *******
2025-12-08 06:39:30.792855 | controller | ok: [instance]
2025-12-08 06:39:30.816470 | controller |
2025-12-08 06:39:30.816495 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-12-08 06:39:30.816503 | controller | Monday 08 December 2025  06:39:30 +0000 (0:00:00.025)       0:00:18.059 *******
2025-12-08 06:39:30.816513 | controller | ok: [instance] => changed=false
2025-12-08 06:39:30.816529 | controller |   msg: All assertions passed
2025-12-08 06:39:30.816536 | controller |
2025-12-08 06:39:30.816543 | controller | TASK [Direct hooks] ************************************************************
2025-12-08 06:39:30.816613 | controller | Monday 08 December 2025  06:39:30 +0000 (0:00:00.023)       0:00:18.082 *******
2025-12-08 06:39:30.854512 | controller |
2025-12-08 06:39:30.911822 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-12-08 06:39:30.911872 | controller | Monday 08 December 2025  06:39:30 +0000 (0:00:00.037)       0:00:18.120 *******
2025-12-08 06:39:30.911885 | controller | ok: [instance]
2025-12-08 06:39:30.987495 | controller |
2025-12-08 06:39:30.987529 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-12-08 06:39:30.987539 | controller | Monday 08 December 2025  06:39:30 +0000 (0:00:00.057)       0:00:18.177 *******
2025-12-08 06:39:30.987551 | controller | ok: [instance]
2025-12-08 06:39:30.987582 | controller |
2025-12-08 06:39:30.987736 | controller | TASK [run_hook : Loop on hooks for no_hook] ************************************
2025-12-08 06:39:31.082528 | controller | Monday 08 December 2025  06:39:30 +0000 (0:00:00.075)       0:00:18.253 *******
2025-12-08 06:39:31.082561 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/run_hook/tasks/playbook.yml for instance => (item={'name': 'Dummy-5', 'source': '/tmp/dummy-5.yml', 'type': 'playbook', 'extra_vars': {'foo': 'bar', 'file': '/tmp/dummy-env.yml'}})
2025-12-08 06:39:31.130905 | controller |
2025-12-08 06:39:31.130927 | controller | TASK [run_hook : Set playbook path for Dummy-5] ********************************
2025-12-08 06:39:31.130934 | controller | Monday 08 December 2025  06:39:31 +0000 (0:00:00.094)       0:00:18.348 *******
2025-12-08 06:39:31.130944 | controller | ok: [instance]
2025-12-08 06:39:31.318012 | controller |
2025-12-08 06:39:31.318043 | controller | TASK [run_hook : Get file stat] ************************************************
2025-12-08 06:39:31.318052 | controller | Monday 08 December 2025  06:39:31 +0000 (0:00:00.048)       0:00:18.397 *******
2025-12-08 06:39:31.318062 | controller | ok: [instance]
2025-12-08 06:39:31.335072 | controller |
2025-12-08 06:39:31.335097 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-12-08 06:39:31.335107 | controller | Monday 08 December 2025  06:39:31 +0000 (0:00:00.187)       0:00:18.584 *******
2025-12-08 06:39:31.335118 | controller | skipping: [instance]
2025-12-08 06:39:31.521328 | controller |
2025-12-08 06:39:31.521359 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-12-08 06:39:31.521367 | controller | Monday 08 December 2025  06:39:31 +0000 (0:00:00.017)       0:00:18.601 *******
2025-12-08 06:39:31.521377 | controller | ok: [instance]
2025-12-08 06:39:31.541373 | controller |
2025-12-08 06:39:31.541398 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-12-08 06:39:31.541427 | controller | Monday 08 December 2025  06:39:31 +0000 (0:00:00.186)       0:00:18.787 *******
2025-12-08 06:39:31.541442 | controller | ok: [instance]
2025-12-08 06:39:31.736215 | controller |
2025-12-08 06:39:31.736245 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-12-08 06:39:31.736253 | controller | Monday 08 December 2025  06:39:31 +0000 (0:00:00.020)       0:00:18.807 *******
2025-12-08 06:39:31.736263 | controller | ok: [instance]
2025-12-08 06:39:31.922482 | controller |
2025-12-08 06:39:31.922513 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-12-08 06:39:31.922522 | controller | Monday 08 December 2025  06:39:31 +0000 (0:00:00.194)       0:00:19.002 *******
2025-12-08 06:39:31.922532 | controller | ok: [instance]
2025-12-08 06:39:33.836368 | controller |
2025-12-08 06:39:33.836399 | controller | TASK [run_hook : Run hook without retry - Dummy-5] *****************************
2025-12-08 06:39:33.836480 | controller | Monday 08 December 2025  06:39:31 +0000 (0:00:00.186)       0:00:19.188 *******
2025-12-08 06:39:33.836496 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_006_run_hook_without_retry_dummy.log
2025-12-08 06:39:33.866143 | controller | changed: [instance]
2025-12-08 06:39:33.866164 | controller |
2025-12-08 06:39:33.866171 | controller | TASK [run_hook : Run hook with retry - Dummy-5] ********************************
2025-12-08 06:39:33.866178 | controller | Monday 08 December 2025  06:39:33 +0000 (0:00:01.913)       0:00:21.102 *******
2025-12-08 06:39:33.866187 | controller | skipping: [instance]
2025-12-08 06:39:34.055373 | controller |
2025-12-08 06:39:34.055402 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-12-08 06:39:34.055430 | controller | Monday 08 December 2025  06:39:33 +0000 (0:00:00.029)       0:00:21.132 *******
2025-12-08 06:39:34.055441 | controller | ok: [instance]
2025-12-08 06:39:34.100223 | controller |
2025-12-08 06:39:34.100255 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-12-08 06:39:34.100264 | controller | Monday 08 December 2025  06:39:34 +0000 (0:00:00.189)       0:00:21.321 *******
2025-12-08 06:39:34.100275 | controller | ok: [instance]
2025-12-08 06:39:34.125699 | controller |
2025-12-08 06:39:34.125719 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-12-08 06:39:34.125726 | controller | Monday 08 December 2025  06:39:34 +0000 (0:00:00.044)       0:00:21.366 *******
2025-12-08 06:39:34.125736 | controller | ok: [instance] => changed=false
2025-12-08 06:39:34.164032 | controller |   msg: All assertions passed
2025-12-08 06:39:34.164058 | controller |
2025-12-08 06:39:34.164067 | controller | TASK [Direct hooks as param] ***************************************************
2025-12-08 06:39:34.164081 | controller | Monday 08 December 2025  06:39:34 +0000 (0:00:00.025)       0:00:21.391 *******
2025-12-08 06:39:34.164101 | controller |
2025-12-08 06:39:34.224072 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-12-08 06:39:34.224097 | controller | Monday 08 December 2025  06:39:34 +0000 (0:00:00.038)       0:00:21.430 *******
2025-12-08 06:39:34.224108 | controller | ok: [instance]
2025-12-08 06:39:34.299675 | controller |
2025-12-08 06:39:34.299710 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-12-08 06:39:34.299720 | controller | Monday 08 December 2025  06:39:34 +0000 (0:00:00.059)       0:00:21.490 *******
2025-12-08 06:39:34.299732 | controller | ok: [instance]
2025-12-08 06:39:34.299916 | controller |
2025-12-08 06:39:34.300063 | controller | TASK [run_hook : Loop on hooks for no_hook] ************************************
2025-12-08 06:39:34.300206 | controller | Monday 08 December 2025  06:39:34 +0000 (0:00:00.075)       0:00:21.566 *******
2025-12-08 06:39:34.396242 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/run_hook/tasks/playbook.yml for instance => (item={'name': 'Hook as param', 'source': '/tmp/dummy-6.yml', 'type': 'playbook', 'extra_vars': {'foo': 'bar', 'file': '/tmp/dummy-env.yml'}})
2025-12-08 06:39:34.396469 | controller |
2025-12-08 06:39:34.396649 | controller | TASK [run_hook : Set playbook path for Hook as param] **************************
2025-12-08 06:39:34.396818 | controller | Monday 08 December 2025  06:39:34 +0000 (0:00:00.096)       0:00:21.662 *******
2025-12-08 06:39:34.444859 | controller | ok: [instance]
2025-12-08 06:39:34.445021 | controller |
2025-12-08 06:39:34.445163 | controller | TASK [run_hook : Get file stat] ************************************************
2025-12-08 06:39:34.445299 | controller | Monday 08 December 2025  06:39:34 +0000 (0:00:00.048)       0:00:21.711 *******
2025-12-08 06:39:34.634397 | controller | ok: [instance]
2025-12-08 06:39:34.652359 | controller |
2025-12-08 06:39:34.652383 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-12-08 06:39:34.652391 | controller | Monday 08 December 2025  06:39:34 +0000 (0:00:00.189)       0:00:21.900 *******
2025-12-08 06:39:34.652401 | controller | skipping: [instance]
2025-12-08 06:39:34.840066 | controller |
2025-12-08 06:39:34.840099 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-12-08 06:39:34.840107 | controller | Monday 08 December 2025  06:39:34 +0000 (0:00:00.018)       0:00:21.918 *******
2025-12-08 06:39:34.840118 | controller | ok: [instance]
2025-12-08 06:39:34.860988 | controller |
2025-12-08 06:39:34.861007 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-12-08 06:39:34.861015 | controller | Monday 08 December 2025  06:39:34 +0000 (0:00:00.187)       0:00:22.106 *******
2025-12-08 06:39:34.861024 | controller | ok: [instance]
2025-12-08 06:39:35.053983 | controller |
2025-12-08 06:39:35.054013 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-12-08 06:39:35.054022 | controller | Monday 08 December 2025  06:39:34 +0000 (0:00:00.021)       0:00:22.127 *******
2025-12-08 06:39:35.054033 | controller | ok: [instance]
2025-12-08 06:39:35.241015 | controller |
2025-12-08 06:39:35.241046 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-12-08 06:39:35.241055 | controller | Monday 08 December 2025  06:39:35 +0000 (0:00:00.192)       0:00:22.320 *******
2025-12-08 06:39:35.241064 | controller | ok: [instance]
2025-12-08 06:39:37.167377 | controller |
2025-12-08 06:39:37.167430 | controller | TASK [run_hook : Run hook without retry - Hook as param] ***********************
2025-12-08 06:39:37.167442 | controller | Monday 08 December 2025  06:39:35 +0000 (0:00:00.187)       0:00:22.507 *******
2025-12-08 06:39:37.167454 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_007_run_hook_without_retry_hook.log
2025-12-08 06:39:37.198451 | controller | changed: [instance]
2025-12-08 06:39:37.198477 | controller |
2025-12-08 06:39:37.198486 | controller | TASK [run_hook : Run hook with retry - Hook as param] **************************
2025-12-08 06:39:37.198493 | controller | Monday 08 December 2025  06:39:37 +0000 (0:00:01.926)       0:00:24.433 *******
2025-12-08 06:39:37.198503 | controller | skipping: [instance]
2025-12-08 06:39:37.385479 | controller |
2025-12-08 06:39:37.385509 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-12-08 06:39:37.385524 | controller | Monday 08 December 2025  06:39:37 +0000 (0:00:00.031)       0:00:24.464 *******
2025-12-08 06:39:37.385538 | controller | ok: [instance]
2025-12-08 06:39:37.411498 | controller |
2025-12-08 06:39:37.411530 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-12-08 06:39:37.411539 | controller | Monday 08 December 2025  06:39:37 +0000 (0:00:00.186)       0:00:24.651 *******
2025-12-08 06:39:37.411548 | controller | ok: [instance]
2025-12-08 06:39:37.411571 | controller |
2025-12-08 06:39:37.411579 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-12-08 06:39:37.411736 | controller | Monday 08 December 2025  06:39:37 +0000 (0:00:00.026)       0:00:24.677 *******
2025-12-08 06:39:37.436445 | controller | ok: [instance] => changed=false
2025-12-08 06:39:37.472993 | controller |   msg: All assertions passed
2025-12-08 06:39:37.473024 | controller |
2025-12-08 06:39:37.473032 | controller | TASK [Ensure we have the test_list variable now] *******************************
2025-12-08 06:39:37.473039 | controller | Monday 08 December 2025  06:39:37 +0000 (0:00:00.024)       0:00:24.702 *******
2025-12-08 06:39:37.473048 | controller | ok: [instance] => changed=false
2025-12-08 06:39:37.498963 | controller |   msg: All assertions passed
2025-12-08 06:39:37.498986 | controller |
2025-12-08 06:39:37.498993 | controller | TASK [Run hook with retry] *****************************************************
2025-12-08 06:39:37.498999 | controller | Monday 08 December 2025  06:39:37 +0000 (0:00:00.036)       0:00:24.738 *******
2025-12-08 06:39:37.499008 | controller |
2025-12-08 06:39:37.556505 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-12-08 06:39:37.556536 | controller | Monday 08 December 2025  06:39:37 +0000 (0:00:00.026)       0:00:24.765 *******
2025-12-08 06:39:37.556546 | controller | ok: [instance]
2025-12-08 06:39:37.632235 | controller |
2025-12-08 06:39:37.632264 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-12-08 06:39:37.632271 | controller | Monday 08 December 2025  06:39:37 +0000 (0:00:00.057)       0:00:24.822 *******
2025-12-08 06:39:37.632281 | controller | ok: [instance]
2025-12-08 06:39:37.632462 | controller |
2025-12-08 06:39:37.632613 | controller | TASK [run_hook : Loop on hooks for retry_hook] *********************************
2025-12-08 06:39:37.632759 | controller | Monday 08 December 2025  06:39:37 +0000 (0:00:00.076)       0:00:24.898 *******
2025-12-08 06:39:37.729310 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/run_hook/tasks/playbook.yml for instance => (item={'name': 'Run hook with retry', 'source': '/tmp/dummy-retry.yml', 'type': 'playbook', 'retry_hook': True})
2025-12-08 06:39:37.729540 | controller |
2025-12-08 06:39:37.729696 | controller | TASK [run_hook : Set playbook path for Run hook with retry] ********************
2025-12-08 06:39:37.729859 | controller | Monday 08 December 2025  06:39:37 +0000 (0:00:00.096)       0:00:24.995 *******
2025-12-08 06:39:37.777327 | controller | ok: [instance]
2025-12-08 06:39:37.777520 | controller |
2025-12-08 06:39:37.777671 | controller | TASK [run_hook : Get file stat] ************************************************
2025-12-08 06:39:37.777809 | controller | Monday 08 December 2025  06:39:37 +0000 (0:00:00.048)       0:00:25.043 *******
2025-12-08 06:39:37.969860 | controller | ok: [instance]
2025-12-08 06:39:37.988945 | controller |
2025-12-08 06:39:37.988971 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-12-08 06:39:37.988980 | controller | Monday 08 December 2025  06:39:37 +0000 (0:00:00.192)       0:00:25.235 *******
2025-12-08 06:39:37.988990 | controller | skipping: [instance]
2025-12-08 06:39:38.176231 | controller |
2025-12-08 06:39:38.176263 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-12-08 06:39:38.176272 | controller | Monday 08 December 2025  06:39:37 +0000 (0:00:00.019)       0:00:25.255 *******
2025-12-08 06:39:38.176282 | controller | ok: [instance]
2025-12-08 06:39:38.196299 | controller |
2025-12-08 06:39:38.196322 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-12-08 06:39:38.196329 | controller | Monday 08 December 2025  06:39:38 +0000 (0:00:00.187)       0:00:25.442 *******
2025-12-08 06:39:38.196339 | controller | ok: [instance]
2025-12-08 06:39:38.383850 | controller |
2025-12-08 06:39:38.383881 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-12-08 06:39:38.383895 | controller | Monday 08 December 2025  06:39:38 +0000 (0:00:00.020)       0:00:25.462 *******
2025-12-08 06:39:38.383906 | controller | ok: [instance]
2025-12-08 06:39:38.568501 | controller |
2025-12-08 06:39:38.568529 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-12-08 06:39:38.568537 | controller | Monday 08 December 2025  06:39:38 +0000 (0:00:00.187)       0:00:25.649 *******
2025-12-08 06:39:38.568547 | controller | ok: [instance]
2025-12-08 06:39:40.419684 | controller |
2025-12-08 06:39:40.419715 | controller | TASK [run_hook : Run hook without retry - Run hook with retry] *****************
2025-12-08 06:39:40.419724 | controller | Monday 08 December 2025  06:39:38 +0000 (0:00:00.184)       0:00:25.834 *******
2025-12-08 06:39:40.419734 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_008_run_hook_without_retry_run.log
2025-12-08 06:39:40.448091 | controller | changed: [instance]
2025-12-08 06:39:40.448110 | controller |
2025-12-08 06:39:40.448118 | controller | TASK [run_hook : Run hook with retry - Run hook with retry] ********************
2025-12-08 06:39:40.448124 | controller | Monday 08 December 2025  06:39:40 +0000 (0:00:01.850)       0:00:27.685 *******
2025-12-08 06:39:40.448133 | controller | skipping: [instance]
2025-12-08 06:39:40.614824 | controller |
2025-12-08 06:39:40.614856 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-12-08 06:39:40.614865 | controller | Monday 08 December 2025  06:39:40 +0000 (0:00:00.028)       0:00:27.714 *******
2025-12-08 06:39:40.614874 | controller | ok: [instance]
2025-12-08 06:39:40.635107 | controller |
2025-12-08 06:39:40.635128 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-12-08 06:39:40.635142 | controller | Monday 08 December 2025  06:39:40 +0000 (0:00:00.166)       0:00:27.881 *******
2025-12-08 06:39:40.635151 | controller | skipping: [instance]
2025-12-08 06:39:40.810490 | controller |
2025-12-08 06:39:40.810526 | controller | TASK [Check if fake file exists for retry playbook] ****************************
2025-12-08 06:39:40.810535 | controller | Monday 08 December 2025  06:39:40 +0000 (0:00:00.020)       0:00:27.901 *******
2025-12-08 06:39:40.810545 | controller | ok: [instance]
2025-12-08 06:39:40.810569 | controller |
2025-12-08 06:39:40.810577 | controller | TASK [Ensure file exists and was created on retry] *****************************
2025-12-08 06:39:40.810715 | controller | Monday 08 December 2025  06:39:40 +0000 (0:00:00.175)       0:00:28.076 *******
2025-12-08 06:39:40.829155 | controller | ok: [instance] => changed=false
2025-12-08 06:39:41.013516 | controller |   msg: All assertions passed
2025-12-08 06:39:41.013546 | controller |
2025-12-08 06:39:41.013554 | controller | TASK [Remove generated file] ***************************************************
2025-12-08 06:39:41.013561 | controller | Monday 08 December 2025  06:39:40 +0000 (0:00:00.018)       0:00:28.095 *******
2025-12-08 06:39:41.013570 | controller | changed: [instance]
2025-12-08 06:39:41.013592 | controller |
2025-12-08 06:39:41.013598 | controller | PLAY RECAP *********************************************************************
2025-12-08 06:39:41.013605 | controller | instance                   : ok=112  changed=10   unreachable=0    failed=0    skipped=22   rescued=0    ignored=0
2025-12-08 06:39:41.014449 | controller |
2025-12-08 06:39:41.015443 | controller | Monday 08 December 2025  06:39:41 +0000 (0:00:00.184)       0:00:28.279 *******
2025-12-08 06:39:41.015456 | controller | ===============================================================================
2025-12-08 06:39:41.015462 | controller | run_hook : Run hook without retry - 03 single hook ---------------------- 2.01s
2025-12-08 06:39:41.015467 | controller | run_hook : Run hook without retry - Run dummy-2 ------------------------- 1.95s
2025-12-08 06:39:41.015473 | controller | run_hook : Run hook without retry - Run dummy-3 ------------------------- 1.94s
2025-12-08 06:39:41.015478 | controller | run_hook : Run hook without retry - Hook as param ----------------------- 1.93s
2025-12-08 06:39:41.015483 | controller | run_hook : Run hook without retry - Dummy-5 ----------------------------- 1.91s
2025-12-08 06:39:41.015489 | controller | run_hook : Run hook without retry - 01 my hook -------------------------- 1.91s
2025-12-08 06:39:41.015497 | controller | run_hook : Run hook without retry - Run hook with retry ----------------- 1.85s
2025-12-08 06:39:41.015821 | controller | Gathering Facts --------------------------------------------------------- 0.82s
2025-12-08 06:39:41.015852 | controller | run_hook : Run hook without retry - 01 Default noop hook ---------------- 0.61s
2025-12-08 06:39:41.015861 | controller | run_hook : Run hook without retry - 02 Re-run noop ---------------------- 0.61s
2025-12-08 06:39:41.015866 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.30s
2025-12-08 06:39:41.015872 | controller | run_hook : Get file stat ------------------------------------------------ 0.29s
2025-12-08 06:39:41.015877 | controller | run_hook : Get parameters files ----------------------------------------- 0.29s
2025-12-08 06:39:41.015882 | controller | run_hook : Get parameters files ----------------------------------------- 0.21s
2025-12-08 06:39:41.015888 | controller | run_hook : Ensure artifacts directory exists ---------------------------- 0.21s
2025-12-08 06:39:41.015893 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.21s
2025-12-08 06:39:41.015901 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.20s
2025-12-08 06:39:41.071535 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.20s
2025-12-08 06:39:41.071568 | controller | run_hook : Get file stat ------------------------------------------------ 0.20s
2025-12-08 06:39:41.071576 | controller | run_hook : Get file stat ------------------------------------------------ 0.20s
2025-12-08 06:39:41.071587 | controller | INFO     Running default > cleanup
2025-12-08 06:39:41.072063 | controller | WARNING  Skipping, cleanup playbook not configured.
2025-12-08 06:39:41.072597 | controller | INFO     Writing /tmp/report.html report.
2025-12-08 06:39:41.441558 | controller | changed
2025-12-08 06:39:41.471785 | 
2025-12-08 06:39:41.471864 | PLAY RECAP
2025-12-08 06:39:41.471952 | controller | ok: 4 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-12-08 06:39:41.471988 | 
2025-12-08 06:39:41.538006 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-12-08 06:39:41.539101 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-12-08 06:39:42.070045 | 
2025-12-08 06:39:42.070174 | PLAY [Run ci/playbooks/collect-logs.yml]
2025-12-08 06:39:42.090630 | 
2025-12-08 06:39:42.090704 | TASK [Filter out host if needed]
2025-12-08 06:39:42.099097 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2025-12-08 06:39:42.103580 | 
2025-12-08 06:39:42.103647 | TASK [Ensure file is present]
2025-12-08 06:39:42.435788 | controller | ok
2025-12-08 06:39:42.442529 | 
2025-12-08 06:39:42.442615 | TASK [Manage molecule report file]
2025-12-08 06:39:42.968307 | controller | changed
2025-12-08 06:39:42.973772 | 
2025-12-08 06:39:42.973839 | TASK [Check if we get ci-framework-data basedir]
2025-12-08 06:39:43.164594 | controller | ok
2025-12-08 06:39:43.169569 | 
2025-12-08 06:39:43.169634 | TASK [Create ci-framework-data log directory for zuul]
2025-12-08 06:39:43.491851 | controller | changed
2025-12-08 06:39:43.496972 | 
2025-12-08 06:39:43.497040 | TASK [Copy ci-framework interesting files]
2025-12-08 06:39:43.709090 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory
2025-12-08 06:39:44.023344 | controller | changed
2025-12-08 06:39:44.028894 | 
2025-12-08 06:39:44.028997 | TASK [Get SELinux listing]
2025-12-08 06:39:44.555563 | controller | changed
2025-12-08 06:39:44.561802 | 
2025-12-08 06:39:44.561892 | TASK [Generate log index]
2025-12-08 06:39:45.188538 | controller | changed
2025-12-08 06:39:45.193346 | 
2025-12-08 06:39:45.193411 | TASK [Get some env related data]
2025-12-08 06:39:45.732083 | controller | /home/zuul/.local/bin/ansible
2025-12-08 06:39:46.719992 | controller | changed
2025-12-08 06:39:46.725130 | 
2025-12-08 06:39:46.725192 | TASK [Generate list of logs to collect in home directory]
2025-12-08 06:39:47.016325 | controller | ok: All paths examined
2025-12-08 06:39:47.021416 | 
2025-12-08 06:39:47.021479 | LOOP [Copy logs from home directory]
2025-12-08 06:39:47.329411 | controller | changed:
2025-12-08 06:39:47.329516 | controller | {
2025-12-08 06:39:47.329544 | controller |   "atime": 1765175928.890101,
2025-12-08 06:39:47.329563 | controller |   "ctime": 1765175944.4182565,
2025-12-08 06:39:47.329580 | controller |   "dev": 64513,
2025-12-08 06:39:47.329596 | controller |   "gid": 1000,
2025-12-08 06:39:47.329611 | controller |   "gr_name": "zuul",
2025-12-08 06:39:47.329626 | controller |   "inode": 4386657,
2025-12-08 06:39:47.329641 | controller |   "isblk": false,
2025-12-08 06:39:47.329656 | controller |   "ischr": false,
2025-12-08 06:39:47.329672 | controller |   "isdir": false,
2025-12-08 06:39:47.329687 | controller |   "isfifo": false,
2025-12-08 06:39:47.329701 | controller |   "isgid": false,
2025-12-08 06:39:47.329728 | controller |   "islnk": false,
2025-12-08 06:39:47.329744 | controller |   "isreg": true,
2025-12-08 06:39:47.329759 | controller |   "issock": false,
2025-12-08 06:39:47.329773 | controller |   "isuid": false,
2025-12-08 06:39:47.329787 | controller |   "mode": "0644",
2025-12-08 06:39:47.329800 | controller |   "mtime": 1765175944.4182565,
2025-12-08 06:39:47.329814 | controller |   "nlink": 1,
2025-12-08 06:39:47.329827 | controller |   "path": "/home/zuul/ansible.log",
2025-12-08 06:39:47.329842 | controller |   "pw_name": "zuul",
2025-12-08 06:39:47.329857 | controller |   "rgrp": true,
2025-12-08 06:39:47.329871 | controller |   "roth": true,
2025-12-08 06:39:47.329885 | controller |   "rusr": true,
2025-12-08 06:39:47.329899 | controller |   "size": 6749,
2025-12-08 06:39:47.329932 | controller |   "uid": 1000,
2025-12-08 06:39:47.329951 | controller |   "wgrp": false,
2025-12-08 06:39:47.329965 | controller |   "woth": false,
2025-12-08 06:39:47.329981 | controller |   "wusr": true,
2025-12-08 06:39:47.329996 | controller |   "xgrp": false,
2025-12-08 06:39:47.330010 | controller |   "xoth": false,
2025-12-08 06:39:47.330023 | controller |   "xusr": false
2025-12-08 06:39:47.330037 | controller | }
2025-12-08 06:39:47.343976 | 
2025-12-08 06:39:47.344086 | TASK [Copy crio stats log file]
2025-12-08 06:39:47.357680 | controller | skipping: Conditional result was False
2025-12-08 06:39:47.365018 | 
2025-12-08 06:39:47.365129 | TASK [Get SELinux related data]
2025-12-08 06:39:47.580057 | controller | <no matches>
2025-12-08 06:39:47.891986 | controller | ERROR
2025-12-08 06:39:47.892170 | controller | {
2025-12-08 06:39:47.892202 | controller |   "delta": "0:00:00.008896",
2025-12-08 06:39:47.892226 | controller |   "end": "2025-12-08 06:39:47.580955",
2025-12-08 06:39:47.892245 | controller |   "msg": "non-zero return code",
2025-12-08 06:39:47.892263 | controller |   "rc": 1,
2025-12-08 06:39:47.892281 | controller |   "start": "2025-12-08 06:39:47.572059"
2025-12-08 06:39:47.892298 | controller | }
2025-12-08 06:39:47.892323 | controller | ERROR: Ignoring Errors
2025-12-08 06:39:47.897592 | 
2025-12-08 06:39:47.897657 | TASK [Create system configuration directory]
2025-12-08 06:39:48.088684 | controller | changed
2025-12-08 06:39:48.093775 | 
2025-12-08 06:39:48.093845 | TASK [Get some of the system configurations]
2025-12-08 06:39:48.621152 | controller | changed
2025-12-08 06:39:48.626490 | 
2025-12-08 06:39:48.626554 | TASK [Copy generated documentation if available]
2025-12-08 06:39:48.639834 | controller | skipping: Conditional result was False
2025-12-08 06:39:48.645522 | 
2025-12-08 06:39:48.645587 | TASK [Copy generated AsciiDoc documentation if available]
2025-12-08 06:39:48.658866 | controller | skipping: Conditional result was False
2025-12-08 06:39:48.665021 | 
2025-12-08 06:39:48.665086 | TASK [Compress logs bigger than 2MB]
2025-12-08 06:39:49.192143 | controller | changed
2025-12-08 06:39:49.197636 | 
2025-12-08 06:39:49.197698 | TASK [Copy files from workspace on node]
2025-12-08 06:39:49.215828 | controller | ok
2025-12-08 06:39:49.237827 | 
2025-12-08 06:39:49.237894 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-08 06:39:49.251313 | controller | skipping: Conditional result was False
2025-12-08 06:39:49.257099 | 
2025-12-08 06:39:49.257169 | TASK [fetch-output : Set log path for single node]
2025-12-08 06:39:49.285413 | controller | ok
2025-12-08 06:39:49.291320 | 
2025-12-08 06:39:49.291385 | LOOP [fetch-output : Ensure local output dirs]
2025-12-08 06:39:49.485088 | controller -> localhost | ok: "/var/lib/zuul/builds/c8a8de4fe48c4950991f041df900c43e/work/logs"
2025-12-08 06:39:49.485309 | controller -> localhost | changed: All items complete
2025-12-08 06:39:49.485341 | 
2025-12-08 06:39:49.666792 | controller -> localhost | changed: "/var/lib/zuul/builds/c8a8de4fe48c4950991f041df900c43e/work/artifacts"
2025-12-08 06:39:49.844086 | controller -> localhost | changed: "/var/lib/zuul/builds/c8a8de4fe48c4950991f041df900c43e/work/docs"
2025-12-08 06:39:49.853690 | 
2025-12-08 06:39:49.853783 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-08 06:39:50.382469 | controller | changed:
2025-12-08 06:39:50.382648 | controller | .d..t...... ./
2025-12-08 06:39:50.382678 | controller | >f+++++++++ README.html
2025-12-08 06:39:50.382712 | controller | >f+++++++++ ansible-execution.log
2025-12-08 06:39:50.382737 | controller | >f+++++++++ ansible.log
2025-12-08 06:39:50.382757 | controller | >f+++++++++ dmesg.log
2025-12-08 06:39:50.382774 | controller | >f+++++++++ installed-pkgs.log
2025-12-08 06:39:50.382791 | controller | >f+++++++++ python.log
2025-12-08 06:39:50.382808 | controller | >f+++++++++ registries.conf
2025-12-08 06:39:50.382824 | controller | >f+++++++++ report.html
2025-12-08 06:39:50.382842 | controller | >f+++++++++ selinux-denials.log
2025-12-08 06:39:50.382858 | controller | >f+++++++++ selinux-listing.log
2025-12-08 06:39:50.382874 | controller | cd+++++++++ ci-framework-data/
2025-12-08 06:39:50.382890 | controller | cd+++++++++ ci-framework-data/artifacts/
2025-12-08 06:39:50.382927 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_000_run_hook_without_retry_01.sh
2025-12-08 06:39:50.382954 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_001_run_hook_without_retry_02_re.sh
2025-12-08 06:39:50.382978 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_002_run_hook_without_retry_03.sh
2025-12-08 06:39:50.382997 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_003_run_hook_without_retry_run.sh
2025-12-08 06:39:50.383014 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_004_run_hook_without_retry_run.sh
2025-12-08 06:39:50.383030 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_005_run_hook_without_retry_01_my.sh
2025-12-08 06:39:50.383045 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_006_run_hook_without_retry_dummy.sh
2025-12-08 06:39:50.383059 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_007_run_hook_without_retry_hook.sh
2025-12-08 06:39:50.383074 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_008_run_hook_without_retry_run.sh
2025-12-08 06:39:50.383089 | controller | >f+++++++++ ci-framework-data/artifacts/filtered_hooks_01_my_hook.yml
2025-12-08 06:39:50.383104 | controller | >f+++++++++ ci-framework-data/artifacts/list_hooks_run_dummy-2.yml
2025-12-08 06:39:50.383119 | controller | >f+++++++++ ci-framework-data/artifacts/list_hooks_run_dummy-3.yml
2025-12-08 06:39:50.383135 | controller | >f+++++++++ ci-framework-data/artifacts/no_hook_dummy-5.yml
2025-12-08 06:39:50.383151 | controller | >f+++++++++ ci-framework-data/artifacts/no_hook_hook_as_param.yml
2025-12-08 06:39:50.383166 | controller | >f+++++++++ ci-framework-data/artifacts/run_molecule_03_single_hook.yml
2025-12-08 06:39:50.383182 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2025-12-08 06:39:50.383199 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2025-12-08 06:39:50.383214 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2025-12-08 06:39:50.383229 | controller | cd+++++++++ ci-framework-data/logs/
2025-12-08 06:39:50.383244 | controller | >f+++++++++ ci-framework-data/logs/ci_script_000_run_hook_without_retry_01.log
2025-12-08 06:39:50.383259 | controller | >f+++++++++ ci-framework-data/logs/ci_script_001_run_hook_without_retry_02_re.log
2025-12-08 06:39:50.383274 | controller | >f+++++++++ ci-framework-data/logs/ci_script_002_run_hook_without_retry_03.log
2025-12-08 06:39:50.383289 | controller | >f+++++++++ ci-framework-data/logs/ci_script_003_run_hook_without_retry_run.log
2025-12-08 06:39:50.383303 | controller | >f+++++++++ ci-framework-data/logs/ci_script_004_run_hook_without_retry_run.log
2025-12-08 06:39:50.383318 | controller | >f+++++++++ ci-framework-data/logs/ci_script_005_run_hook_without_retry_01_my.log
2025-12-08 06:39:50.383332 | controller | >f+++++++++ ci-framework-data/logs/ci_script_006_run_hook_without_retry_dummy.log
2025-12-08 06:39:50.383347 | controller | >f+++++++++ ci-framework-data/logs/ci_script_007_run_hook_without_retry_hook.log
2025-12-08 06:39:50.383361 | controller | >f+++++++++ ci-framework-data/logs/ci_script_008_run_hook_without_retry_run.log
2025-12-08 06:39:50.383375 | controller | >f+++++++++ ci-framework-data/logs/filtered_hooks_01_my_hook.log
2025-12-08 06:39:50.383389 | controller | >f+++++++++ ci-framework-data/logs/list_hooks_run_dummy-2.log
2025-12-08 06:39:50.383403 | controller | >f+++++++++ ci-framework-data/logs/list_hooks_run_dummy-3.log
2025-12-08 06:39:50.383418 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2025-12-08 06:39:50.383432 | controller | >f+++++++++ ci-framework-data/logs/no_hook_dummy-5.log
2025-12-08 06:39:50.383446 | controller | >f+++++++++ ci-framework-data/logs/no_hook_hook_as_param.log
2025-12-08 06:39:50.383460 | controller | >f+++++++++ ci-framework-data/logs/retry_hook_run_hook_with_retry.log
2025-12-08 06:39:50.383474 | controller | >f+++++++++ ci-framework-data/logs/run_molecule_01_default_noop_hook.log
2025-12-08 06:39:50.383488 | controller | >f+++++++++ ci-framework-data/logs/run_molecule_02_re-run_noop.log
2025-12-08 06:39:50.383502 | controller | >f+++++++++ ci-framework-data/logs/run_molecule_03_single_hook.log
2025-12-08 06:39:50.383520 | controller | cd+++++++++ registries.conf.d/
2025-12-08 06:39:50.383536 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2025-12-08 06:39:50.383550 | controller | cd+++++++++ system-config/
2025-12-08 06:39:50.383564 | controller | cd+++++++++ system-config/libvirt/
2025-12-08 06:39:50.385959 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2025-12-08 06:39:50.386007 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2025-12-08 06:39:50.751635 | controller | changed: .d..t...... ./
2025-12-08 06:39:51.126658 | controller | changed: .d..t...... ./
2025-12-08 06:39:51.143849 | 
2025-12-08 06:39:51.143960 | TASK [Return artifact to Zuul]
2025-12-08 06:39:51.172638 | controller | ok
2025-12-08 06:39:51.192295 | 
2025-12-08 06:39:51.192417 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2025-12-08 06:39:51.192673 | 
2025-12-08 06:39:51.192718 | PLAY RECAP
2025-12-08 06:39:51.192762 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-12-08 06:39:51.192784 | 
2025-12-08 06:39:51.273248 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-12-08 06:39:51.274000 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-08 06:39:51.784435 | 
2025-12-08 06:39:51.784542 | PLAY [all]
2025-12-08 06:39:51.802929 | 
2025-12-08 06:39:51.803010 | TASK [include_role : fetch-output]
2025-12-08 06:39:51.831333 | controller | ok
2025-12-08 06:39:51.847738 | 
2025-12-08 06:39:51.847827 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-08 06:39:51.891850 | controller | skipping: Conditional result was False
2025-12-08 06:39:51.897339 | 
2025-12-08 06:39:51.897417 | TASK [fetch-output : Set log path for single node]
2025-12-08 06:39:51.925473 | controller | ok
2025-12-08 06:39:51.930389 | 
2025-12-08 06:39:51.930460 | LOOP [fetch-output : Ensure local output dirs]
2025-12-08 06:39:52.256202 | controller -> localhost | ok: "/var/lib/zuul/builds/c8a8de4fe48c4950991f041df900c43e/work/logs"
2025-12-08 06:39:52.438470 | controller -> localhost | ok: "/var/lib/zuul/builds/c8a8de4fe48c4950991f041df900c43e/work/artifacts"
2025-12-08 06:39:52.622285 | controller -> localhost | ok: "/var/lib/zuul/builds/c8a8de4fe48c4950991f041df900c43e/work/docs"
2025-12-08 06:39:52.630150 | 
2025-12-08 06:39:52.630228 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-08 06:39:53.136513 | controller | ok
2025-12-08 06:39:53.136713 | controller | ok: All items complete
2025-12-08 06:39:53.136749 | 
2025-12-08 06:39:53.508736 | controller | ok
2025-12-08 06:39:53.888214 | controller | ok
2025-12-08 06:39:53.903635 | 
2025-12-08 06:39:53.903749 | TASK [include_role : fetch-output-openshift]
2025-12-08 06:39:53.917284 | controller | skipping: Conditional result was False
2025-12-08 06:39:53.922900 | 
2025-12-08 06:39:53.922989 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-08 06:39:54.270255 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.006428
2025-12-08 06:39:54.460280 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.006229
2025-12-08 06:39:54.487155 | 
2025-12-08 06:39:54.487248 | PLAY [all]
2025-12-08 06:39:54.500762 | 
2025-12-08 06:39:54.500834 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-12-08 06:39:54.914810 | controller | changed
2025-12-08 06:39:54.936451 | 
2025-12-08 06:39:54.936534 | PLAY RECAP
2025-12-08 06:39:54.936584 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-08 06:39:54.936607 | 
2025-12-08 06:39:55.008724 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-08 06:39:55.009476 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-12-08 06:39:55.547473 | 
2025-12-08 06:39:55.547578 | PLAY [localhost]
2025-12-08 06:39:55.565101 | 
2025-12-08 06:39:55.565195 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-08 06:39:55.876199 | localhost | changed
2025-12-08 06:39:55.880700 | 
2025-12-08 06:39:55.880784 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-08 06:39:55.900627 | localhost | ok
2025-12-08 06:39:55.908674 | 
2025-12-08 06:39:55.908771 | TASK [add-fileserver : Create SSH private key tempfile]
2025-12-08 06:39:56.221945 | localhost | changed
2025-12-08 06:39:56.227481 | 
2025-12-08 06:39:56.227568 | TASK [add-fileserver : Create SSH private key from secret]
2025-12-08 06:39:56.771726 | localhost | changed
2025-12-08 06:39:56.776673 | 
2025-12-08 06:39:56.776765 | TASK [add-fileserver : Add fileserver ssh key]
2025-12-08 06:39:57.108628 | localhost | Identity added: /var/lib/zuul/builds/c8a8de4fe48c4950991f041df900c43e/work/tmp/ansible.bamvvo4f (/var/lib/zuul/builds/c8a8de4fe48c4950991f041df900c43e/work/tmp/ansible.bamvvo4f)
2025-12-08 06:39:57.108815 | localhost | ok: Runtime: 0:00:00.005865
2025-12-08 06:39:57.113089 | 
2025-12-08 06:39:57.113165 | TASK [add-fileserver : Remove SSH private key from disk]
2025-12-08 06:39:57.322944 | localhost | ok: Runtime: 0:00:00.003749
2025-12-08 06:39:57.327591 | 
2025-12-08 06:39:57.327692 | TASK [add-fileserver : Add fileserver to inventory]
2025-12-08 06:39:57.375344 | localhost | changed
2025-12-08 06:39:57.380265 | 
2025-12-08 06:39:57.380340 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-12-08 06:39:57.701307 | localhost | changed
2025-12-08 06:39:57.721334 | 
2025-12-08 06:39:57.721393 | PLAY [localhost]
2025-12-08 06:39:57.732596 | 
2025-12-08 06:39:57.732662 | TASK [Generate bulk log download script]
2025-12-08 06:39:57.750717 | localhost | ok
2025-12-08 06:39:57.762037 | 
2025-12-08 06:39:57.762118 | TASK [local-log-download : Check API endpoint is defined]
2025-12-08 06:39:57.789476 | localhost | ok: All assertions passed
2025-12-08 06:39:57.794000 | 
2025-12-08 06:39:57.794069 | TASK [local-log-download : Create download script]
2025-12-08 06:39:58.131716 | localhost -> localhost | changed
2025-12-08 06:39:58.140440 | 
2025-12-08 06:39:58.140526 | TASK [Register quick-download link]
2025-12-08 06:39:58.158215 | localhost | ok
2025-12-08 06:39:58.195628 | 
2025-12-08 06:39:58.195715 | PLAY [logserver.rdoproject.org]
2025-12-08 06:39:58.205092 | 
2025-12-08 06:39:58.205154 | TASK [Set zuul-log-path fact]
2025-12-08 06:39:58.221493 | logserver.rdoproject.org | ok
2025-12-08 06:39:58.231338 | 
2025-12-08 06:39:58.231427 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-08 06:39:58.257984 | logserver.rdoproject.org | ok
2025-12-08 06:39:58.264078 | 
2025-12-08 06:39:58.264149 | TASK [upload-logs : Create log directories]
2025-12-08 06:39:59.802300 | logserver.rdoproject.org | changed
2025-12-08 06:39:59.805649 | 
2025-12-08 06:39:59.805767 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-12-08 06:40:00.044147 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.005771
2025-12-08 06:40:00.048804 | 
2025-12-08 06:40:00.048874 | TASK [upload-logs : Upload logs to log server]
2025-12-08 06:40:02.000282 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-12-08 06:40:02.004857 | 
2025-12-08 06:40:02.004970 | LOOP [upload-logs : Compress console log and json output]
2025-12-08 06:40:02.043768 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-08 06:40:02.052014 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-08 06:40:02.063978 | 
2025-12-08 06:40:02.064098 | LOOP [upload-logs : Upload compressed console log and json output]
2025-12-08 06:40:02.099753 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-08 06:40:02.099974 | 
2025-12-08 06:40:02.103325 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-08 06:40:02.111689 | 
2025-12-08 06:40:02.111780 | LOOP [upload-logs : Upload console log and json output]