2026-03-13 10:13:40.733342 | Job console starting...
2026-03-13 10:13:40.941608 | Updating repositories
2026-03-13 10:13:40.958911 | Preparing job workspace
2026-03-13 10:13:47.813603 | Running Ansible setup...
2026-03-13 10:13:51.263909 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2026-03-13 10:13:51.736479 | 
2026-03-13 10:13:51.736578 | PLAY [localhost]
2026-03-13 10:13:51.744152 | 
2026-03-13 10:13:51.744218 | TASK [Gathering Facts]
2026-03-13 10:13:52.548978 | localhost | ok
2026-03-13 10:13:52.562734 | 
2026-03-13 10:13:52.562832 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-03-13 10:13:52.869903 | localhost -> localhost | changed
2026-03-13 10:13:52.874790 | 
2026-03-13 10:13:52.874862 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-03-13 10:13:53.506221 | localhost -> localhost | changed
2026-03-13 10:13:53.513905 | 
2026-03-13 10:13:53.513969 | TASK [Setup log path fact]
2026-03-13 10:13:53.531244 | localhost | ok
2026-03-13 10:13:53.541278 | 
2026-03-13 10:13:53.541394 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-03-13 10:13:53.558572 | localhost | ok
2026-03-13 10:13:53.565174 | 
2026-03-13 10:13:53.565233 | TASK [emit-job-header : Print job information]
2026-03-13 10:13:53.592168 | # Job Information
2026-03-13 10:13:53.592278 | Ansible Version: 2.15.12
2026-03-13 10:13:53.592324 | Job: cifmw-molecule-reproducer
2026-03-13 10:13:53.592348 | Pipeline: github-check
2026-03-13 10:13:53.592368 | Executor: ibm-bm4-ze.softwarefactory-project.io
2026-03-13 10:13:53.592385 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3739
2026-03-13 10:13:53.592403 | Log URL (when completed): https://logserver.rdoproject.org/d70/rdoproject.org/d70368b102fb4619967560b1a46c331a/
2026-03-13 10:13:53.592421 | Event ID: 2b9e47e0-1ec5-11f1-9a71-feae00c026ed
2026-03-13 10:13:53.595786 | 
2026-03-13 10:13:53.595851 | LOOP [emit-job-header : Print node information]
2026-03-13 10:13:53.673735 | localhost | ok:
2026-03-13 10:13:53.673846 | localhost | # Node Information
2026-03-13 10:13:53.673874 | localhost | Inventory Hostname: controller
2026-03-13 10:13:53.673897 | localhost | Hostname: np0005646133
2026-03-13 10:13:53.673917 | localhost | Username: zuul
2026-03-13 10:13:53.673937 | localhost | Distro: CentOS 9
2026-03-13 10:13:53.673954 | localhost | Provider: ibm-bm4-nodepool
2026-03-13 10:13:53.673971 | localhost | Region: regionOne
2026-03-13 10:13:53.673987 | localhost | Label: centos-9-stream-crc-2-48-0-xxl-ibm
2026-03-13 10:13:53.674004 | localhost | Product Name: OpenStack Compute
2026-03-13 10:13:53.674021 | localhost | Interface IP: 192.168.26.132
2026-03-13 10:13:53.700140 | 
2026-03-13 10:13:53.700215 | PLAY [all]
2026-03-13 10:13:53.705811 | 
2026-03-13 10:13:53.705871 | TASK [Gather network facts]
2026-03-13 10:13:54.170026 | controller | ok
2026-03-13 10:13:54.182787 | 
2026-03-13 10:13:54.182849 | TASK [include_role : start-zuul-console]
2026-03-13 10:13:54.200643 | controller | ok
2026-03-13 10:13:54.210782 | 
2026-03-13 10:13:54.210846 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-03-13 10:13:54.572745 | controller | ok
2026-03-13 10:13:54.580424 | 
2026-03-13 10:13:54.580492 | TASK [include_role : add-build-sshkey]
2026-03-13 10:13:54.597947 | controller | ok
2026-03-13 10:13:54.609576 | 
2026-03-13 10:13:54.609645 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-03-13 10:13:54.795077 | controller -> localhost | ok
2026-03-13 10:13:54.800395 | 
2026-03-13 10:13:54.800457 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-03-13 10:13:54.818786 | controller | ok
2026-03-13 10:13:54.829903 | controller | included: /var/lib/zuul/builds/d70368b102fb4619967560b1a46c331a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-03-13 10:13:54.834963 | 
2026-03-13 10:13:54.835020 | TASK [add-build-sshkey : Create Temp SSH key]
2026-03-13 10:13:55.263736 | controller -> localhost | Generating public/private rsa key pair.
2026-03-13 10:13:55.263917 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/d70368b102fb4619967560b1a46c331a/work/d70368b102fb4619967560b1a46c331a_id_rsa.
2026-03-13 10:13:55.263951 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/d70368b102fb4619967560b1a46c331a/work/d70368b102fb4619967560b1a46c331a_id_rsa.pub.
2026-03-13 10:13:55.263973 | controller -> localhost | The key fingerprint is:
2026-03-13 10:13:55.263993 | controller -> localhost | SHA256:ey1qL5uTEbL30ApZFvROptYnRu5KuWwnB9558LUQeqc zuul-build-sshkey
2026-03-13 10:13:55.264011 | controller -> localhost | The key's randomart image is:
2026-03-13 10:13:55.264028 | controller -> localhost | +---[RSA 3072]----+
2026-03-13 10:13:55.264044 | controller -> localhost | |       ..        |
2026-03-13 10:13:55.264059 | controller -> localhost | |        ..       |
2026-03-13 10:13:55.264075 | controller -> localhost | |         .=      |
2026-03-13 10:13:55.264090 | controller -> localhost | |      . +O  .    |
2026-03-13 10:13:55.264105 | controller -> localhost | |       *So*...   |
2026-03-13 10:13:55.264119 | controller -> localhost | |      +.==++o o  |
2026-03-13 10:13:55.264133 | controller -> localhost | |       ++O+=.= . |
2026-03-13 10:13:55.264151 | controller -> localhost | |       oX**.E .  |
2026-03-13 10:13:55.264168 | controller -> localhost | |       oBO..     |
2026-03-13 10:13:55.264184 | controller -> localhost | +----[SHA256]-----+
2026-03-13 10:13:55.264221 | controller -> localhost | ok: Runtime: 0:00:00.130214
2026-03-13 10:13:55.269241 | 
2026-03-13 10:13:55.269325 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-03-13 10:13:55.286763 | controller | ok
2026-03-13 10:13:55.295554 | controller | included: /var/lib/zuul/builds/d70368b102fb4619967560b1a46c331a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-03-13 10:13:55.302894 | 
2026-03-13 10:13:55.302958 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-03-13 10:13:55.316194 | controller | skipping: Conditional result was False
2026-03-13 10:13:55.321216 | 
2026-03-13 10:13:55.321282 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-03-13 10:13:55.806409 | controller | changed
2026-03-13 10:13:55.811108 | 
2026-03-13 10:13:55.811170 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-03-13 10:13:56.092153 | controller | ok
2026-03-13 10:13:56.096941 | 
2026-03-13 10:13:56.097004 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-03-13 10:13:57.320333 | controller | changed
2026-03-13 10:13:57.325440 | 
2026-03-13 10:13:57.325504 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-03-13 10:13:58.525152 | controller | changed
2026-03-13 10:13:58.529967 | 
2026-03-13 10:13:58.530043 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-03-13 10:13:58.543771 | controller | skipping: Conditional result was False
2026-03-13 10:13:58.548918 | 
2026-03-13 10:13:58.548984 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-03-13 10:13:58.825640 | controller -> localhost | changed
2026-03-13 10:13:58.834458 | 
2026-03-13 10:13:58.834532 | TASK [add-build-sshkey : Add back temp key]
2026-03-13 10:13:59.040532 | controller -> localhost | Identity added: /var/lib/zuul/builds/d70368b102fb4619967560b1a46c331a/work/d70368b102fb4619967560b1a46c331a_id_rsa (zuul-build-sshkey)
2026-03-13 10:13:59.040684 | controller -> localhost | ok: Runtime: 0:00:00.006951
2026-03-13 10:13:59.045637 | 
2026-03-13 10:13:59.045694 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-03-13 10:13:59.408559 | controller | ok
2026-03-13 10:13:59.413033 | 
2026-03-13 10:13:59.413098 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-03-13 10:13:59.437417 | controller | skipping: Conditional result was False
2026-03-13 10:13:59.445901 | 
2026-03-13 10:13:59.445964 | TASK [include_role : validate-host]
2026-03-13 10:13:59.464274 | controller | ok
2026-03-13 10:13:59.482024 | 
2026-03-13 10:13:59.482091 | TASK [validate-host : Define zuul_info_dir fact]
2026-03-13 10:13:59.509715 | controller | ok
2026-03-13 10:13:59.514075 | 
2026-03-13 10:13:59.514134 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2026-03-13 10:13:59.700160 | controller -> localhost | ok
2026-03-13 10:13:59.705636 | 
2026-03-13 10:13:59.705697 | TASK [validate-host : Collect information about the host]
2026-03-13 10:14:00.429915 | controller | ok
2026-03-13 10:14:00.437084 | 
2026-03-13 10:14:00.437142 | TASK [validate-host : Sanitize hostname]
2026-03-13 10:14:00.474158 | controller | ok
2026-03-13 10:14:00.478403 | 
2026-03-13 10:14:00.478465 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2026-03-13 10:14:00.836010 | controller -> localhost | changed
2026-03-13 10:14:00.841364 | 
2026-03-13 10:14:00.841435 | TASK [validate-host : Collect information about zuul worker]
2026-03-13 10:14:01.244164 | controller | ok
2026-03-13 10:14:01.248933 | 
2026-03-13 10:14:01.249001 | TASK [validate-host : Write out all zuul information for each host]
2026-03-13 10:14:01.600017 | controller -> localhost | changed
2026-03-13 10:14:01.608064 | 
2026-03-13 10:14:01.608124 | TASK [include_role : prepare-workspace-openshift]
2026-03-13 10:14:01.621014 | controller | skipping: Conditional result was False
2026-03-13 10:14:01.625710 | 
2026-03-13 10:14:01.625767 | TASK [include_role : remove-zuul-sshkey]
2026-03-13 10:14:01.638953 | controller | skipping: Conditional result was False
2026-03-13 10:14:01.643390 | 
2026-03-13 10:14:01.643448 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-03-13 10:14:01.905026 | controller | ok: "logs"
2026-03-13 10:14:01.905248 | controller | ok: All items complete
2026-03-13 10:14:01.905275 | 
2026-03-13 10:14:02.141738 | controller | ok: "artifacts"
2026-03-13 10:14:02.388879 | controller | ok: "docs"
2026-03-13 10:14:02.402772 | 
2026-03-13 10:14:02.402846 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-03-13 10:14:02.664947 | controller | changed: "logs"
2026-03-13 10:14:02.924716 | controller | changed: "artifacts"
2026-03-13 10:14:03.159751 | controller | changed: "docs"
2026-03-13 10:14:03.188548 | 
2026-03-13 10:14:03.188622 | PLAY RECAP
2026-03-13 10:14:03.188665 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2026-03-13 10:14:03.188692 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-03-13 10:14:03.188710 | 
2026-03-13 10:14:03.264281 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2026-03-13 10:14:03.264937 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2026-03-13 10:14:03.773212 | 
2026-03-13 10:14:03.773351 | PLAY [all]
2026-03-13 10:14:03.791104 | 
2026-03-13 10:14:03.791176 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2026-03-13 10:14:03.841112 | controller | ok
2026-03-13 10:14:03.845625 | 
2026-03-13 10:14:03.845700 | TASK [mirror-info-fork : Create /etc/ci]
2026-03-13 10:14:04.239472 | controller | changed
2026-03-13 10:14:04.244517 | 
2026-03-13 10:14:04.244585 | TASK [mirror-info-fork : Install ci_mirror script]
2026-03-13 10:14:05.536544 | controller | changed
2026-03-13 10:14:05.546177 | 
2026-03-13 10:14:05.546250 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2026-03-13 10:14:05.989679 | controller | changed:
2026-03-13 10:14:05.989838 | controller | {
2026-03-13 10:14:05.989872 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2026-03-13 10:14:05.989901 | controller | }
2026-03-13 10:14:06.286364 | controller | changed:
2026-03-13 10:14:06.286454 | controller | {
2026-03-13 10:14:06.286482 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2026-03-13 10:14:06.286513 | controller | }
2026-03-13 10:14:06.588556 | controller | changed:
2026-03-13 10:14:06.588622 | controller | {
2026-03-13 10:14:06.588646 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com"
2026-03-13 10:14:06.588665 | controller | }
2026-03-13 10:14:06.879654 | controller | changed:
2026-03-13 10:14:06.879742 | controller | {
2026-03-13 10:14:06.879768 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2026-03-13 10:14:06.879787 | controller | }
2026-03-13 10:14:07.170312 | controller | changed:
2026-03-13 10:14:07.170369 | controller | {
2026-03-13 10:14:07.170396 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2026-03-13 10:14:07.170417 | controller | }
2026-03-13 10:14:07.466047 | controller | changed:
2026-03-13 10:14:07.466095 | controller | {
2026-03-13 10:14:07.466121 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2026-03-13 10:14:07.466140 | controller | }
2026-03-13 10:14:07.749050 | controller | changed:
2026-03-13 10:14:07.749098 | controller | {
2026-03-13 10:14:07.749122 | 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"
2026-03-13 10:14:07.749142 | controller | }
2026-03-13 10:14:08.050268 | controller | changed:
2026-03-13 10:14:08.050337 | controller | {
2026-03-13 10:14:08.050366 | 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"
2026-03-13 10:14:08.050387 | controller | }
2026-03-13 10:14:08.335516 | controller | changed:
2026-03-13 10:14:08.335572 | controller | {
2026-03-13 10:14:08.335598 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2026-03-13 10:14:08.335618 | controller | }
2026-03-13 10:14:08.656915 | controller | changed:
2026-03-13 10:14:08.657034 | controller | {
2026-03-13 10:14:08.657064 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2026-03-13 10:14:08.657086 | controller | }
2026-03-13 10:14:08.930747 | controller | changed:
2026-03-13 10:14:08.930812 | controller | {
2026-03-13 10:14:08.930838 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2026-03-13 10:14:08.930858 | controller | }
2026-03-13 10:14:09.220595 | controller | changed:
2026-03-13 10:14:09.220642 | controller | {
2026-03-13 10:14:09.220667 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2026-03-13 10:14:09.220687 | controller | }
2026-03-13 10:14:09.530559 | controller | changed:
2026-03-13 10:14:09.530623 | controller | {
2026-03-13 10:14:09.530650 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICWBreHW95Wz2Toz5YwCGQwFcUG8oFYkienDh9tntmDc ralfieri@redhat.com"
2026-03-13 10:14:09.530671 | controller | }
2026-03-13 10:14:09.829343 | controller | changed:
2026-03-13 10:14:09.829434 | controller | {
2026-03-13 10:14:09.829463 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2026-03-13 10:14:09.829492 | controller | }
2026-03-13 10:14:10.129874 | controller | changed:
2026-03-13 10:14:10.129945 | controller | {
2026-03-13 10:14:10.129973 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2026-03-13 10:14:10.129996 | controller | }
2026-03-13 10:14:10.417518 | controller | changed:
2026-03-13 10:14:10.417600 | controller | {
2026-03-13 10:14:10.417626 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2026-03-13 10:14:10.417646 | controller | }
2026-03-13 10:14:10.718340 | controller | changed:
2026-03-13 10:14:10.718433 | controller | {
2026-03-13 10:14:10.718463 | 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"
2026-03-13 10:14:10.718498 | controller | }
2026-03-13 10:14:11.014002 | controller | changed:
2026-03-13 10:14:11.014094 | controller | {
2026-03-13 10:14:11.014120 | 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"
2026-03-13 10:14:11.014148 | controller | }
2026-03-13 10:14:11.310770 | controller | changed:
2026-03-13 10:14:11.310860 | controller | {
2026-03-13 10:14:11.310890 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2026-03-13 10:14:11.310912 | controller | }
2026-03-13 10:14:11.600322 | controller | changed:
2026-03-13 10:14:11.600395 | controller | {
2026-03-13 10:14:11.600420 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2026-03-13 10:14:11.600441 | controller | }
2026-03-13 10:14:11.896868 | controller | changed:
2026-03-13 10:14:11.896942 | controller | {
2026-03-13 10:14:11.896974 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2026-03-13 10:14:11.896998 | controller | }
2026-03-13 10:14:12.195012 | controller | changed:
2026-03-13 10:14:12.195094 | controller | {
2026-03-13 10:14:12.195120 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2026-03-13 10:14:12.195139 | controller | }
2026-03-13 10:14:12.503767 | controller | changed:
2026-03-13 10:14:12.503843 | controller | {
2026-03-13 10:14:12.503869 | 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"
2026-03-13 10:14:12.503891 | controller | }
2026-03-13 10:14:12.814961 | controller | changed:
2026-03-13 10:14:12.815045 | controller | {
2026-03-13 10:14:12.815072 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2026-03-13 10:14:12.815093 | controller | }
2026-03-13 10:14:13.117869 | controller | changed:
2026-03-13 10:14:13.117951 | controller | {
2026-03-13 10:14:13.117979 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2026-03-13 10:14:13.117999 | controller | }
2026-03-13 10:14:13.425050 | controller | changed:
2026-03-13 10:14:13.425133 | controller | {
2026-03-13 10:14:13.425165 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2026-03-13 10:14:13.425191 | controller | }
2026-03-13 10:14:13.450142 | 
2026-03-13 10:14:13.450207 | TASK [Set timezone to UTC]
2026-03-13 10:14:13.975939 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2026-03-13 10:14:13.980812 | 
2026-03-13 10:14:13.980887 | TASK [Create nodepool directory]
2026-03-13 10:14:14.272018 | controller | changed
2026-03-13 10:14:14.277027 | 
2026-03-13 10:14:14.277090 | TASK [Create nodepool sub_nodes file]
2026-03-13 10:14:15.358402 | controller | changed
2026-03-13 10:14:15.363161 | 
2026-03-13 10:14:15.363227 | TASK [Create nodepool sub_nodes_private file]
2026-03-13 10:14:16.446679 | controller | changed
2026-03-13 10:14:16.452013 | 
2026-03-13 10:14:16.452089 | LOOP [Populate nodepool sub_nodes file]
2026-03-13 10:14:16.491363 | 
2026-03-13 10:14:16.491499 | LOOP [Populate nodepool sub_nodes_private file]
2026-03-13 10:14:16.520138 | 
2026-03-13 10:14:16.520262 | TASK [Create nodepool primary file]
2026-03-13 10:14:16.543646 | controller | skipping: Conditional result was False
2026-03-13 10:14:16.548993 | 
2026-03-13 10:14:16.549070 | TASK [Create nodepool node_private for this node]
2026-03-13 10:14:17.574423 | controller | changed
2026-03-13 10:14:17.579592 | 
2026-03-13 10:14:17.579654 | LOOP [Copy ssh keys to nodepool directory]
2026-03-13 10:14:17.946184 | controller | ok: Item: id_rsa Runtime: 0:00:00.005612
2026-03-13 10:14:17.946385 | 
2026-03-13 10:14:18.173817 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.006094
2026-03-13 10:14:18.187680 | 
2026-03-13 10:14:18.187749 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2026-03-13 10:14:19.191945 | controller | changed
2026-03-13 10:14:19.196671 | 
2026-03-13 10:14:19.196733 | TASK [Validate sudoers config after edits]
2026-03-13 10:14:19.487413 | controller | /etc/sudoers: parsed OK
2026-03-13 10:14:19.487466 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2026-03-13 10:14:19.487474 | controller | /etc/sudoers.d/zuul: parsed OK
2026-03-13 10:14:19.487480 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2026-03-13 10:14:19.722109 | controller | ok: Runtime: 0:00:00.006139
2026-03-13 10:14:19.729940 | 
2026-03-13 10:14:19.730004 | TASK [Show the environment passed in to job shell scripts]
2026-03-13 10:14:20.010228 | controller | SHELL=/bin/bash
2026-03-13 10:14:20.010273 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2026-03-13 10:14:20.010283 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2026-03-13 10:14:20.010290 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/39/3739/03404f06ee814e03090edc1c9298642aede00297
2026-03-13 10:14:20.010296 | controller | PWD=/home/zuul
2026-03-13 10:14:20.010302 | controller | ZUUL_PIPELINE=github-check
2026-03-13 10:14:20.010307 | controller | LOGNAME=zuul
2026-03-13 10:14:20.010312 | controller | XDG_SESSION_TYPE=tty
2026-03-13 10:14:20.010317 | controller | _=/usr/bin/env
2026-03-13 10:14:20.010350 | controller | MOTD_SHOWN=pam
2026-03-13 10:14:20.010358 | controller | HOME=/home/zuul
2026-03-13 10:14:20.010363 | controller | LANG=en_US.UTF-8
2026-03-13 10:14:20.010369 | controller | SSH_CONNECTION=192.168.26.12 52772 192.168.26.132 22
2026-03-13 10:14:20.010374 | 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
2026-03-13 10:14:20.010383 | controller | ZUUL_CHANGE_IDS=3739,03404f06ee814e03090edc1c9298642aede00297
2026-03-13 10:14:20.010388 | controller | WORKSPACE=/home/zuul/workspace
2026-03-13 10:14:20.010394 | controller | XDG_SESSION_CLASS=user
2026-03-13 10:14:20.010399 | controller | SELINUX_ROLE_REQUESTED=
2026-03-13 10:14:20.010404 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2026-03-13 10:14:20.010410 | controller | USER=zuul
2026-03-13 10:14:20.010415 | controller | ZUUL_VOTING=True
2026-03-13 10:14:20.010420 | controller | BUILD_TIMEOUT=5400000
2026-03-13 10:14:20.010425 | controller | SELINUX_USE_CURRENT_RANGE=
2026-03-13 10:14:20.010431 | controller | SHLVL=1
2026-03-13 10:14:20.010436 | controller | ZUUL_PATCHSET=03404f06ee814e03090edc1c9298642aede00297
2026-03-13 10:14:20.010441 | controller | XDG_SESSION_ID=1
2026-03-13 10:14:20.010447 | controller | ZUUL_BRANCH=main
2026-03-13 10:14:20.010452 | controller | XDG_RUNTIME_DIR=/run/user/1000
2026-03-13 10:14:20.010457 | controller | SSH_CLIENT=192.168.26.12 52772 22
2026-03-13 10:14:20.010463 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2026-03-13 10:14:20.010468 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2026-03-13 10:14:20.010473 | controller | which_declare=declare -f
2026-03-13 10:14:20.010479 | controller | PATH=/home/zuul/.crc/bin/oc:/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2026-03-13 10:14:20.010484 | controller | SELINUX_LEVEL_REQUESTED=
2026-03-13 10:14:20.010489 | controller | ZUUL_CHANGE=3739
2026-03-13 10:14:20.010494 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2026-03-13 10:14:20.010515 | controller | ZUUL_UUID=d70368b102fb4619967560b1a46c331a
2026-03-13 10:14:20.010524 | controller | BASH_FUNC_which%%=() {  ( alias;
2026-03-13 10:14:20.010530 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2026-03-13 10:14:20.010535 | controller | }
2026-03-13 10:14:20.256100 | controller | ok: Runtime: 0:00:00.007124
2026-03-13 10:14:20.260791 | 
2026-03-13 10:14:20.260853 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2026-03-13 10:14:20.273902 | controller | skipping: Conditional result was False
2026-03-13 10:14:20.278450 | 
2026-03-13 10:14:20.278509 | TASK [Symlink /home/zuul-worker/workspace]
2026-03-13 10:14:20.823802 | controller | skipping: Conditional result was False
2026-03-13 10:14:20.829327 | 
2026-03-13 10:14:20.829393 | TASK [Ensure legacy workspace directory]
2026-03-13 10:14:21.070527 | controller | changed
2026-03-13 10:14:21.088340 | 
2026-03-13 10:14:21.088394 | PLAY RECAP
2026-03-13 10:14:21.088439 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2026-03-13 10:14:21.088479 | 
2026-03-13 10:14:21.155190 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2026-03-13 10:14:21.155904 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2026-03-13 10:14:21.628248 | 
2026-03-13 10:14:21.628361 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2026-03-13 10:14:21.646461 | 
2026-03-13 10:14:21.646531 | TASK [Create zuul-output directory]
2026-03-13 10:14:22.021413 | controller | changed
2026-03-13 10:14:22.026355 | 
2026-03-13 10:14:22.026431 | TASK [Slurp Zuul inventory test]
2026-03-13 10:14:22.272813 | controller -> localhost | ok
2026-03-13 10:14:22.279249 | 
2026-03-13 10:14:22.279342 | TASK [Save zuul inventory]
2026-03-13 10:14:23.472257 | controller | changed
2026-03-13 10:14:23.477615 | 
2026-03-13 10:14:23.477681 | TASK [Save zuul vars without the change_message]
2026-03-13 10:14:24.482526 | controller | changed
2026-03-13 10:14:24.500059 | 
2026-03-13 10:14:24.500117 | PLAY RECAP
2026-03-13 10:14:24.500162 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-03-13 10:14:24.500185 | 
2026-03-13 10:14:24.559399 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2026-03-13 10:14:24.560112 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2026-03-13 10:14:25.076278 | 
2026-03-13 10:14:25.076393 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2026-03-13 10:14:25.094956 | 
2026-03-13 10:14:25.095021 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2026-03-13 10:14:25.113029 | controller | ok
2026-03-13 10:14:25.128542 | 
2026-03-13 10:14:25.128613 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2026-03-13 10:14:25.152256 | controller | skipping: Conditional result was False
2026-03-13 10:14:25.157373 | 
2026-03-13 10:14:25.157452 | TASK [mirror-info-fork : Create /etc/ci]
2026-03-13 10:14:25.520718 | controller | ok
2026-03-13 10:14:25.525992 | 
2026-03-13 10:14:25.526061 | TASK [mirror-info-fork : Install ci_mirror script]
2026-03-13 10:14:26.452227 | controller | ok
2026-03-13 10:14:26.461373 | 
2026-03-13 10:14:26.461445 | TASK [Prepare workspace]
2026-03-13 10:14:26.479363 | controller | ok
2026-03-13 10:14:26.495520 | 
2026-03-13 10:14:26.495588 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-03-13 10:14:26.840778 | controller | ok
2026-03-13 10:14:26.846162 | 
2026-03-13 10:14:26.846224 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-03-13 10:14:29.234409 | controller | Output suppressed because no_log was given
2026-03-13 10:14:29.243086 | 
2026-03-13 10:14:29.243146 | LOOP [Create zuul-output directory]
2026-03-13 10:14:29.502240 | controller | changed: "/home/zuul/ci-framework-data/logs"
2026-03-13 10:14:29.722168 | controller | ok: "/home/zuul/zuul-output/logs"
2026-03-13 10:14:29.729917 | 
2026-03-13 10:14:29.729977 | TASK [Install required packages]
2026-03-13 10:14:49.867030 | controller | ok: Nothing to do
2026-03-13 10:14:49.871962 | 
2026-03-13 10:14:49.872023 | TASK [Install venv]
2026-03-13 10:15:46.448019 | controller | changed
2026-03-13 10:15:46.472032 | 
2026-03-13 10:15:46.472126 | PLAY RECAP
2026-03-13 10:15:46.472186 | controller | ok: 7 changed: 3 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-03-13 10:15:46.472211 | 
2026-03-13 10:15:46.542614 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2026-03-13 10:15:46.543345 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2026-03-13 10:15:47.010177 | 
2026-03-13 10:15:47.010264 | PLAY [Run ci/playbooks/molecule-test.yml]
2026-03-13 10:15:47.028932 | 
2026-03-13 10:15:47.029001 | TASK [Gather required facts]
2026-03-13 10:15:47.595360 | controller | ok
2026-03-13 10:15:47.600087 | 
2026-03-13 10:15:47.600153 | TASK [Load environment var if instructed to]
2026-03-13 10:15:47.623197 | controller | skipping: Conditional result was False
2026-03-13 10:15:47.628199 | 
2026-03-13 10:15:47.628259 | TASK [Ensure group_vars dir exists]
2026-03-13 10:15:48.001143 | controller | ok
2026-03-13 10:15:48.005872 | 
2026-03-13 10:15:48.005931 | TASK [Print related variables]
2026-03-13 10:15:48.033998 | controller | ok:
2026-03-13 10:15:48.034108 | controller | mol_config_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config_local.yml
2026-03-13 10:15:48.034137 | controller | roles_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer
2026-03-13 10:15:48.038424 | 
2026-03-13 10:15:48.038483 | TASK [Run molecule]
2026-03-13 10:15:49.031335 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2026-03-13 10:15:49.355293 | controller | INFO     Running bm_redfish > prepare
2026-03-13 10:15:50.055083 | controller |
2026-03-13 10:15:50.401367 | controller | PLAY [Prepare mock iDRAC server] ***********************************************
2026-03-13 10:15:50.401417 | controller |
2026-03-13 10:15:50.401432 | controller | TASK [Create mock server directory] ********************************************
2026-03-13 10:15:50.401443 | controller | Friday 13 March 2026  10:15:50 +0000 (0:00:00.025)       0:00:00.025 **********
2026-03-13 10:15:50.401461 | controller | changed: [instance]
2026-03-13 10:15:50.401474 | controller |
2026-03-13 10:15:50.401488 | controller | TASK [Generate self-signed TLS certificate] ************************************
2026-03-13 10:15:50.401565 | controller | Friday 13 March 2026  10:15:50 +0000 (0:00:00.348)       0:00:00.374 **********
2026-03-13 10:15:50.738954 | controller | changed: [instance]
2026-03-13 10:15:50.738989 | controller |
2026-03-13 10:15:50.739125 | controller | TASK [Copy mock iDRAC server script] *******************************************
2026-03-13 10:15:50.739227 | controller | Friday 13 March 2026  10:15:50 +0000 (0:00:00.337)       0:00:00.711 **********
2026-03-13 10:15:51.253461 | controller | changed: [instance]
2026-03-13 10:15:51.253518 | controller |
2026-03-13 10:15:51.253603 | controller | TASK [Start mock iDRAC server] *************************************************
2026-03-13 10:15:51.253704 | controller | Friday 13 March 2026  10:15:51 +0000 (0:00:00.514)       0:00:01.226 **********
2026-03-13 10:15:51.435333 | controller | changed: [instance]
2026-03-13 10:15:51.435374 | controller |
2026-03-13 10:15:51.436083 | controller | TASK [Record mock server PID] **************************************************
2026-03-13 10:15:51.436127 | controller | Friday 13 March 2026  10:15:51 +0000 (0:00:00.181)       0:00:01.408 **********
2026-03-13 10:15:51.645013 | controller | ok: [instance]
2026-03-13 10:15:51.645112 | controller |
2026-03-13 10:15:51.645177 | controller | TASK [Wait for mock iDRAC to respond] ******************************************
2026-03-13 10:15:51.645275 | controller | Friday 13 March 2026  10:15:51 +0000 (0:00:00.209)       0:00:01.617 **********
2026-03-13 10:15:52.107397 | controller | ok: [instance]
2026-03-13 10:15:52.107438 | controller |
2026-03-13 10:15:52.107573 | controller | PLAY RECAP *********************************************************************
2026-03-13 10:15:52.107668 | controller | instance                   : ok=6    changed=4    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2026-03-13 10:15:52.107761 | controller |
2026-03-13 10:15:52.107854 | controller | Friday 13 March 2026  10:15:52 +0000 (0:00:00.462)       0:00:02.080 **********
2026-03-13 10:15:52.107926 | controller | ===============================================================================
2026-03-13 10:15:52.108018 | controller | Copy mock iDRAC server script ------------------------------------------- 0.51s
2026-03-13 10:15:52.108106 | controller | Wait for mock iDRAC to respond ------------------------------------------ 0.46s
2026-03-13 10:15:52.108195 | controller | Create mock server directory -------------------------------------------- 0.35s
2026-03-13 10:15:52.108284 | controller | Generate self-signed TLS certificate ------------------------------------ 0.34s
2026-03-13 10:15:52.108371 | controller | Record mock server PID -------------------------------------------------- 0.21s
2026-03-13 10:15:52.108461 | controller | Start mock iDRAC server ------------------------------------------------- 0.18s
2026-03-13 10:15:52.178480 | controller | INFO     Running bm_redfish > converge
2026-03-13 10:15:52.611391 | controller |
2026-03-13 10:15:52.611465 | controller | PLAY [Converge -- test bm_* Redfish tasks against mock iDRAC] ******************
2026-03-13 10:15:52.611553 | controller |
2026-03-13 10:15:52.611680 | controller | TASK [Test bm_power_off] *******************************************************
2026-03-13 10:15:52.611779 | controller | Friday 13 March 2026  10:15:52 +0000 (0:00:00.054)       0:00:00.054 **********
2026-03-13 10:15:52.635079 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/molecule/bm_redfish/tasks/test_power_off.yml for instance
2026-03-13 10:15:52.635130 | controller |
2026-03-13 10:15:52.635277 | controller | TASK [Reset mock to power Off] *************************************************
2026-03-13 10:15:52.635367 | controller | Friday 13 March 2026  10:15:52 +0000 (0:00:00.024)       0:00:00.079 **********
2026-03-13 10:15:53.039810 | controller | ok: [instance]
2026-03-13 10:15:53.039943 | controller |
2026-03-13 10:15:53.039969 | controller | TASK [Include bm_power_off] ****************************************************
2026-03-13 10:15:53.040056 | controller | Friday 13 March 2026  10:15:53 +0000 (0:00:00.404)       0:00:00.483 **********
2026-03-13 10:15:53.071135 | controller |
2026-03-13 10:15:53.071291 | controller | TASK [reproducer : Query current power state] **********************************
2026-03-13 10:15:53.071476 | controller | Friday 13 March 2026  10:15:53 +0000 (0:00:00.031)       0:00:00.515 **********
2026-03-13 10:15:53.395614 | controller | ok: [instance]
2026-03-13 10:15:53.395648 | controller |
2026-03-13 10:15:53.395763 | controller | TASK [reproducer : Force power off via Redfish] ********************************
2026-03-13 10:15:53.395847 | controller | Friday 13 March 2026  10:15:53 +0000 (0:00:00.324)       0:00:00.839 **********
2026-03-13 10:15:53.416486 | controller | skipping: [instance]
2026-03-13 10:15:53.416536 | controller |
2026-03-13 10:15:53.416758 | controller | TASK [reproducer : Wait for host to power off] *********************************
2026-03-13 10:15:53.416861 | controller | Friday 13 March 2026  10:15:53 +0000 (0:00:00.021)       0:00:00.860 **********
2026-03-13 10:15:53.440283 | controller | skipping: [instance]
2026-03-13 10:15:53.440313 | controller |
2026-03-13 10:15:53.440455 | controller | TASK [Query mock state after power_off (already off)] **************************
2026-03-13 10:15:53.440522 | controller | Friday 13 March 2026  10:15:53 +0000 (0:00:00.023)       0:00:00.884 **********
2026-03-13 10:15:53.732256 | controller | ok: [instance]
2026-03-13 10:15:53.732347 | controller |
2026-03-13 10:15:53.732363 | controller | TASK [Assert host is still Off] ************************************************
2026-03-13 10:15:53.732556 | controller | Friday 13 March 2026  10:15:53 +0000 (0:00:00.291)       0:00:01.176 **********
2026-03-13 10:15:53.756233 | controller | ok: [instance] => {
2026-03-13 10:15:54.045173 | controller |     "changed": false,
2026-03-13 10:15:54.045194 | controller |     "msg": "All assertions passed"
2026-03-13 10:15:54.045208 | controller | }
2026-03-13 10:15:54.045214 | controller |
2026-03-13 10:15:54.045220 | controller | TASK [Reset mock to power On] **************************************************
2026-03-13 10:15:54.045227 | controller | Friday 13 March 2026  10:15:53 +0000 (0:00:00.023)       0:00:01.200 **********
2026-03-13 10:15:54.045236 | controller | ok: [instance]
2026-03-13 10:15:54.074496 | controller |
2026-03-13 10:15:54.074533 | controller | TASK [Include bm_power_off] ****************************************************
2026-03-13 10:15:54.074541 | controller | Friday 13 March 2026  10:15:54 +0000 (0:00:00.289)       0:00:01.489 **********
2026-03-13 10:15:54.074551 | controller |
2026-03-13 10:15:54.383400 | controller | TASK [reproducer : Query current power state] **********************************
2026-03-13 10:15:54.383419 | controller | Friday 13 March 2026  10:15:54 +0000 (0:00:00.028)       0:00:01.517 **********
2026-03-13 10:15:54.383432 | controller | ok: [instance]
2026-03-13 10:15:54.678729 | controller |
2026-03-13 10:15:54.678786 | controller | TASK [reproducer : Force power off via Redfish] ********************************
2026-03-13 10:15:54.678796 | controller | Friday 13 March 2026  10:15:54 +0000 (0:00:00.309)       0:00:01.827 **********
2026-03-13 10:15:54.678811 | controller | ok: [instance]
2026-03-13 10:15:54.978613 | controller |
2026-03-13 10:15:54.978645 | controller | TASK [reproducer : Wait for host to power off] *********************************
2026-03-13 10:15:54.978653 | controller | Friday 13 March 2026  10:15:54 +0000 (0:00:00.295)       0:00:02.122 **********
2026-03-13 10:15:54.978662 | controller | ok: [instance]
2026-03-13 10:15:55.267280 | controller |
2026-03-13 10:15:55.267315 | controller | TASK [Query mock state after power_off (was on)] *******************************
2026-03-13 10:15:55.267329 | controller | Friday 13 March 2026  10:15:54 +0000 (0:00:00.299)       0:00:02.422 **********
2026-03-13 10:15:55.267345 | controller | ok: [instance]
2026-03-13 10:15:55.292710 | controller |
2026-03-13 10:15:55.292762 | controller | TASK [Assert host is now Off] **************************************************
2026-03-13 10:15:55.292772 | controller | Friday 13 March 2026  10:15:55 +0000 (0:00:00.287)       0:00:02.710 **********
2026-03-13 10:15:55.292786 | controller | ok: [instance] => {
2026-03-13 10:15:55.292819 | controller |     "changed": false,
2026-03-13 10:15:55.292826 | controller |     "msg": "All assertions passed"
2026-03-13 10:15:55.292843 | controller | }
2026-03-13 10:15:55.292850 | controller |
2026-03-13 10:15:55.292860 | controller | TASK [Test bm_power_on] ********************************************************
2026-03-13 10:15:55.316543 | controller | Friday 13 March 2026  10:15:55 +0000 (0:00:00.025)       0:00:02.736 **********
2026-03-13 10:15:55.316572 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/molecule/bm_redfish/tasks/test_power_on.yml for instance
2026-03-13 10:15:55.629954 | controller |
2026-03-13 10:15:55.629973 | controller | TASK [Reset mock to power On] **************************************************
2026-03-13 10:15:55.629980 | controller | Friday 13 March 2026  10:15:55 +0000 (0:00:00.024)       0:00:02.760 **********
2026-03-13 10:15:55.629989 | controller | ok: [instance]
2026-03-13 10:15:55.655691 | controller |
2026-03-13 10:15:55.655740 | controller | TASK [Include bm_power_on] *****************************************************
2026-03-13 10:15:55.655750 | controller | Friday 13 March 2026  10:15:55 +0000 (0:00:00.313)       0:00:03.073 **********
2026-03-13 10:15:55.655763 | controller |
2026-03-13 10:15:55.946644 | controller | TASK [reproducer : Query current power state] **********************************
2026-03-13 10:15:55.946683 | controller | Friday 13 March 2026  10:15:55 +0000 (0:00:00.025)       0:00:03.099 **********
2026-03-13 10:15:55.946696 | controller | ok: [instance]
2026-03-13 10:15:55.964680 | controller |
2026-03-13 10:15:55.964720 | controller | TASK [reproducer : Power on bare metal host] ***********************************
2026-03-13 10:15:55.964728 | controller | Friday 13 March 2026  10:15:55 +0000 (0:00:00.290)       0:00:03.390 **********
2026-03-13 10:15:55.964739 | controller | skipping: [instance]
2026-03-13 10:15:55.964768 | controller |
2026-03-13 10:15:55.964950 | controller | TASK [reproducer : Wait for host POST to complete] *****************************
2026-03-13 10:15:56.263651 | controller | Friday 13 March 2026  10:15:55 +0000 (0:00:00.018)       0:00:03.408 **********
2026-03-13 10:15:56.263714 | controller | ok: [instance]
2026-03-13 10:15:56.263743 | controller |
2026-03-13 10:15:56.263752 | controller | TASK [Query mock state after power_on (already on)] ****************************
2026-03-13 10:15:56.263900 | controller | Friday 13 March 2026  10:15:56 +0000 (0:00:00.298)       0:00:03.707 **********
2026-03-13 10:15:56.578309 | controller | ok: [instance]
2026-03-13 10:15:56.605266 | controller |
2026-03-13 10:15:56.605309 | controller | TASK [Assert host is still On] *************************************************
2026-03-13 10:15:56.605317 | controller | Friday 13 March 2026  10:15:56 +0000 (0:00:00.313)       0:00:04.021 **********
2026-03-13 10:15:56.605328 | controller | ok: [instance] => {
2026-03-13 10:15:56.605359 | controller |     "changed": false,
2026-03-13 10:15:56.605365 | controller |     "msg": "All assertions passed"
2026-03-13 10:15:56.605371 | controller | }
2026-03-13 10:15:56.605382 | controller |
2026-03-13 10:15:56.605390 | controller | TASK [Reset mock to power Off] *************************************************
2026-03-13 10:15:56.914827 | controller | Friday 13 March 2026  10:15:56 +0000 (0:00:00.027)       0:00:04.049 **********
2026-03-13 10:15:56.914871 | controller | ok: [instance]
2026-03-13 10:15:56.945997 | controller |
2026-03-13 10:15:56.946019 | controller | TASK [Include bm_power_on] *****************************************************
2026-03-13 10:15:56.946028 | controller | Friday 13 March 2026  10:15:56 +0000 (0:00:00.309)       0:00:04.358 **********
2026-03-13 10:15:56.946040 | controller |
2026-03-13 10:15:57.238138 | controller | TASK [reproducer : Query current power state] **********************************
2026-03-13 10:15:57.238171 | controller | Friday 13 March 2026  10:15:56 +0000 (0:00:00.031)       0:00:04.389 **********
2026-03-13 10:15:57.238191 | controller | ok: [instance]
2026-03-13 10:15:57.528121 | controller |
2026-03-13 10:15:57.528140 | controller | TASK [reproducer : Power on bare metal host] ***********************************
2026-03-13 10:15:57.528148 | controller | Friday 13 March 2026  10:15:57 +0000 (0:00:00.291)       0:00:04.681 **********
2026-03-13 10:15:57.528156 | controller | ok: [instance]
2026-03-13 10:15:57.834569 | controller |
2026-03-13 10:15:57.834590 | controller | TASK [reproducer : Wait for host POST to complete] *****************************
2026-03-13 10:15:57.834598 | controller | Friday 13 March 2026  10:15:57 +0000 (0:00:00.290)       0:00:04.972 **********
2026-03-13 10:15:57.834607 | controller | ok: [instance]
2026-03-13 10:15:57.834805 | controller |
2026-03-13 10:15:57.834819 | controller | TASK [Query mock state after power_on (was off)] *******************************
2026-03-13 10:15:58.120486 | controller | Friday 13 March 2026  10:15:57 +0000 (0:00:00.306)       0:00:05.278 **********
2026-03-13 10:15:58.120575 | controller | ok: [instance]
2026-03-13 10:15:58.142387 | controller |
2026-03-13 10:15:58.142404 | controller | TASK [Assert host is now On] ***************************************************
2026-03-13 10:15:58.142411 | controller | Friday 13 March 2026  10:15:58 +0000 (0:00:00.285)       0:00:05.564 **********
2026-03-13 10:15:58.142420 | controller | ok: [instance] => {
2026-03-13 10:15:58.167688 | controller |     "changed": false,
2026-03-13 10:15:58.167732 | controller |     "msg": "All assertions passed"
2026-03-13 10:15:58.167742 | controller | }
2026-03-13 10:15:58.167750 | controller |
2026-03-13 10:15:58.167759 | controller | TASK [Test bm_check_usb_boot] **************************************************
2026-03-13 10:15:58.167766 | controller | Friday 13 March 2026  10:15:58 +0000 (0:00:00.022)       0:00:05.586 **********
2026-03-13 10:15:58.167780 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/molecule/bm_redfish/tasks/test_check_usb_boot.yml for instance
2026-03-13 10:15:58.457665 | controller |
2026-03-13 10:15:58.457731 | controller | TASK [Reset mock with usb_boot Enabled] ****************************************
2026-03-13 10:15:58.457742 | controller | Friday 13 March 2026  10:15:58 +0000 (0:00:00.025)       0:00:05.611 **********
2026-03-13 10:15:58.457760 | controller | ok: [instance]
2026-03-13 10:15:58.485360 | controller |
2026-03-13 10:15:58.485397 | controller | TASK [Include bm_check_usb_boot] ***********************************************
2026-03-13 10:15:58.485408 | controller | Friday 13 March 2026  10:15:58 +0000 (0:00:00.289)       0:00:05.901 **********
2026-03-13 10:15:58.485421 | controller |
2026-03-13 10:15:58.800473 | controller | TASK [reproducer : Read GenericUsbBoot BIOS attribute] *************************
2026-03-13 10:15:58.800493 | controller | Friday 13 March 2026  10:15:58 +0000 (0:00:00.028)       0:00:05.929 **********
2026-03-13 10:15:58.800540 | controller | ok: [instance]
2026-03-13 10:15:58.838642 | controller |
2026-03-13 10:15:58.838710 | controller | TASK [reproducer : Set GenericUsbBoot status fact] *****************************
2026-03-13 10:15:58.838724 | controller | Friday 13 March 2026  10:15:58 +0000 (0:00:00.314)       0:00:06.243 **********
2026-03-13 10:15:58.838742 | controller | ok: [instance]
2026-03-13 10:15:58.870210 | controller |
2026-03-13 10:15:58.870246 | controller | TASK [reproducer : Fail if GenericUsbBoot is disabled] *************************
2026-03-13 10:15:58.870258 | controller | Friday 13 March 2026  10:15:58 +0000 (0:00:00.038)       0:00:06.282 **********
2026-03-13 10:15:58.870272 | controller | skipping: [instance]
2026-03-13 10:15:58.899720 | controller |
2026-03-13 10:15:58.899738 | controller | TASK [Assert _usb_boot_enabled is true] ****************************************
2026-03-13 10:15:58.899744 | controller | Friday 13 March 2026  10:15:58 +0000 (0:00:00.031)       0:00:06.314 **********
2026-03-13 10:15:58.899754 | controller | ok: [instance] => {
2026-03-13 10:15:59.218925 | controller |     "changed": false,
2026-03-13 10:15:59.218944 | controller |     "msg": "All assertions passed"
2026-03-13 10:15:59.218953 | controller | }
2026-03-13 10:15:59.218959 | controller |
2026-03-13 10:15:59.218964 | controller | TASK [Reset mock with usb_boot Disabled] ***************************************
2026-03-13 10:15:59.218969 | controller | Friday 13 March 2026  10:15:58 +0000 (0:00:00.029)       0:00:06.343 **********
2026-03-13 10:15:59.218977 | controller | ok: [instance]
2026-03-13 10:15:59.248655 | controller |
2026-03-13 10:15:59.248708 | controller | TASK [Include bm_check_usb_boot (expect failure)] ******************************
2026-03-13 10:15:59.248718 | controller | Friday 13 March 2026  10:15:59 +0000 (0:00:00.319)       0:00:06.662 **********
2026-03-13 10:15:59.248733 | controller |
2026-03-13 10:15:59.542897 | controller | TASK [reproducer : Read GenericUsbBoot BIOS attribute] *************************
2026-03-13 10:15:59.542928 | controller | Friday 13 March 2026  10:15:59 +0000 (0:00:00.029)       0:00:06.692 **********
2026-03-13 10:15:59.542947 | controller | ok: [instance]
2026-03-13 10:15:59.574229 | controller |
2026-03-13 10:15:59.574247 | controller | TASK [reproducer : Set GenericUsbBoot status fact] *****************************
2026-03-13 10:15:59.574254 | controller | Friday 13 March 2026  10:15:59 +0000 (0:00:00.294)       0:00:06.986 **********
2026-03-13 10:15:59.574270 | controller | ok: [instance]
2026-03-13 10:15:59.606497 | controller |
2026-03-13 10:15:59.606539 | controller | TASK [reproducer : Fail if GenericUsbBoot is disabled] *************************
2026-03-13 10:15:59.606546 | controller | Friday 13 March 2026  10:15:59 +0000 (0:00:00.031)       0:00:07.018 **********
2026-03-13 10:15:59.606563 | controller | fatal: [instance]: FAILED! => {"changed": false, "msg": "GenericUsbBoot is Disabled in BIOS. VirtualMedia cannot boot host localhost:8443."}
2026-03-13 10:15:59.612082 | controller |
2026-03-13 10:15:59.636337 | controller | TASK [Assert failure was about GenericUsbBoot] *********************************
2026-03-13 10:15:59.636353 | controller | Friday 13 March 2026  10:15:59 +0000 (0:00:00.037)       0:00:07.055 **********
2026-03-13 10:15:59.636363 | controller | ok: [instance] => {
2026-03-13 10:15:59.668311 | controller |     "changed": false,
2026-03-13 10:15:59.668343 | controller |     "msg": "All assertions passed"
2026-03-13 10:15:59.668357 | controller | }
2026-03-13 10:15:59.668368 | controller |
2026-03-13 10:15:59.668377 | controller | TASK [Test bm_ensure_usb_boot] *************************************************
2026-03-13 10:15:59.668387 | controller | Friday 13 March 2026  10:15:59 +0000 (0:00:00.024)       0:00:07.079 **********
2026-03-13 10:15:59.668403 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/molecule/bm_redfish/tasks/test_ensure_usb_boot.yml for instance
2026-03-13 10:15:59.957616 | controller |
2026-03-13 10:15:59.957641 | controller | TASK [Reset mock with usb_boot Enabled and host Off] ***************************
2026-03-13 10:15:59.957648 | controller | Friday 13 March 2026  10:15:59 +0000 (0:00:00.031)       0:00:07.111 **********
2026-03-13 10:15:59.957658 | controller | ok: [instance]
2026-03-13 10:15:59.990681 | controller |
2026-03-13 10:15:59.990754 | controller | TASK [Include bm_ensure_usb_boot] **********************************************
2026-03-13 10:15:59.990766 | controller | Friday 13 March 2026  10:15:59 +0000 (0:00:00.289)       0:00:07.401 **********
2026-03-13 10:15:59.990784 | controller |
2026-03-13 10:15:59.990849 | controller | TASK [reproducer : Check current GenericUsbBoot state] *************************
2026-03-13 10:16:00.013706 | controller | Friday 13 March 2026  10:15:59 +0000 (0:00:00.033)       0:00:07.434 **********
2026-03-13 10:16:00.013732 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/tasks/bm_check_usb_boot.yml for instance
2026-03-13 10:16:00.013841 | controller |
2026-03-13 10:16:00.013868 | controller | TASK [reproducer : Read GenericUsbBoot BIOS attribute] *************************
2026-03-13 10:16:00.013881 | controller | Friday 13 March 2026  10:16:00 +0000 (0:00:00.023)       0:00:07.457 **********
2026-03-13 10:16:00.298023 | controller | ok: [instance]
2026-03-13 10:16:00.328679 | controller |
2026-03-13 10:16:00.328713 | controller | TASK [reproducer : Set GenericUsbBoot status fact] *****************************
2026-03-13 10:16:00.328723 | controller | Friday 13 March 2026  10:16:00 +0000 (0:00:00.284)       0:00:07.741 **********
2026-03-13 10:16:00.328735 | controller | ok: [instance]
2026-03-13 10:16:00.328792 | controller |
2026-03-13 10:16:00.328820 | controller | TASK [reproducer : Fail if GenericUsbBoot is disabled] *************************
2026-03-13 10:16:00.328836 | controller | Friday 13 March 2026  10:16:00 +0000 (0:00:00.030)       0:00:07.772 **********
2026-03-13 10:16:00.364653 | controller | skipping: [instance]
2026-03-13 10:16:00.364856 | controller |
2026-03-13 10:16:00.364879 | controller | TASK [Query mock state] ********************************************************
2026-03-13 10:16:00.364890 | controller | Friday 13 March 2026  10:16:00 +0000 (0:00:00.035)       0:00:07.807 **********
2026-03-13 10:16:00.662277 | controller | ok: [instance]
2026-03-13 10:16:00.684643 | controller |
2026-03-13 10:16:00.684713 | controller | TASK [Assert host stayed Off (no power cycle needed)] **************************
2026-03-13 10:16:00.684724 | controller | Friday 13 March 2026  10:16:00 +0000 (0:00:00.298)       0:00:08.106 **********
2026-03-13 10:16:00.684741 | controller | ok: [instance] => {
2026-03-13 10:16:00.684791 | controller |     "changed": false,
2026-03-13 10:16:00.684798 | controller |     "msg": "All assertions passed"
2026-03-13 10:16:00.684807 | controller | }
2026-03-13 10:16:00.684968 | controller |
2026-03-13 10:16:00.684996 | controller | TASK [Reset mock with usb_boot Disabled and host Off] **************************
2026-03-13 10:16:00.974884 | controller | Friday 13 March 2026  10:16:00 +0000 (0:00:00.022)       0:00:08.128 **********
2026-03-13 10:16:00.974963 | controller | ok: [instance]
2026-03-13 10:16:00.974995 | controller |
2026-03-13 10:16:00.975005 | controller | TASK [Include bm_ensure_usb_boot with auto-enable] *****************************
2026-03-13 10:16:01.005093 | controller | Friday 13 March 2026  10:16:00 +0000 (0:00:00.290)       0:00:08.418 **********
2026-03-13 10:16:01.005142 | controller |
2026-03-13 10:16:01.028070 | controller | TASK [reproducer : Check current GenericUsbBoot state] *************************
2026-03-13 10:16:01.028090 | controller | Friday 13 March 2026  10:16:01 +0000 (0:00:00.029)       0:00:08.448 **********
2026-03-13 10:16:01.028103 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/tasks/bm_check_usb_boot.yml for instance
2026-03-13 10:16:01.310028 | controller |
2026-03-13 10:16:01.310049 | controller | TASK [reproducer : Read GenericUsbBoot BIOS attribute] *************************
2026-03-13 10:16:01.310062 | controller | Friday 13 March 2026  10:16:01 +0000 (0:00:00.023)       0:00:08.472 **********
2026-03-13 10:16:01.310071 | controller | ok: [instance]
2026-03-13 10:16:01.342388 | controller |
2026-03-13 10:16:01.342410 | controller | TASK [reproducer : Set GenericUsbBoot status fact] *****************************
2026-03-13 10:16:01.342418 | controller | Friday 13 March 2026  10:16:01 +0000 (0:00:00.281)       0:00:08.753 **********
2026-03-13 10:16:01.342427 | controller | ok: [instance]
2026-03-13 10:16:01.374697 | controller |
2026-03-13 10:16:01.374718 | controller | TASK [reproducer : Fail if GenericUsbBoot is disabled] *************************
2026-03-13 10:16:01.374727 | controller | Friday 13 March 2026  10:16:01 +0000 (0:00:00.032)       0:00:08.786 **********
2026-03-13 10:16:01.374740 | controller | fatal: [instance]: FAILED! => {"changed": false, "msg": "GenericUsbBoot is Disabled in BIOS. VirtualMedia cannot boot host localhost:8443."}
2026-03-13 10:16:01.380008 | controller |
2026-03-13 10:16:01.415239 | controller | TASK [reproducer : Fail if auto-enable is off] *********************************
2026-03-13 10:16:01.415253 | controller | Friday 13 March 2026  10:16:01 +0000 (0:00:00.037)       0:00:08.824 **********
2026-03-13 10:16:01.415263 | controller | skipping: [instance]
2026-03-13 10:16:01.723685 | controller |
2026-03-13 10:16:01.723741 | controller | TASK [reproducer : Set GenericUsbBoot BIOS attribute] **************************
2026-03-13 10:16:01.723751 | controller | Friday 13 March 2026  10:16:01 +0000 (0:00:00.034)       0:00:08.858 **********
2026-03-13 10:16:01.723767 | controller | ok: [instance]
2026-03-13 10:16:02.012971 | controller |
2026-03-13 10:16:02.013014 | controller | TASK [reproducer : Create BIOS config job to schedule the change] **************
2026-03-13 10:16:02.013023 | controller | Friday 13 March 2026  10:16:01 +0000 (0:00:00.308)       0:00:09.167 **********
2026-03-13 10:16:02.013035 | controller | ok: [instance]
2026-03-13 10:16:02.038699 | controller |
2026-03-13 10:16:02.038757 | controller | TASK [reproducer : Power off before applying BIOS change] **********************
2026-03-13 10:16:02.038769 | controller | Friday 13 March 2026  10:16:02 +0000 (0:00:00.289)       0:00:09.456 **********
2026-03-13 10:16:02.038785 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/tasks/bm_power_off.yml for instance
2026-03-13 10:16:02.347657 | controller |
2026-03-13 10:16:02.347717 | controller | TASK [reproducer : Query current power state] **********************************
2026-03-13 10:16:02.347725 | controller | Friday 13 March 2026  10:16:02 +0000 (0:00:00.025)       0:00:09.482 **********
2026-03-13 10:16:02.347739 | controller | ok: [instance]
2026-03-13 10:16:02.370708 | controller |
2026-03-13 10:16:02.370772 | controller | TASK [reproducer : Force power off via Redfish] ********************************
2026-03-13 10:16:02.370783 | controller | Friday 13 March 2026  10:16:02 +0000 (0:00:00.308)       0:00:09.791 **********
2026-03-13 10:16:02.370800 | controller | skipping: [instance]
2026-03-13 10:16:02.389342 | controller |
2026-03-13 10:16:02.389376 | controller | TASK [reproducer : Wait for host to power off] *********************************
2026-03-13 10:16:02.389385 | controller | Friday 13 March 2026  10:16:02 +0000 (0:00:00.023)       0:00:09.814 **********
2026-03-13 10:16:02.389397 | controller | skipping: [instance]
2026-03-13 10:16:02.415624 | controller |
2026-03-13 10:16:02.415658 | controller | TASK [reproducer : Power on to apply BIOS config job during POST] **************
2026-03-13 10:16:02.415679 | controller | Friday 13 March 2026  10:16:02 +0000 (0:00:00.018)       0:00:09.832 **********
2026-03-13 10:16:02.415691 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/tasks/bm_power_on.yml for instance
2026-03-13 10:16:02.415719 | controller |
2026-03-13 10:16:02.415727 | controller | TASK [reproducer : Query current power state] **********************************
2026-03-13 10:16:02.415897 | controller | Friday 13 March 2026  10:16:02 +0000 (0:00:00.026)       0:00:09.859 **********
2026-03-13 10:16:02.730119 | controller | ok: [instance]
2026-03-13 10:16:03.034169 | controller |
2026-03-13 10:16:03.034203 | controller | TASK [reproducer : Power on bare metal host] ***********************************
2026-03-13 10:16:03.034211 | controller | Friday 13 March 2026  10:16:02 +0000 (0:00:00.314)       0:00:10.174 **********
2026-03-13 10:16:03.034220 | controller | ok: [instance]
2026-03-13 10:16:03.343217 | controller |
2026-03-13 10:16:03.343237 | controller | TASK [reproducer : Wait for host POST to complete] *****************************
2026-03-13 10:16:03.343245 | controller | Friday 13 March 2026  10:16:03 +0000 (0:00:00.303)       0:00:10.477 **********
2026-03-13 10:16:03.343255 | controller | ok: [instance]
2026-03-13 10:16:03.372686 | controller |
2026-03-13 10:16:03.372739 | controller | TASK [reproducer : Power off after BIOS change applied] ************************
2026-03-13 10:16:03.372750 | controller | Friday 13 March 2026  10:16:03 +0000 (0:00:00.309)       0:00:10.787 **********
2026-03-13 10:16:03.372765 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/tasks/bm_power_off.yml for instance
2026-03-13 10:16:03.669028 | controller |
2026-03-13 10:16:03.669057 | controller | TASK [reproducer : Query current power state] **********************************
2026-03-13 10:16:03.669066 | controller | Friday 13 March 2026  10:16:03 +0000 (0:00:00.029)       0:00:10.816 **********
2026-03-13 10:16:03.669082 | controller | ok: [instance]
2026-03-13 10:16:03.956933 | controller |
2026-03-13 10:16:03.956952 | controller | TASK [reproducer : Force power off via Redfish] ********************************
2026-03-13 10:16:03.956960 | controller | Friday 13 March 2026  10:16:03 +0000 (0:00:00.296)       0:00:11.112 **********
2026-03-13 10:16:03.956969 | controller | ok: [instance]
2026-03-13 10:16:04.266612 | controller |
2026-03-13 10:16:04.266662 | controller | TASK [reproducer : Wait for host to power off] *********************************
2026-03-13 10:16:04.266671 | controller | Friday 13 March 2026  10:16:03 +0000 (0:00:00.287)       0:00:11.400 **********
2026-03-13 10:16:04.266684 | controller | ok: [instance]
2026-03-13 10:16:04.266711 | controller |
2026-03-13 10:16:04.266822 | controller | TASK [Query mock state after auto-enable] **************************************
2026-03-13 10:16:04.266845 | controller | Friday 13 March 2026  10:16:04 +0000 (0:00:00.309)       0:00:11.710 **********
2026-03-13 10:16:04.556218 | controller | ok: [instance]
2026-03-13 10:16:04.584651 | controller |
2026-03-13 10:16:04.584714 | controller | TASK [Assert BIOS updated and host left Off] ***********************************
2026-03-13 10:16:04.584724 | controller | Friday 13 March 2026  10:16:04 +0000 (0:00:00.289)       0:00:12.000 **********
2026-03-13 10:16:04.584738 | controller | ok: [instance] => {
2026-03-13 10:16:04.878691 | controller |     "changed": false,
2026-03-13 10:16:04.878747 | controller |     "msg": "All assertions passed"
2026-03-13 10:16:04.878758 | controller | }
2026-03-13 10:16:04.878766 | controller |
2026-03-13 10:16:04.878774 | controller | TASK [Reset mock with usb_boot Disabled] ***************************************
2026-03-13 10:16:04.878782 | controller | Friday 13 March 2026  10:16:04 +0000 (0:00:00.027)       0:00:12.028 **********
2026-03-13 10:16:04.878798 | controller | ok: [instance]
2026-03-13 10:16:04.878805 | controller |
2026-03-13 10:16:04.878814 | controller | TASK [Include bm_ensure_usb_boot without auto-enable (expect failure)] *********
2026-03-13 10:16:04.912118 | controller | Friday 13 March 2026  10:16:04 +0000 (0:00:00.294)       0:00:12.322 **********
2026-03-13 10:16:04.912150 | controller |
2026-03-13 10:16:04.934979 | controller | TASK [reproducer : Check current GenericUsbBoot state] *************************
2026-03-13 10:16:04.934997 | controller | Friday 13 March 2026  10:16:04 +0000 (0:00:00.033)       0:00:12.356 **********
2026-03-13 10:16:04.935009 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/tasks/bm_check_usb_boot.yml for instance
2026-03-13 10:16:05.242176 | controller |
2026-03-13 10:16:05.242199 | controller | TASK [reproducer : Read GenericUsbBoot BIOS attribute] *************************
2026-03-13 10:16:05.242207 | controller | Friday 13 March 2026  10:16:04 +0000 (0:00:00.022)       0:00:12.378 **********
2026-03-13 10:16:05.242216 | controller | ok: [instance]
2026-03-13 10:16:05.282041 | controller |
2026-03-13 10:16:05.282096 | controller | TASK [reproducer : Set GenericUsbBoot status fact] *****************************
2026-03-13 10:16:05.282106 | controller | Friday 13 March 2026  10:16:05 +0000 (0:00:00.307)       0:00:12.685 **********
2026-03-13 10:16:05.282121 | controller | ok: [instance]
2026-03-13 10:16:05.282151 | controller |
2026-03-13 10:16:05.282162 | controller | TASK [reproducer : Fail if GenericUsbBoot is disabled] *************************
2026-03-13 10:16:05.282323 | controller | Friday 13 March 2026  10:16:05 +0000 (0:00:00.039)       0:00:12.725 **********
2026-03-13 10:16:05.317294 | controller | fatal: [instance]: FAILED! => {"changed": false, "msg": "GenericUsbBoot is Disabled in BIOS. VirtualMedia cannot boot host localhost:8443."}
2026-03-13 10:16:05.323088 | controller |
2026-03-13 10:16:05.357481 | controller | TASK [reproducer : Fail if auto-enable is off] *********************************
2026-03-13 10:16:05.357519 | controller | Friday 13 March 2026  10:16:05 +0000 (0:00:00.040)       0:00:12.766 **********
2026-03-13 10:16:05.357536 | controller | fatal: [instance]: FAILED! => {"changed": false, "msg": "GenericUsbBoot is Disabled in BIOS. VirtualMedia cannot boot host localhost:8443. Set cifmw_bm_agent_enable_usb_boot: true in vars.yaml to allow this playbook to enable it automatically (requires a reboot cycle)."}
2026-03-13 10:16:05.363012 | controller |
2026-03-13 10:16:05.385795 | controller | TASK [Assert failure mentions GenericUsbBoot or auto-enable] *******************
2026-03-13 10:16:05.385813 | controller | Friday 13 March 2026  10:16:05 +0000 (0:00:00.039)       0:00:12.806 **********
2026-03-13 10:16:05.385824 | controller | ok: [instance] => {
2026-03-13 10:16:05.415158 | controller |     "changed": false,
2026-03-13 10:16:05.415191 | controller |     "msg": "All assertions passed"
2026-03-13 10:16:05.415206 | controller | }
2026-03-13 10:16:05.415216 | controller |
2026-03-13 10:16:05.415226 | controller | TASK [Test bm_eject_vmedia] ****************************************************
2026-03-13 10:16:05.415236 | controller | Friday 13 March 2026  10:16:05 +0000 (0:00:00.022)       0:00:12.829 **********
2026-03-13 10:16:05.415251 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/molecule/bm_redfish/tasks/test_eject_vmedia.yml for instance
2026-03-13 10:16:05.415550 | controller |
2026-03-13 10:16:05.415763 | controller | TASK [Reset mock with VirtualMedia inserted] ***********************************
2026-03-13 10:16:05.415902 | controller | Friday 13 March 2026  10:16:05 +0000 (0:00:00.030)       0:00:12.859 **********
2026-03-13 10:16:05.720118 | controller | ok: [instance]
2026-03-13 10:16:05.747686 | controller |
2026-03-13 10:16:05.747737 | controller | TASK [Include bm_eject_vmedia] *************************************************
2026-03-13 10:16:05.747747 | controller | Friday 13 March 2026  10:16:05 +0000 (0:00:00.304)       0:00:13.163 **********
2026-03-13 10:16:05.747762 | controller |
2026-03-13 10:16:06.047556 | controller | TASK [reproducer : Eject VirtualMedia] *****************************************
2026-03-13 10:16:06.047605 | controller | Friday 13 March 2026  10:16:05 +0000 (0:00:00.027)       0:00:13.191 **********
2026-03-13 10:16:06.047618 | controller | ok: [instance]
2026-03-13 10:16:11.077561 | controller |
2026-03-13 10:16:11.077602 | controller | TASK [reproducer : Wait for VirtualMedia eject to settle] **********************
2026-03-13 10:16:11.077610 | controller | Friday 13 March 2026  10:16:06 +0000 (0:00:00.299)       0:00:13.491 **********
2026-03-13 10:16:11.077621 | controller | Pausing for 5 seconds
2026-03-13 10:16:11.375768 | controller | ok: [instance]
2026-03-13 10:16:11.375816 | controller |
2026-03-13 10:16:11.375825 | controller | TASK [Query mock state after eject] ********************************************
2026-03-13 10:16:11.375833 | controller | Friday 13 March 2026  10:16:11 +0000 (0:00:05.029)       0:00:18.521 **********
2026-03-13 10:16:11.375845 | controller | ok: [instance]
2026-03-13 10:16:11.404632 | controller |
2026-03-13 10:16:11.404684 | controller | TASK [Assert VirtualMedia is ejected] ******************************************
2026-03-13 10:16:11.404694 | controller | Friday 13 March 2026  10:16:11 +0000 (0:00:00.298)       0:00:18.819 **********
2026-03-13 10:16:11.404717 | controller | ok: [instance] => {
2026-03-13 10:16:11.405216 | controller |     "changed": false,
2026-03-13 10:16:11.685416 | controller |     "msg": "All assertions passed"
2026-03-13 10:16:11.685442 | controller | }
2026-03-13 10:16:11.685450 | controller |
2026-03-13 10:16:11.685456 | controller | TASK [Reset mock with VirtualMedia not inserted] *******************************
2026-03-13 10:16:11.685461 | controller | Friday 13 March 2026  10:16:11 +0000 (0:00:00.029)       0:00:18.848 **********
2026-03-13 10:16:11.685471 | controller | ok: [instance]
2026-03-13 10:16:11.709349 | controller |
2026-03-13 10:16:11.709393 | controller | TASK [Include bm_eject_vmedia (idempotent)] ************************************
2026-03-13 10:16:11.709406 | controller | Friday 13 March 2026  10:16:11 +0000 (0:00:00.280)       0:00:19.129 **********
2026-03-13 10:16:11.709421 | controller |
2026-03-13 10:16:11.994173 | controller | TASK [reproducer : Eject VirtualMedia] *****************************************
2026-03-13 10:16:11.994220 | controller | Friday 13 March 2026  10:16:11 +0000 (0:00:00.024)       0:00:19.153 **********
2026-03-13 10:16:11.994234 | controller | ok: [instance]
2026-03-13 10:16:17.025666 | controller |
2026-03-13 10:16:17.025714 | controller | TASK [reproducer : Wait for VirtualMedia eject to settle] **********************
2026-03-13 10:16:17.025724 | controller | Friday 13 March 2026  10:16:11 +0000 (0:00:00.283)       0:00:19.437 **********
2026-03-13 10:16:17.025739 | controller | Pausing for 5 seconds
2026-03-13 10:16:17.312277 | controller | ok: [instance]
2026-03-13 10:16:17.312325 | controller |
2026-03-13 10:16:17.312335 | controller | TASK [Query mock state] ********************************************************
2026-03-13 10:16:17.312342 | controller | Friday 13 March 2026  10:16:17 +0000 (0:00:05.031)       0:00:24.469 **********
2026-03-13 10:16:17.312353 | controller | ok: [instance]
2026-03-13 10:16:17.312382 | controller |
2026-03-13 10:16:17.312525 | controller | TASK [Assert VirtualMedia is still not inserted] *******************************
2026-03-13 10:16:17.312659 | controller | Friday 13 March 2026  10:16:17 +0000 (0:00:00.287)       0:00:24.756 **********
2026-03-13 10:16:17.342109 | controller | ok: [instance] => {
2026-03-13 10:16:17.342222 | controller |     "changed": false,
2026-03-13 10:16:17.342322 | controller |     "msg": "All assertions passed"
2026-03-13 10:16:17.342422 | controller | }
2026-03-13 10:16:17.342493 | controller |
2026-03-13 10:16:17.342618 | controller | TASK [Test bm_discover_vmedia_target] ******************************************
2026-03-13 10:16:17.342695 | controller | Friday 13 March 2026  10:16:17 +0000 (0:00:00.029)       0:00:24.786 **********
2026-03-13 10:16:17.377055 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/molecule/bm_redfish/tasks/test_discover_vmedia.yml for instance
2026-03-13 10:16:17.377087 | controller |
2026-03-13 10:16:17.377301 | controller | TASK [Reset mock with VirtualMedia inserted] ***********************************
2026-03-13 10:16:17.377345 | controller | Friday 13 March 2026  10:16:17 +0000 (0:00:00.035)       0:00:24.821 **********
2026-03-13 10:16:17.648827 | controller | ok: [instance]
2026-03-13 10:16:17.648903 | controller |
2026-03-13 10:16:17.649022 | controller | TASK [Include bm_discover_vmedia_target (auto-discover)] ***********************
2026-03-13 10:16:17.649146 | controller | Friday 13 March 2026  10:16:17 +0000 (0:00:00.271)       0:00:25.092 **********
2026-03-13 10:16:17.685093 | controller |
2026-03-13 10:16:17.685175 | controller | TASK [reproducer : Fetch UEFI boot option IDs] *********************************
2026-03-13 10:16:17.685268 | controller | Friday 13 March 2026  10:16:17 +0000 (0:00:00.036)       0:00:25.129 **********
2026-03-13 10:16:17.964489 | controller | ok: [instance]
2026-03-13 10:16:17.964552 | controller |
2026-03-13 10:16:17.964681 | controller | TASK [reproducer : Fetch each UEFI boot option detail] *************************
2026-03-13 10:16:17.964797 | controller | Friday 13 March 2026  10:16:17 +0000 (0:00:00.279)       0:00:25.408 **********
2026-03-13 10:16:19.355603 | controller | ok: [instance] => (item=Boot0001)
2026-03-13 10:16:19.392971 | controller | ok: [instance] => (item=Boot0003)
2026-03-13 10:16:19.393021 | controller | ok: [instance] => (item=Boot0004)
2026-03-13 10:16:19.393028 | controller | ok: [instance] => (item=Boot0005)
2026-03-13 10:16:19.393033 | controller | ok: [instance] => (item=Boot0006)
2026-03-13 10:16:19.393038 | controller |
2026-03-13 10:16:19.393045 | controller | TASK [reproducer : Build list of known UEFI device paths] **********************
2026-03-13 10:16:19.393058 | controller | Friday 13 March 2026  10:16:19 +0000 (0:00:01.390)       0:00:26.798 **********
2026-03-13 10:16:19.393076 | controller | ok: [instance]
2026-03-13 10:16:19.416518 | controller |
2026-03-13 10:16:19.416541 | controller | TASK [reproducer : Validate user-provided VirtualMedia UEFI path] **************
2026-03-13 10:16:19.416549 | controller | Friday 13 March 2026  10:16:19 +0000 (0:00:00.038)       0:00:26.836 **********
2026-03-13 10:16:19.416560 | controller | skipping: [instance]
2026-03-13 10:16:19.482642 | controller |
2026-03-13 10:16:19.482677 | controller | TASK [reproducer : Find Virtual Optical Drive boot path] ***********************
2026-03-13 10:16:19.482688 | controller | Friday 13 March 2026  10:16:19 +0000 (0:00:00.023)       0:00:26.860 **********
2026-03-13 10:16:19.482702 | controller | skipping: [instance] => (item=PXE Device 1: Embedded NIC 1 Port 1 Partition 1)
2026-03-13 10:16:19.506296 | controller | skipping: [instance] => (item=Virtual Floppy Drive)
2026-03-13 10:16:19.506322 | controller | ok: [instance] => (item=Virtual Optical Drive)
2026-03-13 10:16:19.506330 | controller | skipping: [instance] => (item=Integrated RAID Controller 1: Red Hat Enterprise Linux)
2026-03-13 10:16:19.506336 | controller | skipping: [instance] => (item=Generic USB Boot)
2026-03-13 10:16:19.506342 | controller |
2026-03-13 10:16:19.506347 | controller | TASK [reproducer : Fail if no Virtual Optical Drive found] *********************
2026-03-13 10:16:19.506353 | controller | Friday 13 March 2026  10:16:19 +0000 (0:00:00.065)       0:00:26.926 **********
2026-03-13 10:16:19.506362 | controller | skipping: [instance]
2026-03-13 10:16:19.526641 | controller |
2026-03-13 10:16:19.526682 | controller | TASK [reproducer : Show VirtualMedia UEFI boot target] *************************
2026-03-13 10:16:19.526692 | controller | Friday 13 March 2026  10:16:19 +0000 (0:00:00.023)       0:00:26.950 **********
2026-03-13 10:16:19.526704 | controller | ok: [instance] => {
2026-03-13 10:16:19.526734 | controller |     "msg": "VirtualMedia UEFI path: PciRoot(0x0)/Pci(0x14,0x0)/USB(0xD,0x0)/USB(0x0,0x0)/USB(0x2,0x0)/Unit(0x0)"
2026-03-13 10:16:19.526743 | controller | }
2026-03-13 10:16:19.527013 | controller |
2026-03-13 10:16:19.821202 | controller | TASK [reproducer : Clear pending iDRAC config jobs that block boot override] ***
2026-03-13 10:16:19.821224 | controller | Friday 13 March 2026  10:16:19 +0000 (0:00:00.020)       0:00:26.970 **********
2026-03-13 10:16:19.821236 | controller | ok: [instance]
2026-03-13 10:16:29.847089 | controller |
2026-03-13 10:16:29.847144 | controller | TASK [reproducer : Wait for iDRAC to settle after clearing jobs] ***************
2026-03-13 10:16:29.847153 | controller | Friday 13 March 2026  10:16:19 +0000 (0:00:00.294)       0:00:27.265 **********
2026-03-13 10:16:29.847164 | controller | Pausing for 10 seconds
2026-03-13 10:16:30.156566 | controller | ok: [instance]
2026-03-13 10:16:30.156604 | controller |
2026-03-13 10:16:30.156612 | controller | TASK [reproducer : Set one-time boot from Virtual Optical Drive] ***************
2026-03-13 10:16:30.156619 | controller | Friday 13 March 2026  10:16:29 +0000 (0:00:10.025)       0:00:37.290 **********
2026-03-13 10:16:30.156630 | controller | ok: [instance]
2026-03-13 10:16:30.445569 | controller |
2026-03-13 10:16:30.445610 | controller | TASK [reproducer : Verify boot override was applied] ***************************
2026-03-13 10:16:30.445618 | controller | Friday 13 March 2026  10:16:30 +0000 (0:00:00.309)       0:00:37.600 **********
2026-03-13 10:16:30.445629 | controller | ok: [instance]
2026-03-13 10:16:30.476567 | controller |
2026-03-13 10:16:30.476591 | controller | TASK [reproducer : Assert boot override is set correctly] **********************
2026-03-13 10:16:30.476601 | controller | Friday 13 March 2026  10:16:30 +0000 (0:00:00.289)       0:00:37.889 **********
2026-03-13 10:16:30.476622 | controller | ok: [instance] => {
2026-03-13 10:16:30.772395 | controller |     "changed": false,
2026-03-13 10:16:30.772424 | controller |     "msg": "All assertions passed"
2026-03-13 10:16:30.772432 | controller | }
2026-03-13 10:16:30.772438 | controller |
2026-03-13 10:16:30.772444 | controller | TASK [reproducer : Verify VirtualMedia is still inserted] **********************
2026-03-13 10:16:30.772450 | controller | Friday 13 March 2026  10:16:30 +0000 (0:00:00.030)       0:00:37.920 **********
2026-03-13 10:16:30.772460 | controller | ok: [instance]
2026-03-13 10:16:30.818570 | controller |
2026-03-13 10:16:30.818592 | controller | TASK [reproducer : Assert VirtualMedia ISO is mounted] *************************
2026-03-13 10:16:30.818610 | controller | Friday 13 March 2026  10:16:30 +0000 (0:00:00.295)       0:00:38.215 **********
2026-03-13 10:16:30.818622 | controller | ok: [instance] => {
2026-03-13 10:16:30.818958 | controller |     "changed": false,
2026-03-13 10:16:30.818973 | controller |     "msg": "All assertions passed"
2026-03-13 10:16:30.818984 | controller | }
2026-03-13 10:16:30.866486 | controller |
2026-03-13 10:16:30.866521 | controller | TASK [Assert discovered path is Virtual Optical Drive] *************************
2026-03-13 10:16:30.866531 | controller | Friday 13 March 2026  10:16:30 +0000 (0:00:00.046)       0:00:38.262 **********
2026-03-13 10:16:30.866541 | controller | ok: [instance] => {
2026-03-13 10:16:31.182618 | controller |     "changed": false,
2026-03-13 10:16:31.182659 | controller |     "msg": "All assertions passed"
2026-03-13 10:16:31.182669 | controller | }
2026-03-13 10:16:31.182676 | controller |
2026-03-13 10:16:31.182684 | controller | TASK [Query mock state after discover] *****************************************
2026-03-13 10:16:31.182691 | controller | Friday 13 March 2026  10:16:30 +0000 (0:00:00.047)       0:00:38.309 **********
2026-03-13 10:16:31.182704 | controller | ok: [instance]
2026-03-13 10:16:31.182783 | controller |
2026-03-13 10:16:31.182826 | controller | TASK [Assert boot override was set] ********************************************
2026-03-13 10:16:31.211590 | controller | Friday 13 March 2026  10:16:31 +0000 (0:00:00.316)       0:00:38.626 **********
2026-03-13 10:16:31.211616 | controller | ok: [instance] => {
2026-03-13 10:16:31.211644 | controller |     "changed": false,
2026-03-13 10:16:31.211652 | controller |     "msg": "All assertions passed"
2026-03-13 10:16:31.211662 | controller | }
2026-03-13 10:16:31.211966 | controller |
2026-03-13 10:16:31.496393 | controller | TASK [Reset mock with VirtualMedia inserted] ***********************************
2026-03-13 10:16:31.496431 | controller | Friday 13 March 2026  10:16:31 +0000 (0:00:00.029)       0:00:38.655 **********
2026-03-13 10:16:31.496449 | controller | ok: [instance]
2026-03-13 10:16:31.533327 | controller |
2026-03-13 10:16:31.533348 | controller | TASK [Include bm_discover_vmedia_target with valid explicit path] **************
2026-03-13 10:16:31.533357 | controller | Friday 13 March 2026  10:16:31 +0000 (0:00:00.284)       0:00:38.940 **********
2026-03-13 10:16:31.533368 | controller |
2026-03-13 10:16:31.831083 | controller | TASK [reproducer : Fetch UEFI boot option IDs] *********************************
2026-03-13 10:16:31.831121 | controller | Friday 13 March 2026  10:16:31 +0000 (0:00:00.037)       0:00:38.977 **********
2026-03-13 10:16:31.831132 | controller | ok: [instance]
2026-03-13 10:16:33.210578 | controller |
2026-03-13 10:16:33.210615 | controller | TASK [reproducer : Fetch each UEFI boot option detail] *************************
2026-03-13 10:16:33.210623 | controller | Friday 13 March 2026  10:16:31 +0000 (0:00:00.297)       0:00:39.274 **********
2026-03-13 10:16:33.210633 | controller | ok: [instance] => (item=Boot0001)
2026-03-13 10:16:33.210654 | controller | ok: [instance] => (item=Boot0003)
2026-03-13 10:16:33.210662 | controller | ok: [instance] => (item=Boot0004)
2026-03-13 10:16:33.211038 | controller | ok: [instance] => (item=Boot0005)
2026-03-13 10:16:33.250672 | controller | ok: [instance] => (item=Boot0006)
2026-03-13 10:16:33.250711 | controller |
2026-03-13 10:16:33.250720 | controller | TASK [reproducer : Build list of known UEFI device paths] **********************
2026-03-13 10:16:33.250727 | controller | Friday 13 March 2026  10:16:33 +0000 (0:00:01.379)       0:00:40.654 **********
2026-03-13 10:16:33.250739 | controller | ok: [instance]
2026-03-13 10:16:33.291726 | controller |
2026-03-13 10:16:33.291791 | controller | TASK [reproducer : Validate user-provided VirtualMedia UEFI path] **************
2026-03-13 10:16:33.291803 | controller | Friday 13 March 2026  10:16:33 +0000 (0:00:00.039)       0:00:40.694 **********
2026-03-13 10:16:33.291818 | controller | ok: [instance] => {
2026-03-13 10:16:33.291858 | controller |     "changed": false,
2026-03-13 10:16:33.291865 | controller |     "msg": "All assertions passed"
2026-03-13 10:16:33.291876 | controller | }
2026-03-13 10:16:33.292273 | controller |
2026-03-13 10:16:33.292315 | controller | TASK [reproducer : Find Virtual Optical Drive boot path] ***********************
2026-03-13 10:16:33.346514 | controller | Friday 13 March 2026  10:16:33 +0000 (0:00:00.041)       0:00:40.735 **********
2026-03-13 10:16:33.346538 | controller | skipping: [instance] => (item=PXE Device 1: Embedded NIC 1 Port 1 Partition 1)
2026-03-13 10:16:33.368401 | controller | skipping: [instance] => (item=Virtual Floppy Drive)
2026-03-13 10:16:33.368424 | controller | skipping: [instance] => (item=Virtual Optical Drive)
2026-03-13 10:16:33.368442 | controller | skipping: [instance] => (item=Integrated RAID Controller 1: Red Hat Enterprise Linux)
2026-03-13 10:16:33.368450 | controller | skipping: [instance] => (item=Generic USB Boot)
2026-03-13 10:16:33.368457 | controller | skipping: [instance]
2026-03-13 10:16:33.368465 | controller |
2026-03-13 10:16:33.368472 | controller | TASK [reproducer : Fail if no Virtual Optical Drive found] *********************
2026-03-13 10:16:33.368480 | controller | Friday 13 March 2026  10:16:33 +0000 (0:00:00.054)       0:00:40.789 **********
2026-03-13 10:16:33.368490 | controller | skipping: [instance]
2026-03-13 10:16:33.368682 | controller |
2026-03-13 10:16:33.368853 | controller | TASK [reproducer : Show VirtualMedia UEFI boot target] *************************
2026-03-13 10:16:33.369016 | controller | Friday 13 March 2026  10:16:33 +0000 (0:00:00.022)       0:00:40.812 **********
2026-03-13 10:16:33.388359 | controller | ok: [instance] => {
2026-03-13 10:16:33.388581 | controller |     "msg": "VirtualMedia UEFI path: PciRoot(0x0)/Pci(0x14,0x0)/USB(0xD,0x0)/USB(0x0,0x0)/USB(0x2,0x0)/Unit(0x0)"
2026-03-13 10:16:33.388754 | controller | }
2026-03-13 10:16:33.388904 | controller |
2026-03-13 10:16:33.389059 | controller | TASK [reproducer : Clear pending iDRAC config jobs that block boot override] ***
2026-03-13 10:16:33.389231 | controller | Friday 13 March 2026  10:16:33 +0000 (0:00:00.020)       0:00:40.832 **********
2026-03-13 10:16:33.688356 | controller | ok: [instance]
2026-03-13 10:16:43.723655 | controller |
2026-03-13 10:16:43.723714 | controller | TASK [reproducer : Wait for iDRAC to settle after clearing jobs] ***************
2026-03-13 10:16:43.723722 | controller | Friday 13 March 2026  10:16:33 +0000 (0:00:00.299)       0:00:41.132 **********
2026-03-13 10:16:43.723733 | controller | Pausing for 10 seconds
2026-03-13 10:16:44.003154 | controller | ok: [instance]
2026-03-13 10:16:44.003184 | controller |
2026-03-13 10:16:44.003196 | controller | TASK [reproducer : Set one-time boot from Virtual Optical Drive] ***************
2026-03-13 10:16:44.003202 | controller | Friday 13 March 2026  10:16:43 +0000 (0:00:10.034)       0:00:51.166 **********
2026-03-13 10:16:44.003212 | controller | ok: [instance]
2026-03-13 10:16:44.280283 | controller |
2026-03-13 10:16:44.280320 | controller | TASK [reproducer : Verify boot override was applied] ***************************
2026-03-13 10:16:44.280328 | controller | Friday 13 March 2026  10:16:44 +0000 (0:00:00.280)       0:00:51.446 **********
2026-03-13 10:16:44.280339 | controller | ok: [instance]
2026-03-13 10:16:44.309653 | controller |
2026-03-13 10:16:44.309693 | controller | TASK [reproducer : Assert boot override is set correctly] **********************
2026-03-13 10:16:44.309702 | controller | Friday 13 March 2026  10:16:44 +0000 (0:00:00.276)       0:00:51.723 **********
2026-03-13 10:16:44.309714 | controller | ok: [instance] => {
2026-03-13 10:16:44.309745 | controller |     "changed": false,
2026-03-13 10:16:44.309770 | controller |     "msg": "All assertions passed"
2026-03-13 10:16:44.310204 | controller | }
2026-03-13 10:16:44.586025 | controller |
2026-03-13 10:16:44.586067 | controller | TASK [reproducer : Verify VirtualMedia is still inserted] **********************
2026-03-13 10:16:44.586075 | controller | Friday 13 March 2026  10:16:44 +0000 (0:00:00.029)       0:00:51.753 **********
2026-03-13 10:16:44.586086 | controller | ok: [instance]
2026-03-13 10:16:44.626649 | controller |
2026-03-13 10:16:44.626694 | controller | TASK [reproducer : Assert VirtualMedia ISO is mounted] *************************
2026-03-13 10:16:44.626704 | controller | Friday 13 March 2026  10:16:44 +0000 (0:00:00.275)       0:00:52.029 **********
2026-03-13 10:16:44.626723 | controller | ok: [instance] => {
2026-03-13 10:16:44.626752 | controller |     "changed": false,
2026-03-13 10:16:44.626762 | controller |     "msg": "All assertions passed"
2026-03-13 10:16:44.627098 | controller | }
2026-03-13 10:16:44.627134 | controller |
2026-03-13 10:16:44.903043 | controller | TASK [Query mock state] ********************************************************
2026-03-13 10:16:44.903085 | controller | Friday 13 March 2026  10:16:44 +0000 (0:00:00.041)       0:00:52.070 **********
2026-03-13 10:16:44.903097 | controller | ok: [instance]
2026-03-13 10:16:44.929376 | controller |
2026-03-13 10:16:44.929395 | controller | TASK [Assert boot override set with user-provided path] ************************
2026-03-13 10:16:44.929402 | controller | Friday 13 March 2026  10:16:44 +0000 (0:00:00.275)       0:00:52.346 **********
2026-03-13 10:16:44.929410 | controller | ok: [instance] => {
2026-03-13 10:16:45.204533 | controller |     "changed": false,
2026-03-13 10:16:45.204576 | controller |     "msg": "All assertions passed"
2026-03-13 10:16:45.204583 | controller | }
2026-03-13 10:16:45.204589 | controller |
2026-03-13 10:16:45.204595 | controller | TASK [Reset mock with VirtualMedia inserted] ***********************************
2026-03-13 10:16:45.204600 | controller | Friday 13 March 2026  10:16:44 +0000 (0:00:00.026)       0:00:52.373 **********
2026-03-13 10:16:45.204609 | controller | ok: [instance]
2026-03-13 10:16:45.241241 | controller |
2026-03-13 10:16:45.241272 | controller | TASK [Include bm_discover_vmedia_target with invalid path (expect failure)] ****
2026-03-13 10:16:45.241285 | controller | Friday 13 March 2026  10:16:45 +0000 (0:00:00.275)       0:00:52.648 **********
2026-03-13 10:16:45.241299 | controller |
2026-03-13 10:16:45.555215 | controller | TASK [reproducer : Fetch UEFI boot option IDs] *********************************
2026-03-13 10:16:45.555242 | controller | Friday 13 March 2026  10:16:45 +0000 (0:00:00.036)       0:00:52.684 **********
2026-03-13 10:16:45.555256 | controller | ok: [instance]
2026-03-13 10:16:46.902588 | controller |
2026-03-13 10:16:46.902633 | controller | TASK [reproducer : Fetch each UEFI boot option detail] *************************
2026-03-13 10:16:46.902641 | controller | Friday 13 March 2026  10:16:45 +0000 (0:00:00.313)       0:00:52.998 **********
2026-03-13 10:16:46.902652 | controller | ok: [instance] => (item=Boot0001)
2026-03-13 10:16:46.902677 | controller | ok: [instance] => (item=Boot0003)
2026-03-13 10:16:46.903329 | controller | ok: [instance] => (item=Boot0004)
2026-03-13 10:16:46.948670 | controller | ok: [instance] => (item=Boot0005)
2026-03-13 10:16:46.948711 | controller | ok: [instance] => (item=Boot0006)
2026-03-13 10:16:46.948720 | controller |
2026-03-13 10:16:46.948728 | controller | TASK [reproducer : Build list of known UEFI device paths] **********************
2026-03-13 10:16:46.948735 | controller | Friday 13 March 2026  10:16:46 +0000 (0:00:01.347)       0:00:54.346 **********
2026-03-13 10:16:46.948747 | controller | ok: [instance]
2026-03-13 10:16:46.948774 | controller |
2026-03-13 10:16:46.948944 | controller | TASK [reproducer : Validate user-provided VirtualMedia UEFI path] **************
2026-03-13 10:16:46.948977 | controller | Friday 13 March 2026  10:16:46 +0000 (0:00:00.046)       0:00:54.392 **********
2026-03-13 10:16:46.988585 | controller | fatal: [instance]: FAILED! => {
2026-03-13 10:16:46.988860 | controller |     "assertion": "cifmw_bm_agent_vmedia_uefi_path in _known_uefi_paths",
2026-03-13 10:16:46.988873 | controller |     "changed": false,
2026-03-13 10:16:46.988894 | controller |     "evaluated_to": false,
2026-03-13 10:16:46.994235 | controller |     "msg": "cifmw_bm_agent_vmedia_uefi_path 'PciRoot(0x0)/INVALID/PATH' is not listed in UEFI boot options. Available paths: PXE Device 1: Embedded NIC 1 Port 1 Partition 1 -> VenHw(3A191845-5F86-4E78-8FCE-C4CFF59F9DAA), Virtual Floppy Drive -> PciRoot(0x0)/Pci(0x14,0x0)/USB(0xD,0x0)/USB(0x0,0x0)/USB(0x2,0x0)/Unit(0x1), Virtual Optical Drive -> PciRoot(0x0)/Pci(0x14,0x0)/USB(0xD,0x0)/USB(0x0,0x0)/USB(0x2,0x0)/Unit(0x0), Integrated RAID Controller 1: Red Hat Enterprise Linux -> HD(2,GPT,FF726BC2-263F-EE4A-BAE7-7CACE574EBD8,0x1000,0x3F800)/\\EFI\\redhat\\shimx64.efi, Generic USB Boot -> VenHw(0C8CB6CC-13AE-45F4-BBCD-6A25E98AC250)"
2026-03-13 10:16:46.994253 | controller | }
2026-03-13 10:16:46.994264 | controller |
2026-03-13 10:16:47.040668 | controller | TASK [Assert failure was about UEFI path] **************************************
2026-03-13 10:16:47.040707 | controller | Friday 13 March 2026  10:16:46 +0000 (0:00:00.045)       0:00:54.438 **********
2026-03-13 10:16:47.040719 | controller | ok: [instance] => {
2026-03-13 10:16:47.040747 | controller |     "changed": false,
2026-03-13 10:16:47.040756 | controller |     "msg": "All assertions passed"
2026-03-13 10:16:47.041587 | controller | }
2026-03-13 10:16:47.041622 | controller |
2026-03-13 10:16:47.041631 | controller | PLAY RECAP *********************************************************************
2026-03-13 10:16:47.041637 | controller | instance                   : ok=110  changed=0    unreachable=0    failed=0    skipped=12   rescued=5    ignored=0
2026-03-13 10:16:47.041642 | controller |
2026-03-13 10:16:47.041647 | controller | Friday 13 March 2026  10:16:47 +0000 (0:00:00.045)       0:00:54.484 **********
2026-03-13 10:16:47.041653 | controller | ===============================================================================
2026-03-13 10:16:47.041660 | controller | reproducer : Wait for iDRAC to settle after clearing jobs -------------- 10.03s
2026-03-13 10:16:47.041734 | controller | reproducer : Wait for iDRAC to settle after clearing jobs -------------- 10.03s
2026-03-13 10:16:47.041868 | controller | reproducer : Wait for VirtualMedia eject to settle ---------------------- 5.03s
2026-03-13 10:16:47.041961 | controller | reproducer : Wait for VirtualMedia eject to settle ---------------------- 5.03s
2026-03-13 10:16:47.042056 | controller | reproducer : Fetch each UEFI boot option detail ------------------------- 1.39s
2026-03-13 10:16:47.042160 | controller | reproducer : Fetch each UEFI boot option detail ------------------------- 1.38s
2026-03-13 10:16:47.042254 | controller | reproducer : Fetch each UEFI boot option detail ------------------------- 1.35s
2026-03-13 10:16:47.042353 | controller | Reset mock to power Off ------------------------------------------------- 0.40s
2026-03-13 10:16:47.042634 | controller | reproducer : Query current power state ---------------------------------- 0.32s
2026-03-13 10:16:47.042741 | controller | Reset mock with usb_boot Disabled --------------------------------------- 0.32s
2026-03-13 10:16:47.042848 | controller | Query mock state after discover ----------------------------------------- 0.32s
2026-03-13 10:16:47.042962 | controller | reproducer : Query current power state ---------------------------------- 0.31s
2026-03-13 10:16:47.043070 | controller | reproducer : Read GenericUsbBoot BIOS attribute ------------------------- 0.31s
2026-03-13 10:16:47.043174 | controller | Query mock state after power_on (already on) ---------------------------- 0.31s
2026-03-13 10:16:47.043281 | controller | reproducer : Fetch UEFI boot option IDs --------------------------------- 0.31s
2026-03-13 10:16:47.043386 | controller | Reset mock to power On -------------------------------------------------- 0.31s
2026-03-13 10:16:47.043493 | controller | reproducer : Set one-time boot from Virtual Optical Drive --------------- 0.31s
2026-03-13 10:16:47.043618 | controller | reproducer : Wait for host POST to complete ----------------------------- 0.31s
2026-03-13 10:16:47.043728 | controller | Reset mock to power Off ------------------------------------------------- 0.31s
2026-03-13 10:16:47.043835 | controller | reproducer : Wait for host to power off --------------------------------- 0.31s
2026-03-13 10:16:47.137217 | controller | INFO     Running bm_redfish > cleanup
2026-03-13 10:16:47.538375 | controller |
2026-03-13 10:16:47.538491 | controller | PLAY [Cleanup mock iDRAC server] ***********************************************
2026-03-13 10:16:47.538641 | controller |
2026-03-13 10:16:47.538724 | controller | TASK [Stop mock iDRAC server] **************************************************
2026-03-13 10:16:47.538827 | controller | Friday 13 March 2026  10:16:47 +0000 (0:00:00.022)       0:00:00.022 **********
2026-03-13 10:16:47.822385 | controller | fatal: [instance]: FAILED! => {"changed": false, "cmd": "pkill -f 'mock_idrac.py.*--port 8443' || true", "delta": "0:00:00.015413", "end": "2026-03-13 10:16:47.799255", "msg": "non-zero return code", "rc": -15, "start": "2026-03-13 10:16:47.783842", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}
2026-03-13 10:16:47.823609 | controller |
2026-03-13 10:16:47.824115 | controller | PLAY RECAP *********************************************************************
2026-03-13 10:16:47.877641 | controller | instance                   : ok=0    changed=0    unreachable=0    failed=1    skipped=0    rescued=0    ignored=0
2026-03-13 10:16:47.877695 | controller |
2026-03-13 10:16:47.877705 | controller | Friday 13 March 2026  10:16:47 +0000 (0:00:00.286)       0:00:00.308 **********
2026-03-13 10:16:47.877712 | controller | ===============================================================================
2026-03-13 10:16:47.877718 | controller | Stop mock iDRAC server -------------------------------------------------- 0.29s
2026-03-13 10:16:47.877733 | controller | CRITICAL Ansible return code was 2, command was: ['ansible-playbook', '--inventory', '/home/zuul/.cache/molecule/reproducer/bm_redfish/inventory', '--skip-tags', 'molecule-notest,notest', '/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/molecule/bm_redfish/cleanup.yml']
2026-03-13 10:16:47.885899 | controller | WARNING  An error occurred during the test sequence action: 'cleanup'. Cleaning up.
2026-03-13 10:16:47.885928 | controller | INFO     Running bm_redfish > cleanup
2026-03-13 10:16:48.290496 | controller |
2026-03-13 10:16:48.290662 | controller | PLAY [Cleanup mock iDRAC server] ***********************************************
2026-03-13 10:16:48.290769 | controller |
2026-03-13 10:16:48.290884 | controller | TASK [Stop mock iDRAC server] **************************************************
2026-03-13 10:16:48.291004 | controller | Friday 13 March 2026  10:16:48 +0000 (0:00:00.029)       0:00:00.029 **********
2026-03-13 10:16:48.564841 | controller | fatal: [instance]: FAILED! => {"changed": false, "cmd": "pkill -f 'mock_idrac.py.*--port 8443' || true", "delta": "0:00:00.014946", "end": "2026-03-13 10:16:48.542674", "msg": "non-zero return code", "rc": -15, "start": "2026-03-13 10:16:48.527728", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}
2026-03-13 10:16:48.566377 | controller |
2026-03-13 10:16:48.566428 | controller | PLAY RECAP *********************************************************************
2026-03-13 10:16:48.566537 | controller | instance                   : ok=0    changed=0    unreachable=0    failed=1    skipped=0    rescued=0    ignored=0
2026-03-13 10:16:48.566877 | controller |
2026-03-13 10:16:48.621561 | controller | Friday 13 March 2026  10:16:48 +0000 (0:00:00.277)       0:00:00.306 **********
2026-03-13 10:16:48.621584 | controller | ===============================================================================
2026-03-13 10:16:48.621591 | controller | Stop mock iDRAC server -------------------------------------------------- 0.28s
2026-03-13 10:16:48.621601 | controller | CRITICAL Ansible return code was 2, command was: ['ansible-playbook', '--inventory', '/home/zuul/.cache/molecule/reproducer/bm_redfish/inventory', '--skip-tags', 'molecule-notest,notest', '/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/reproducer/molecule/bm_redfish/cleanup.yml']
2026-03-13 10:16:48.622073 | controller | INFO     Writing /tmp/report.html report.
2026-03-13 10:16:49.137098 | controller | ERROR
2026-03-13 10:16:49.137229 | controller | {
2026-03-13 10:16:49.137260 | controller |   "delta": "0:01:00.269279",
2026-03-13 10:16:49.137280 | controller |   "end": "2026-03-13 10:16:48.674879",
2026-03-13 10:16:49.137317 | controller |   "msg": "non-zero return code",
2026-03-13 10:16:49.137337 | controller |   "rc": 2,
2026-03-13 10:16:49.137353 | controller |   "start": "2026-03-13 10:15:48.405600"
2026-03-13 10:16:49.137368 | controller | }
failure
2026-03-13 10:16:49.182716 | 
2026-03-13 10:16:49.182806 | PLAY RECAP
2026-03-13 10:16:49.182858 | controller | ok: 3 changed: 0 unreachable: 0 failed: 1 skipped: 1 rescued: 0 ignored: 0
2026-03-13 10:16:49.182882 | 
2026-03-13 10:16:49.239431 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2026-03-13 10:16:49.240128 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2026-03-13 10:16:49.717188 | 
2026-03-13 10:16:49.717280 | PLAY [Run ci/playbooks/collect-logs.yml]
2026-03-13 10:16:49.735709 | 
2026-03-13 10:16:49.735777 | TASK [Filter out host if needed]
2026-03-13 10:16:49.743724 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2026-03-13 10:16:49.747796 | 
2026-03-13 10:16:49.747859 | TASK [Ensure file is present]
2026-03-13 10:16:50.090780 | controller | ok
2026-03-13 10:16:50.097054 | 
2026-03-13 10:16:50.097120 | TASK [Manage molecule report file]
2026-03-13 10:16:50.621448 | controller | changed
2026-03-13 10:16:50.625905 | 
2026-03-13 10:16:50.625973 | TASK [Check if we get ci-framework-data basedir]
2026-03-13 10:16:50.868369 | controller | ok
2026-03-13 10:16:50.873272 | 
2026-03-13 10:16:50.873352 | TASK [Create ci-framework-data log directory for zuul]
2026-03-13 10:16:51.226515 | controller | changed
2026-03-13 10:16:51.231716 | 
2026-03-13 10:16:51.231780 | TASK [Copy ci-framework interesting files]
2026-03-13 10:16:51.494950 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory
2026-03-13 10:16:51.757468 | controller | changed
2026-03-13 10:16:51.762052 | 
2026-03-13 10:16:51.762115 | TASK [Get SELinux listing]
2026-03-13 10:16:52.285415 | controller | changed
2026-03-13 10:16:52.290399 | 
2026-03-13 10:16:52.290460 | TASK [Generate log index]
2026-03-13 10:16:53.344103 | controller | changed
2026-03-13 10:16:53.348914 | 
2026-03-13 10:16:53.348985 | TASK [Get some env related data]
2026-03-13 10:16:53.998105 | controller | /home/zuul/.local/bin/ansible
2026-03-13 10:16:54.876392 | controller | changed
2026-03-13 10:16:54.881544 | 
2026-03-13 10:16:54.881608 | TASK [Generate list of logs to collect in home directory]
2026-03-13 10:16:55.224878 | controller | ok: All paths examined
2026-03-13 10:16:55.248326 | 
2026-03-13 10:16:55.248404 | LOOP [Copy logs from home directory]
2026-03-13 10:16:55.833081 | controller | changed:
2026-03-13 10:16:55.833272 | controller | {
2026-03-13 10:16:55.833319 | controller |   "atime": 1772005405.932821,
2026-03-13 10:16:55.833343 | controller |   "ctime": 1772006396.9238591,
2026-03-13 10:16:55.833361 | controller |   "dev": 64513,
2026-03-13 10:16:55.833382 | controller |   "gid": 1000,
2026-03-13 10:16:55.833399 | controller |   "gr_name": "zuul",
2026-03-13 10:16:55.833415 | controller |   "inode": 2773,
2026-03-13 10:16:55.833429 | controller |   "isblk": false,
2026-03-13 10:16:55.833445 | controller |   "ischr": false,
2026-03-13 10:16:55.833460 | controller |   "isdir": false,
2026-03-13 10:16:55.833475 | controller |   "isfifo": false,
2026-03-13 10:16:55.833490 | controller |   "isgid": false,
2026-03-13 10:16:55.833503 | controller |   "islnk": false,
2026-03-13 10:16:55.833517 | controller |   "isreg": true,
2026-03-13 10:16:55.833531 | controller |   "issock": false,
2026-03-13 10:16:55.833545 | controller |   "isuid": false,
2026-03-13 10:16:55.833558 | controller |   "mode": "0644",
2026-03-13 10:16:55.833571 | controller |   "mtime": 1772006396.9238591,
2026-03-13 10:16:55.833584 | controller |   "nlink": 1,
2026-03-13 10:16:55.833598 | controller |   "path": "/home/zuul/crc-setup.log",
2026-03-13 10:16:55.833618 | controller |   "pw_name": "zuul",
2026-03-13 10:16:55.833633 | controller |   "rgrp": true,
2026-03-13 10:16:55.833649 | controller |   "roth": true,
2026-03-13 10:16:55.833665 | controller |   "rusr": true,
2026-03-13 10:16:55.833680 | controller |   "size": 4108,
2026-03-13 10:16:55.833694 | controller |   "uid": 1000,
2026-03-13 10:16:55.833708 | controller |   "wgrp": false,
2026-03-13 10:16:55.833723 | controller |   "woth": false,
2026-03-13 10:16:55.833741 | controller |   "wusr": true,
2026-03-13 10:16:55.833766 | controller |   "xgrp": false,
2026-03-13 10:16:55.833781 | controller |   "xoth": false,
2026-03-13 10:16:55.833796 | controller |   "xusr": false
2026-03-13 10:16:55.833810 | controller | }
2026-03-13 10:16:56.389086 | controller | changed:
2026-03-13 10:16:56.389231 | controller | {
2026-03-13 10:16:56.389264 | controller |   "atime": 1772006398.6759083,
2026-03-13 10:16:56.389286 | controller |   "ctime": 1772007098.5537844,
2026-03-13 10:16:56.389336 | controller |   "dev": 64513,
2026-03-13 10:16:56.389357 | controller |   "gid": 1000,
2026-03-13 10:16:56.389373 | controller |   "gr_name": "zuul",
2026-03-13 10:16:56.389389 | controller |   "inode": 359205,
2026-03-13 10:16:56.389404 | controller |   "isblk": false,
2026-03-13 10:16:56.389427 | controller |   "ischr": false,
2026-03-13 10:16:56.389441 | controller |   "isdir": false,
2026-03-13 10:16:56.389455 | controller |   "isfifo": false,
2026-03-13 10:16:56.389468 | controller |   "isgid": false,
2026-03-13 10:16:56.389487 | controller |   "islnk": false,
2026-03-13 10:16:56.389500 | controller |   "isreg": true,
2026-03-13 10:16:56.389514 | controller |   "issock": false,
2026-03-13 10:16:56.389527 | controller |   "isuid": false,
2026-03-13 10:16:56.389542 | controller |   "mode": "0644",
2026-03-13 10:16:56.389556 | controller |   "mtime": 1772007098.5537844,
2026-03-13 10:16:56.389571 | controller |   "nlink": 1,
2026-03-13 10:16:56.389585 | controller |   "path": "/home/zuul/crc-start.log",
2026-03-13 10:16:56.389599 | controller |   "pw_name": "zuul",
2026-03-13 10:16:56.389614 | controller |   "rgrp": true,
2026-03-13 10:16:56.389628 | controller |   "roth": true,
2026-03-13 10:16:56.389642 | controller |   "rusr": true,
2026-03-13 10:16:56.389655 | controller |   "size": 4654,
2026-03-13 10:16:56.389669 | controller |   "uid": 1000,
2026-03-13 10:16:56.389683 | controller |   "wgrp": false,
2026-03-13 10:16:56.389697 | controller |   "woth": false,
2026-03-13 10:16:56.389710 | controller |   "wusr": true,
2026-03-13 10:16:56.389723 | controller |   "xgrp": false,
2026-03-13 10:16:56.389737 | controller |   "xoth": false,
2026-03-13 10:16:56.389752 | controller |   "xusr": false
2026-03-13 10:16:56.389765 | controller | }
2026-03-13 10:16:56.927820 | controller | changed:
2026-03-13 10:16:56.927896 | controller | {
2026-03-13 10:16:56.927921 | controller |   "atime": 1773396929.720076,
2026-03-13 10:16:56.927956 | controller |   "ctime": 1773396945.9975975,
2026-03-13 10:16:56.927975 | controller |   "dev": 64513,
2026-03-13 10:16:56.927998 | controller |   "gid": 1000,
2026-03-13 10:16:56.928017 | controller |   "gr_name": "zuul",
2026-03-13 10:16:56.928036 | controller |   "inode": 1188425,
2026-03-13 10:16:56.928051 | controller |   "isblk": false,
2026-03-13 10:16:56.928066 | controller |   "ischr": false,
2026-03-13 10:16:56.928081 | controller |   "isdir": false,
2026-03-13 10:16:56.928095 | controller |   "isfifo": false,
2026-03-13 10:16:56.928109 | controller |   "isgid": false,
2026-03-13 10:16:56.928123 | controller |   "islnk": false,
2026-03-13 10:16:56.928136 | controller |   "isreg": true,
2026-03-13 10:16:56.928150 | controller |   "issock": false,
2026-03-13 10:16:56.928164 | controller |   "isuid": false,
2026-03-13 10:16:56.928177 | controller |   "mode": "0644",
2026-03-13 10:16:56.928190 | controller |   "mtime": 1773396945.9975975,
2026-03-13 10:16:56.928204 | controller |   "nlink": 1,
2026-03-13 10:16:56.928218 | controller |   "path": "/home/zuul/ansible.log",
2026-03-13 10:16:56.928232 | controller |   "pw_name": "zuul",
2026-03-13 10:16:56.928247 | controller |   "rgrp": true,
2026-03-13 10:16:56.928261 | controller |   "roth": true,
2026-03-13 10:16:56.928278 | controller |   "rusr": true,
2026-03-13 10:16:56.928293 | controller |   "size": 6749,
2026-03-13 10:16:56.928331 | controller |   "uid": 1000,
2026-03-13 10:16:56.928347 | controller |   "wgrp": false,
2026-03-13 10:16:56.928361 | controller |   "woth": false,
2026-03-13 10:16:56.928375 | controller |   "wusr": true,
2026-03-13 10:16:56.928389 | controller |   "xgrp": false,
2026-03-13 10:16:56.928402 | controller |   "xoth": false,
2026-03-13 10:16:56.928416 | controller |   "xusr": false
2026-03-13 10:16:56.928429 | controller | }
2026-03-13 10:16:56.942906 | 
2026-03-13 10:16:56.942978 | TASK [Copy crio stats log file]
2026-03-13 10:16:56.955716 | controller | skipping: Conditional result was False
2026-03-13 10:16:56.960746 | 
2026-03-13 10:16:56.960811 | TASK [Get SELinux related data]
2026-03-13 10:16:57.243409 | controller | <no matches>
2026-03-13 10:16:57.485856 | controller | ERROR
2026-03-13 10:16:57.486001 | controller | {
2026-03-13 10:16:57.486044 | controller |   "delta": "0:00:00.015561",
2026-03-13 10:16:57.486065 | controller |   "end": "2026-03-13 10:16:57.245100",
2026-03-13 10:16:57.486082 | controller |   "msg": "non-zero return code",
2026-03-13 10:16:57.486098 | controller |   "rc": 1,
2026-03-13 10:16:57.486114 | controller |   "start": "2026-03-13 10:16:57.229539"
2026-03-13 10:16:57.486129 | controller | }
2026-03-13 10:16:57.486150 | controller | ERROR: Ignoring Errors
2026-03-13 10:16:57.490822 | 
2026-03-13 10:16:57.490883 | TASK [Create system configuration directory]
2026-03-13 10:16:57.742450 | controller | changed
2026-03-13 10:16:57.747152 | 
2026-03-13 10:16:57.747217 | TASK [Get some of the system configurations]
2026-03-13 10:16:58.271494 | controller | changed
2026-03-13 10:16:58.277213 | 
2026-03-13 10:16:58.277338 | TASK [Copy generated documentation if available]
2026-03-13 10:16:58.290880 | controller | skipping: Conditional result was False
2026-03-13 10:16:58.296655 | 
2026-03-13 10:16:58.296737 | TASK [Copy generated AsciiDoc documentation if available]
2026-03-13 10:16:58.310629 | controller | skipping: Conditional result was False
2026-03-13 10:16:58.315749 | 
2026-03-13 10:16:58.315822 | TASK [Compress logs bigger than 2MB]
2026-03-13 10:16:58.842841 | controller | changed
2026-03-13 10:16:58.847705 | 
2026-03-13 10:16:58.847771 | TASK [Copy files from workspace on node]
2026-03-13 10:16:58.865247 | controller | ok
2026-03-13 10:16:58.886052 | 
2026-03-13 10:16:58.886119 | TASK [fetch-output : Set log path for multiple nodes]
2026-03-13 10:16:58.898981 | controller | skipping: Conditional result was False
2026-03-13 10:16:58.904280 | 
2026-03-13 10:16:58.904363 | TASK [fetch-output : Set log path for single node]
2026-03-13 10:16:58.932862 | controller | ok
2026-03-13 10:16:58.937569 | 
2026-03-13 10:16:58.937631 | LOOP [fetch-output : Ensure local output dirs]
2026-03-13 10:16:59.121752 | controller -> localhost | ok: "/var/lib/zuul/builds/d70368b102fb4619967560b1a46c331a/work/logs"
2026-03-13 10:16:59.121989 | controller -> localhost | changed: All items complete
2026-03-13 10:16:59.122021 | 
2026-03-13 10:16:59.291448 | controller -> localhost | changed: "/var/lib/zuul/builds/d70368b102fb4619967560b1a46c331a/work/artifacts"
2026-03-13 10:16:59.464698 | controller -> localhost | changed: "/var/lib/zuul/builds/d70368b102fb4619967560b1a46c331a/work/docs"
2026-03-13 10:16:59.473794 | 
2026-03-13 10:16:59.473864 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-03-13 10:17:00.062952 | controller | changed:
2026-03-13 10:17:00.063177 | controller | .d..t...... ./
2026-03-13 10:17:00.063214 | controller | >f+++++++++ README.html
2026-03-13 10:17:00.063237 | controller | >f+++++++++ ansible-execution.log
2026-03-13 10:17:00.063258 | controller | >f+++++++++ ansible.log
2026-03-13 10:17:00.063277 | controller | >f+++++++++ crc-setup.log
2026-03-13 10:17:00.063310 | controller | >f+++++++++ crc-start.log
2026-03-13 10:17:00.063335 | controller | >f+++++++++ dmesg.log
2026-03-13 10:17:00.063356 | controller | >f+++++++++ installed-pkgs.log
2026-03-13 10:17:00.063374 | controller | >f+++++++++ python.log
2026-03-13 10:17:00.063390 | controller | >f+++++++++ registries.conf
2026-03-13 10:17:00.063406 | controller | >f+++++++++ report.html
2026-03-13 10:17:00.063420 | controller | >f+++++++++ selinux-denials.log
2026-03-13 10:17:00.063435 | controller | >f+++++++++ selinux-listing.log
2026-03-13 10:17:00.063458 | controller | cd+++++++++ ci-framework-data/
2026-03-13 10:17:00.063473 | controller | cd+++++++++ ci-framework-data/artifacts/
2026-03-13 10:17:00.063489 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2026-03-13 10:17:00.063504 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2026-03-13 10:17:00.063519 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2026-03-13 10:17:00.063533 | controller | cd+++++++++ ci-framework-data/logs/
2026-03-13 10:17:00.063548 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2026-03-13 10:17:00.063562 | controller | cd+++++++++ registries.conf.d/
2026-03-13 10:17:00.063577 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2026-03-13 10:17:00.063593 | controller | cd+++++++++ system-config/
2026-03-13 10:17:00.063608 | controller | cd+++++++++ system-config/libvirt/
2026-03-13 10:17:00.063624 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2026-03-13 10:17:00.063639 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2026-03-13 10:17:00.063654 | controller | >f+++++++++ system-config/libvirt/libvirtd.conf
2026-03-13 10:17:00.063668 | controller | >f+++++++++ system-config/libvirt/network.conf
2026-03-13 10:17:00.063683 | controller | >f+++++++++ system-config/libvirt/qemu-lockd.conf
2026-03-13 10:17:00.063698 | controller | >f+++++++++ system-config/libvirt/qemu.conf
2026-03-13 10:17:00.063712 | controller | >f+++++++++ system-config/libvirt/virtinterfaced.conf
2026-03-13 10:17:00.063726 | controller | >f+++++++++ system-config/libvirt/virtlockd.conf
2026-03-13 10:17:00.063740 | controller | >f+++++++++ system-config/libvirt/virtlogd.conf
2026-03-13 10:17:00.063754 | controller | >f+++++++++ system-config/libvirt/virtnetworkd.conf
2026-03-13 10:17:00.063768 | controller | >f+++++++++ system-config/libvirt/virtnodedevd.conf
2026-03-13 10:17:00.063782 | controller | >f+++++++++ system-config/libvirt/virtnwfilterd.conf
2026-03-13 10:17:00.063796 | controller | >f+++++++++ system-config/libvirt/virtproxyd.conf
2026-03-13 10:17:00.063810 | controller | >f+++++++++ system-config/libvirt/virtqemud.conf
2026-03-13 10:17:00.063823 | controller | >f+++++++++ system-config/libvirt/virtsecretd.conf
2026-03-13 10:17:00.063837 | controller | >f+++++++++ system-config/libvirt/virtstoraged.conf
2026-03-13 10:17:00.515077 | controller | changed: .d..t...... ./
2026-03-13 10:17:00.946729 | controller | changed: .d..t...... ./
2026-03-13 10:17:00.965963 | 
2026-03-13 10:17:00.966028 | TASK [Return artifact to Zuul]
2026-03-13 10:17:00.994569 | controller | ok
2026-03-13 10:17:01.013226 | 
2026-03-13 10:17:01.013312 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2026-03-13 10:17:01.013418 | 
2026-03-13 10:17:01.013447 | PLAY RECAP
2026-03-13 10:17:01.013484 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2026-03-13 10:17:01.013506 | 
2026-03-13 10:17:01.085009 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2026-03-13 10:17:01.085750 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2026-03-13 10:17:01.580507 | 
2026-03-13 10:17:01.580629 | PLAY [all]
2026-03-13 10:17:01.598420 | 
2026-03-13 10:17:01.598493 | TASK [include_role : fetch-output]
2026-03-13 10:17:01.626436 | controller | ok
2026-03-13 10:17:01.642589 | 
2026-03-13 10:17:01.642673 | TASK [fetch-output : Set log path for multiple nodes]
2026-03-13 10:17:01.686041 | controller | skipping: Conditional result was False
2026-03-13 10:17:01.691453 | 
2026-03-13 10:17:01.691532 | TASK [fetch-output : Set log path for single node]
2026-03-13 10:17:01.719321 | controller | ok
2026-03-13 10:17:01.724135 | 
2026-03-13 10:17:01.724201 | LOOP [fetch-output : Ensure local output dirs]
2026-03-13 10:17:02.036597 | controller -> localhost | ok: "/var/lib/zuul/builds/d70368b102fb4619967560b1a46c331a/work/logs"
2026-03-13 10:17:02.214335 | controller -> localhost | ok: "/var/lib/zuul/builds/d70368b102fb4619967560b1a46c331a/work/artifacts"
2026-03-13 10:17:02.385395 | controller -> localhost | ok: "/var/lib/zuul/builds/d70368b102fb4619967560b1a46c331a/work/docs"
2026-03-13 10:17:02.393649 | 
2026-03-13 10:17:02.393717 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-03-13 10:17:02.994970 | controller | ok
2026-03-13 10:17:02.995148 | controller | ok: All items complete
2026-03-13 10:17:02.995177 | 
2026-03-13 10:17:03.420312 | controller | ok
2026-03-13 10:17:03.835889 | controller | ok
2026-03-13 10:17:03.847760 | 
2026-03-13 10:17:03.847825 | TASK [include_role : fetch-output-openshift]
2026-03-13 10:17:03.860617 | controller | skipping: Conditional result was False
2026-03-13 10:17:03.866036 | 
2026-03-13 10:17:03.866111 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-03-13 10:17:04.170984 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.005349
2026-03-13 10:17:04.342347 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.005968
2026-03-13 10:17:04.367768 | 
2026-03-13 10:17:04.367837 | PLAY [all]
2026-03-13 10:17:04.380454 | 
2026-03-13 10:17:04.380516 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-03-13 10:17:04.804687 | controller | changed
2026-03-13 10:17:04.825872 | 
2026-03-13 10:17:04.825937 | PLAY RECAP
2026-03-13 10:17:04.825983 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2026-03-13 10:17:04.826005 | 
2026-03-13 10:17:04.887898 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2026-03-13 10:17:04.888618 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2026-03-13 10:17:05.396616 | 
2026-03-13 10:17:05.396715 | PLAY [localhost]
2026-03-13 10:17:05.412258 | 
2026-03-13 10:17:05.412343 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-03-13 10:17:05.692491 | localhost | changed
2026-03-13 10:17:05.696878 | 
2026-03-13 10:17:05.696973 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-03-13 10:17:05.714537 | localhost | ok
2026-03-13 10:17:05.721854 | 
2026-03-13 10:17:05.721928 | TASK [add-fileserver : Create SSH private key tempfile]
2026-03-13 10:17:06.001857 | localhost | changed
2026-03-13 10:17:06.007369 | 
2026-03-13 10:17:06.007449 | TASK [add-fileserver : Create SSH private key from secret]
2026-03-13 10:17:06.499437 | localhost | changed
2026-03-13 10:17:06.503980 | 
2026-03-13 10:17:06.504044 | TASK [add-fileserver : Add fileserver ssh key]
2026-03-13 10:17:06.814613 | localhost | Identity added: /var/lib/zuul/builds/d70368b102fb4619967560b1a46c331a/work/tmp/ansible.9amunnz_ (/var/lib/zuul/builds/d70368b102fb4619967560b1a46c331a/work/tmp/ansible.9amunnz_)
2026-03-13 10:17:06.814771 | localhost | ok: Runtime: 0:00:00.006393
2026-03-13 10:17:06.818948 | 
2026-03-13 10:17:06.819018 | TASK [add-fileserver : Remove SSH private key from disk]
2026-03-13 10:17:07.028281 | localhost | ok: Runtime: 0:00:00.004013
2026-03-13 10:17:07.032704 | 
2026-03-13 10:17:07.032772 | TASK [add-fileserver : Add fileserver to inventory]
2026-03-13 10:17:07.080242 | localhost | changed
2026-03-13 10:17:07.084780 | 
2026-03-13 10:17:07.084847 | TASK [add-fileserver : Add fileserver server to known hosts]
2026-03-13 10:17:07.385030 | localhost | changed
2026-03-13 10:17:07.403211 | 
2026-03-13 10:17:07.403267 | PLAY [localhost]
2026-03-13 10:17:07.414262 | 
2026-03-13 10:17:07.414334 | TASK [Generate bulk log download script]
2026-03-13 10:17:07.432362 | localhost | ok
2026-03-13 10:17:07.443053 | 
2026-03-13 10:17:07.443120 | TASK [local-log-download : Check API endpoint is defined]
2026-03-13 10:17:07.470177 | localhost | ok: All assertions passed
2026-03-13 10:17:07.474085 | 
2026-03-13 10:17:07.474146 | TASK [local-log-download : Create download script]
2026-03-13 10:17:07.811144 | localhost -> localhost | changed
2026-03-13 10:17:07.819003 | 
2026-03-13 10:17:07.819068 | TASK [Register quick-download link]
2026-03-13 10:17:07.836027 | localhost | ok
2026-03-13 10:17:07.866194 | 
2026-03-13 10:17:07.866262 | PLAY [logserver.rdoproject.org]
2026-03-13 10:17:07.875158 | 
2026-03-13 10:17:07.875215 | TASK [Set zuul-log-path fact]
2026-03-13 10:17:07.890659 | logserver.rdoproject.org | ok
2026-03-13 10:17:07.898732 | 
2026-03-13 10:17:07.898796 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-03-13 10:17:07.913718 | logserver.rdoproject.org | ok
2026-03-13 10:17:07.918419 | 
2026-03-13 10:17:07.918478 | TASK [upload-logs : Create log directories]
2026-03-13 10:17:09.649204 | logserver.rdoproject.org | changed
2026-03-13 10:17:09.652341 | 
2026-03-13 10:17:09.652402 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-03-13 10:17:09.858560 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.004713
2026-03-13 10:17:09.862665 | 
2026-03-13 10:17:09.862723 | TASK [upload-logs : Upload logs to log server]
2026-03-13 10:17:11.279218 | logserver.rdoproject.org | Output suppressed because no_log was given
2026-03-13 10:17:11.281853 | 
2026-03-13 10:17:11.281924 | LOOP [upload-logs : Compress console log and json output]
2026-03-13 10:17:11.317348 | logserver.rdoproject.org | skipping: Conditional result was False
2026-03-13 10:17:11.324725 | logserver.rdoproject.org | skipping: Conditional result was False
2026-03-13 10:17:11.329080 | 
2026-03-13 10:17:11.329147 | LOOP [upload-logs : Upload compressed console log and json output]
2026-03-13 10:17:11.360848 | logserver.rdoproject.org | skipping: Conditional result was False
2026-03-13 10:17:11.361026 | 
2026-03-13 10:17:11.363900 | logserver.rdoproject.org | skipping: Conditional result was False
2026-03-13 10:17:11.375954 | 
2026-03-13 10:17:11.376017 | LOOP [upload-logs : Upload console log and json output]