2026-03-19 12:41:44.914971 | Job console starting...
2026-03-19 12:41:45.127952 | Updating repositories
2026-03-19 12:41:45.859537 | Preparing job workspace
2026-03-19 12:41:53.216607 | Running Ansible setup...
2026-03-19 12:41:56.179475 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2026-03-19 12:41:56.693255 | 
2026-03-19 12:41:56.693373 | PLAY [localhost]
2026-03-19 12:41:56.709609 | 
2026-03-19 12:41:56.709680 | TASK [Gathering Facts]
2026-03-19 12:41:57.534136 | localhost | ok
2026-03-19 12:41:57.546958 | 
2026-03-19 12:41:57.547060 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-03-19 12:41:57.867410 | localhost -> localhost | changed
2026-03-19 12:41:57.872964 | 
2026-03-19 12:41:57.873056 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-03-19 12:41:58.636477 | localhost -> localhost | changed
2026-03-19 12:41:58.645094 | 
2026-03-19 12:41:58.645182 | TASK [Setup log path fact]
2026-03-19 12:41:58.664599 | localhost | ok
2026-03-19 12:41:58.677569 | 
2026-03-19 12:41:58.677648 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-03-19 12:41:58.715899 | localhost | ok
2026-03-19 12:41:58.723359 | 
2026-03-19 12:41:58.723433 | TASK [emit-job-header : Print job information]
2026-03-19 12:41:58.772003 | # Job Information
2026-03-19 12:41:58.772140 | Ansible Version: 2.15.12
2026-03-19 12:41:58.772170 | Job: cifmw-molecule-bm_sno
2026-03-19 12:41:58.772193 | Pipeline: github-check
2026-03-19 12:41:58.772214 | Executor: ibm-bm4-ze.softwarefactory-project.io
2026-03-19 12:41:58.772233 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3739
2026-03-19 12:41:58.772253 | Log URL (when completed): https://logserver.rdoproject.org/cd8/rdoproject.org/cd8ff0e6062f4fd3b8b02c28055504c2/
2026-03-19 12:41:58.772273 | Event ID: d7daf5b0-2390-11f1-8b40-66c1dfe8887a
2026-03-19 12:41:58.775963 | 
2026-03-19 12:41:58.776041 | LOOP [emit-job-header : Print node information]
2026-03-19 12:41:58.877969 | localhost | ok:
2026-03-19 12:41:58.878206 | localhost | # Node Information
2026-03-19 12:41:58.878238 | localhost | Inventory Hostname: controller
2026-03-19 12:41:58.878265 | localhost | Hostname: np0005651926
2026-03-19 12:41:58.878286 | localhost | Username: zuul
2026-03-19 12:41:58.878344 | localhost | Distro: CentOS 9
2026-03-19 12:41:58.878366 | localhost | Provider: ibm-bm4-nodepool
2026-03-19 12:41:58.878383 | localhost | Region: regionOne
2026-03-19 12:41:58.878400 | localhost | Label: cloud-centos-9-stream-tripleo-ibm
2026-03-19 12:41:58.878423 | localhost | Product Name: OpenStack Compute
2026-03-19 12:41:58.878442 | localhost | Interface IP: 192.168.26.241
2026-03-19 12:41:58.901862 | 
2026-03-19 12:41:58.901936 | PLAY [all]
2026-03-19 12:41:58.908555 | 
2026-03-19 12:41:58.908625 | TASK [Gather network facts]
2026-03-19 12:41:59.290163 | controller | ok
2026-03-19 12:41:59.304870 | 
2026-03-19 12:41:59.304952 | TASK [include_role : start-zuul-console]
2026-03-19 12:41:59.326071 | controller | ok
2026-03-19 12:41:59.337737 | 
2026-03-19 12:41:59.337806 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-03-19 12:41:59.701780 | controller | ok
2026-03-19 12:41:59.710421 | 
2026-03-19 12:41:59.710499 | TASK [include_role : add-build-sshkey]
2026-03-19 12:41:59.731358 | controller | ok
2026-03-19 12:41:59.744013 | 
2026-03-19 12:41:59.744082 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-03-19 12:41:59.940266 | controller -> localhost | ok
2026-03-19 12:41:59.945860 | 
2026-03-19 12:41:59.945936 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-03-19 12:41:59.974869 | controller | ok
2026-03-19 12:41:59.987996 | controller | included: /var/lib/zuul/builds/cd8ff0e6062f4fd3b8b02c28055504c2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-03-19 12:41:59.993832 | 
2026-03-19 12:41:59.993905 | TASK [add-build-sshkey : Create Temp SSH key]
2026-03-19 12:42:00.464333 | controller -> localhost | Generating public/private rsa key pair.
2026-03-19 12:42:00.464563 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/cd8ff0e6062f4fd3b8b02c28055504c2/work/cd8ff0e6062f4fd3b8b02c28055504c2_id_rsa.
2026-03-19 12:42:00.464598 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/cd8ff0e6062f4fd3b8b02c28055504c2/work/cd8ff0e6062f4fd3b8b02c28055504c2_id_rsa.pub.
2026-03-19 12:42:00.464623 | controller -> localhost | The key fingerprint is:
2026-03-19 12:42:00.464644 | controller -> localhost | SHA256:TspenyLTgw0a1pLkOyogzpG1xowOUnak1r+kRJVSo7s zuul-build-sshkey
2026-03-19 12:42:00.464665 | controller -> localhost | The key's randomart image is:
2026-03-19 12:42:00.464685 | controller -> localhost | +---[RSA 3072]----+
2026-03-19 12:42:00.464704 | controller -> localhost | |     .o.         |
2026-03-19 12:42:00.464723 | controller -> localhost | |    o.o.         |
2026-03-19 12:42:00.464742 | controller -> localhost | |   +.o           |
2026-03-19 12:42:00.464761 | controller -> localhost | |  =.=.           |
2026-03-19 12:42:00.464779 | controller -> localhost | | +*=o+  S        |
2026-03-19 12:42:00.464797 | controller -> localhost | |=+ =Bo=+         |
2026-03-19 12:42:00.464814 | controller -> localhost | |O ooEBo*o        |
2026-03-19 12:42:00.464831 | controller -> localhost | |.+  =.=.=. .     |
2026-03-19 12:42:00.464849 | controller -> localhost | | ... ..o oo      |
2026-03-19 12:42:00.464866 | controller -> localhost | +----[SHA256]-----+
2026-03-19 12:42:00.464916 | controller -> localhost | ok: Runtime: 0:00:00.121244
2026-03-19 12:42:00.471322 | 
2026-03-19 12:42:00.471389 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-03-19 12:42:00.499816 | controller | ok
2026-03-19 12:42:00.509059 | controller | included: /var/lib/zuul/builds/cd8ff0e6062f4fd3b8b02c28055504c2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-03-19 12:42:00.516695 | 
2026-03-19 12:42:00.516760 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-03-19 12:42:00.530810 | controller | skipping: Conditional result was False
2026-03-19 12:42:00.536507 | 
2026-03-19 12:42:00.536572 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-03-19 12:42:00.920893 | controller | changed
2026-03-19 12:42:00.925634 | 
2026-03-19 12:42:00.925696 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-03-19 12:42:01.147503 | controller | ok
2026-03-19 12:42:01.152412 | 
2026-03-19 12:42:01.152476 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-03-19 12:42:01.750976 | controller | changed
2026-03-19 12:42:01.756590 | 
2026-03-19 12:42:01.756661 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-03-19 12:42:02.333130 | controller | changed
2026-03-19 12:42:02.340083 | 
2026-03-19 12:42:02.340145 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-03-19 12:42:02.357161 | controller | skipping: Conditional result was False
2026-03-19 12:42:02.362659 | 
2026-03-19 12:42:02.362724 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-03-19 12:42:02.716750 | controller -> localhost | changed
2026-03-19 12:42:02.727197 | 
2026-03-19 12:42:02.727353 | TASK [add-build-sshkey : Add back temp key]
2026-03-19 12:42:02.975672 | controller -> localhost | Identity added: /var/lib/zuul/builds/cd8ff0e6062f4fd3b8b02c28055504c2/work/cd8ff0e6062f4fd3b8b02c28055504c2_id_rsa (zuul-build-sshkey)
2026-03-19 12:42:02.975896 | controller -> localhost | ok: Runtime: 0:00:00.007908
2026-03-19 12:42:02.981953 | 
2026-03-19 12:42:02.982037 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-03-19 12:42:03.294154 | controller | ok
2026-03-19 12:42:03.298688 | 
2026-03-19 12:42:03.298762 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-03-19 12:42:03.323957 | controller | skipping: Conditional result was False
2026-03-19 12:42:03.333225 | 
2026-03-19 12:42:03.333292 | TASK [include_role : validate-host]
2026-03-19 12:42:03.352789 | controller | ok
2026-03-19 12:42:03.374433 | 
2026-03-19 12:42:03.374505 | TASK [validate-host : Define zuul_info_dir fact]
2026-03-19 12:42:03.402487 | controller | ok
2026-03-19 12:42:03.406881 | 
2026-03-19 12:42:03.406940 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2026-03-19 12:42:03.613234 | controller -> localhost | ok
2026-03-19 12:42:03.619444 | 
2026-03-19 12:42:03.619517 | TASK [validate-host : Collect information about the host]
2026-03-19 12:42:04.268915 | controller | ok
2026-03-19 12:42:04.278284 | 
2026-03-19 12:42:04.278370 | TASK [validate-host : Sanitize hostname]
2026-03-19 12:42:04.368086 | controller | ok
2026-03-19 12:42:04.372556 | 
2026-03-19 12:42:04.372620 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2026-03-19 12:42:04.763097 | controller -> localhost | changed
2026-03-19 12:42:04.768802 | 
2026-03-19 12:42:04.768872 | TASK [validate-host : Collect information about zuul worker]
2026-03-19 12:42:05.112477 | controller | ok
2026-03-19 12:42:05.117057 | 
2026-03-19 12:42:05.117122 | TASK [validate-host : Write out all zuul information for each host]
2026-03-19 12:42:05.497693 | controller -> localhost | changed
2026-03-19 12:42:05.509752 | 
2026-03-19 12:42:05.509843 | TASK [include_role : prepare-workspace-openshift]
2026-03-19 12:42:05.524015 | controller | skipping: Conditional result was False
2026-03-19 12:42:05.530077 | 
2026-03-19 12:42:05.530156 | TASK [include_role : remove-zuul-sshkey]
2026-03-19 12:42:05.543375 | controller | skipping: Conditional result was False
2026-03-19 12:42:05.548572 | 
2026-03-19 12:42:05.548643 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-03-19 12:42:05.745184 | controller | ok: "logs"
2026-03-19 12:42:05.745443 | controller | ok: All items complete
2026-03-19 12:42:05.745474 | 
2026-03-19 12:42:05.916327 | controller | ok: "artifacts"
2026-03-19 12:42:06.083548 | controller | ok: "docs"
2026-03-19 12:42:06.089105 | 
2026-03-19 12:42:06.089191 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-03-19 12:42:06.290460 | controller | changed: "logs"
2026-03-19 12:42:06.463417 | controller | changed: "artifacts"
2026-03-19 12:42:06.649120 | controller | changed: "docs"
2026-03-19 12:42:06.675091 | 
2026-03-19 12:42:06.675276 | PLAY RECAP
2026-03-19 12:42:06.675363 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2026-03-19 12:42:06.675397 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-03-19 12:42:06.675418 | 
2026-03-19 12:42:06.794200 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2026-03-19 12:42:06.794942 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2026-03-19 12:42:07.369567 | 
2026-03-19 12:42:07.369669 | PLAY [all]
2026-03-19 12:42:07.389482 | 
2026-03-19 12:42:07.389559 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2026-03-19 12:42:07.449241 | controller | ok
2026-03-19 12:42:07.454108 | 
2026-03-19 12:42:07.454193 | TASK [mirror-info-fork : Create /etc/ci]
2026-03-19 12:42:07.807364 | controller | changed
2026-03-19 12:42:07.812931 | 
2026-03-19 12:42:07.813029 | TASK [mirror-info-fork : Install ci_mirror script]
2026-03-19 12:42:08.733715 | controller | changed
2026-03-19 12:42:08.743163 | 
2026-03-19 12:42:08.743231 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2026-03-19 12:42:09.100309 | controller | changed:
2026-03-19 12:42:09.100496 | controller | {
2026-03-19 12:42:09.100524 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2026-03-19 12:42:09.100553 | controller | }
2026-03-19 12:42:09.308235 | controller | changed:
2026-03-19 12:42:09.308345 | controller | {
2026-03-19 12:42:09.308376 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2026-03-19 12:42:09.308400 | controller | }
2026-03-19 12:42:09.517343 | controller | changed:
2026-03-19 12:42:09.517514 | controller | {
2026-03-19 12:42:09.517547 | 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-19 12:42:09.517570 | controller | }
2026-03-19 12:42:09.730561 | controller | changed:
2026-03-19 12:42:09.730615 | controller | {
2026-03-19 12:42:09.730641 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2026-03-19 12:42:09.730661 | controller | }
2026-03-19 12:42:09.931252 | controller | changed:
2026-03-19 12:42:09.931368 | controller | {
2026-03-19 12:42:09.931397 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2026-03-19 12:42:09.931418 | controller | }
2026-03-19 12:42:10.140455 | controller | changed:
2026-03-19 12:42:10.140557 | controller | {
2026-03-19 12:42:10.140622 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2026-03-19 12:42:10.140647 | controller | }
2026-03-19 12:42:10.352844 | controller | changed:
2026-03-19 12:42:10.352937 | controller | {
2026-03-19 12:42:10.352962 | 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-19 12:42:10.352995 | controller | }
2026-03-19 12:42:10.562083 | controller | changed:
2026-03-19 12:42:10.562272 | controller | {
2026-03-19 12:42:10.562330 | 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-19 12:42:10.562357 | controller | }
2026-03-19 12:42:10.771190 | controller | changed:
2026-03-19 12:42:10.771316 | controller | {
2026-03-19 12:42:10.771348 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2026-03-19 12:42:10.771370 | controller | }
2026-03-19 12:42:10.974790 | controller | changed:
2026-03-19 12:42:10.974887 | controller | {
2026-03-19 12:42:10.974916 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2026-03-19 12:42:10.974936 | controller | }
2026-03-19 12:42:11.177153 | controller | changed:
2026-03-19 12:42:11.177253 | controller | {
2026-03-19 12:42:11.177282 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2026-03-19 12:42:11.177322 | controller | }
2026-03-19 12:42:11.408520 | controller | changed:
2026-03-19 12:42:11.408622 | controller | {
2026-03-19 12:42:11.408649 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2026-03-19 12:42:11.408670 | controller | }
2026-03-19 12:42:11.606286 | controller | changed:
2026-03-19 12:42:11.606392 | controller | {
2026-03-19 12:42:11.606418 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICWBreHW95Wz2Toz5YwCGQwFcUG8oFYkienDh9tntmDc ralfieri@redhat.com"
2026-03-19 12:42:11.606439 | controller | }
2026-03-19 12:42:11.816593 | controller | changed:
2026-03-19 12:42:11.816693 | controller | {
2026-03-19 12:42:11.816720 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2026-03-19 12:42:11.816740 | controller | }
2026-03-19 12:42:12.031035 | controller | changed:
2026-03-19 12:42:12.031124 | controller | {
2026-03-19 12:42:12.031150 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2026-03-19 12:42:12.031172 | controller | }
2026-03-19 12:42:12.234586 | controller | changed:
2026-03-19 12:42:12.234684 | controller | {
2026-03-19 12:42:12.234712 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2026-03-19 12:42:12.234733 | controller | }
2026-03-19 12:42:12.448871 | controller | changed:
2026-03-19 12:42:12.448976 | controller | {
2026-03-19 12:42:12.449007 | 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-19 12:42:12.449030 | controller | }
2026-03-19 12:42:12.662203 | controller | changed:
2026-03-19 12:42:12.662281 | controller | {
2026-03-19 12:42:12.662326 | 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-19 12:42:12.662357 | controller | }
2026-03-19 12:42:12.875041 | controller | changed:
2026-03-19 12:42:12.875125 | controller | {
2026-03-19 12:42:12.875150 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2026-03-19 12:42:12.875169 | controller | }
2026-03-19 12:42:13.078802 | controller | changed:
2026-03-19 12:42:13.078884 | controller | {
2026-03-19 12:42:13.078909 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2026-03-19 12:42:13.079004 | controller | }
2026-03-19 12:42:13.285535 | controller | changed:
2026-03-19 12:42:13.285639 | controller | {
2026-03-19 12:42:13.285668 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2026-03-19 12:42:13.285688 | controller | }
2026-03-19 12:42:13.484180 | controller | changed:
2026-03-19 12:42:13.484274 | controller | {
2026-03-19 12:42:13.484382 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2026-03-19 12:42:13.484417 | controller | }
2026-03-19 12:42:13.689051 | controller | changed:
2026-03-19 12:42:13.689142 | controller | {
2026-03-19 12:42:13.689171 | 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-19 12:42:13.689193 | controller | }
2026-03-19 12:42:13.897145 | controller | changed:
2026-03-19 12:42:13.897237 | controller | {
2026-03-19 12:42:13.897265 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2026-03-19 12:42:13.897286 | controller | }
2026-03-19 12:42:14.101794 | controller | changed:
2026-03-19 12:42:14.101876 | controller | {
2026-03-19 12:42:14.101904 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2026-03-19 12:42:14.101924 | controller | }
2026-03-19 12:42:14.304444 | controller | changed:
2026-03-19 12:42:14.304548 | controller | {
2026-03-19 12:42:14.304578 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2026-03-19 12:42:14.304600 | controller | }
2026-03-19 12:42:14.324182 | 
2026-03-19 12:42:14.324258 | TASK [Set timezone to UTC]
2026-03-19 12:42:14.730555 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2026-03-19 12:42:14.737325 | 
2026-03-19 12:42:14.737430 | TASK [Create nodepool directory]
2026-03-19 12:42:14.949544 | controller | changed
2026-03-19 12:42:14.954992 | 
2026-03-19 12:42:14.955058 | TASK [Create nodepool sub_nodes file]
2026-03-19 12:42:15.490696 | controller | changed
2026-03-19 12:42:15.495683 | 
2026-03-19 12:42:15.495757 | TASK [Create nodepool sub_nodes_private file]
2026-03-19 12:42:16.034187 | controller | changed
2026-03-19 12:42:16.039319 | 
2026-03-19 12:42:16.039387 | LOOP [Populate nodepool sub_nodes file]
2026-03-19 12:42:16.069196 | 
2026-03-19 12:42:16.069375 | LOOP [Populate nodepool sub_nodes_private file]
2026-03-19 12:42:16.111934 | 
2026-03-19 12:42:16.112112 | TASK [Create nodepool primary file]
2026-03-19 12:42:16.147160 | controller | skipping: Conditional result was False
2026-03-19 12:42:16.152790 | 
2026-03-19 12:42:16.152872 | TASK [Create nodepool node_private for this node]
2026-03-19 12:42:16.709421 | controller | changed
2026-03-19 12:42:16.716246 | 
2026-03-19 12:42:16.716328 | LOOP [Copy ssh keys to nodepool directory]
2026-03-19 12:42:17.033205 | controller | ok: Item: id_rsa Runtime: 0:00:00.005751
2026-03-19 12:42:17.033408 | 
2026-03-19 12:42:17.196885 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.005911
2026-03-19 12:42:17.211483 | 
2026-03-19 12:42:17.211583 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2026-03-19 12:42:17.756225 | controller | changed
2026-03-19 12:42:17.761705 | 
2026-03-19 12:42:17.761772 | TASK [Validate sudoers config after edits]
2026-03-19 12:42:17.992418 | controller | /etc/sudoers: parsed OK
2026-03-19 12:42:17.992505 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2026-03-19 12:42:17.992516 | controller | /etc/sudoers.d/zuul: parsed OK
2026-03-19 12:42:17.992523 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2026-03-19 12:42:18.296008 | controller | ok: Runtime: 0:00:00.005416
2026-03-19 12:42:18.301281 | 
2026-03-19 12:42:18.301360 | TASK [Show the environment passed in to job shell scripts]
2026-03-19 12:42:18.510962 | controller | SHELL=/bin/bash
2026-03-19 12:42:18.511007 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2026-03-19 12:42:18.511017 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2026-03-19 12:42:18.511024 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/39/3739/aed42d59e83ffbd303ac5f5c196cfa920f63ed22
2026-03-19 12:42:18.511030 | controller | PWD=/home/zuul
2026-03-19 12:42:18.511036 | controller | ZUUL_PIPELINE=github-check
2026-03-19 12:42:18.511042 | controller | LOGNAME=zuul
2026-03-19 12:42:18.511047 | controller | XDG_SESSION_TYPE=tty
2026-03-19 12:42:18.511102 | controller | _=/usr/bin/env
2026-03-19 12:42:18.511114 | controller | MOTD_SHOWN=pam
2026-03-19 12:42:18.511120 | controller | HOME=/home/zuul
2026-03-19 12:42:18.511125 | controller | LANG=en_US.UTF-8
2026-03-19 12:42:18.511130 | controller | SSH_CONNECTION=192.168.26.12 43392 192.168.26.241 22
2026-03-19 12:42:18.511136 | 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-19 12:42:18.511145 | controller | ZUUL_CHANGE_IDS=3739,aed42d59e83ffbd303ac5f5c196cfa920f63ed22
2026-03-19 12:42:18.511151 | controller | WORKSPACE=/home/zuul/workspace
2026-03-19 12:42:18.511156 | controller | XDG_SESSION_CLASS=user
2026-03-19 12:42:18.511162 | controller | SELINUX_ROLE_REQUESTED=
2026-03-19 12:42:18.511167 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2026-03-19 12:42:18.511172 | controller | USER=zuul
2026-03-19 12:42:18.511178 | controller | ZUUL_VOTING=True
2026-03-19 12:42:18.511183 | controller | BUILD_TIMEOUT=1800000
2026-03-19 12:42:18.511189 | controller | SELINUX_USE_CURRENT_RANGE=
2026-03-19 12:42:18.511194 | controller | SHLVL=1
2026-03-19 12:42:18.511199 | controller | ZUUL_PATCHSET=aed42d59e83ffbd303ac5f5c196cfa920f63ed22
2026-03-19 12:42:18.511205 | controller | XDG_SESSION_ID=1
2026-03-19 12:42:18.511210 | controller | ZUUL_BRANCH=main
2026-03-19 12:42:18.511215 | controller | XDG_RUNTIME_DIR=/run/user/1000
2026-03-19 12:42:18.511221 | controller | SSH_CLIENT=192.168.26.12 43392 22
2026-03-19 12:42:18.511226 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2026-03-19 12:42:18.511232 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2026-03-19 12:42:18.511237 | controller | which_declare=declare -f
2026-03-19 12:42:18.511243 | controller | PATH=/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2026-03-19 12:42:18.511249 | controller | SELINUX_LEVEL_REQUESTED=
2026-03-19 12:42:18.511254 | controller | ZUUL_CHANGE=3739
2026-03-19 12:42:18.511260 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2026-03-19 12:42:18.511265 | controller | ZUUL_UUID=cd8ff0e6062f4fd3b8b02c28055504c2
2026-03-19 12:42:18.511272 | controller | BASH_FUNC_which%%=() {  ( alias;
2026-03-19 12:42:18.511278 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2026-03-19 12:42:18.511283 | controller | }
2026-03-19 12:42:18.826594 | controller | ok: Runtime: 0:00:00.006079
2026-03-19 12:42:18.831742 | 
2026-03-19 12:42:18.831804 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2026-03-19 12:42:18.845469 | controller | skipping: Conditional result was False
2026-03-19 12:42:18.850741 | 
2026-03-19 12:42:18.850802 | TASK [Symlink /home/zuul-worker/workspace]
2026-03-19 12:42:19.375059 | controller | skipping: Conditional result was False
2026-03-19 12:42:19.380230 | 
2026-03-19 12:42:19.380314 | TASK [Ensure legacy workspace directory]
2026-03-19 12:42:19.563564 | controller | changed
2026-03-19 12:42:19.590678 | 
2026-03-19 12:42:19.590751 | PLAY RECAP
2026-03-19 12:42:19.590805 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2026-03-19 12:42:19.590835 | 
2026-03-19 12:42:19.662685 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2026-03-19 12:42:19.663424 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2026-03-19 12:42:20.158544 | 
2026-03-19 12:42:20.158628 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2026-03-19 12:42:20.178162 | 
2026-03-19 12:42:20.178237 | TASK [Create zuul-output directory]
2026-03-19 12:42:20.517023 | controller | changed
2026-03-19 12:42:20.522058 | 
2026-03-19 12:42:20.522147 | TASK [Slurp Zuul inventory test]
2026-03-19 12:42:20.789240 | controller -> localhost | ok
2026-03-19 12:42:20.795439 | 
2026-03-19 12:42:20.795527 | TASK [Save zuul inventory]
2026-03-19 12:42:21.523346 | controller | changed
2026-03-19 12:42:21.528191 | 
2026-03-19 12:42:21.528274 | TASK [Save zuul vars without the change_message]
2026-03-19 12:42:22.104653 | controller | changed
2026-03-19 12:42:22.123186 | 
2026-03-19 12:42:22.123399 | PLAY RECAP
2026-03-19 12:42:22.123473 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-03-19 12:42:22.123499 | 
2026-03-19 12:42:22.194266 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2026-03-19 12:42:22.195064 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2026-03-19 12:42:22.743712 | 
2026-03-19 12:42:22.743811 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2026-03-19 12:42:22.766093 | 
2026-03-19 12:42:22.766231 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2026-03-19 12:42:22.784875 | controller | ok
2026-03-19 12:42:22.801863 | 
2026-03-19 12:42:22.801949 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2026-03-19 12:42:22.825611 | controller | skipping: Conditional result was False
2026-03-19 12:42:22.831180 | 
2026-03-19 12:42:22.831254 | TASK [mirror-info-fork : Create /etc/ci]
2026-03-19 12:42:23.152228 | controller | ok
2026-03-19 12:42:23.157853 | 
2026-03-19 12:42:23.157937 | TASK [mirror-info-fork : Install ci_mirror script]
2026-03-19 12:42:23.754583 | controller | ok
2026-03-19 12:42:23.771716 | 
2026-03-19 12:42:23.771810 | TASK [Prepare workspace]
2026-03-19 12:42:23.790347 | controller | ok
2026-03-19 12:42:23.811669 | 
2026-03-19 12:42:23.811749 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-03-19 12:42:24.107210 | controller | ok
2026-03-19 12:42:24.112835 | 
2026-03-19 12:42:24.112900 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-03-19 12:42:26.623625 | controller | Output suppressed because no_log was given
2026-03-19 12:42:26.638709 | 
2026-03-19 12:42:26.638773 | LOOP [Create zuul-output directory]
2026-03-19 12:42:26.825766 | controller | changed: "/home/zuul/ci-framework-data/logs"
2026-03-19 12:42:26.978923 | controller | ok: "/home/zuul/zuul-output/logs"
2026-03-19 12:42:26.988456 | 
2026-03-19 12:42:26.988528 | TASK [Install required packages]
2026-03-19 12:43:05.745785 | controller | changed
2026-03-19 12:43:05.750936 | 
2026-03-19 12:43:05.751011 | TASK [Install venv]
2026-03-19 12:44:06.206249 | controller | changed
2026-03-19 12:44:06.230722 | 
2026-03-19 12:44:06.230783 | PLAY RECAP
2026-03-19 12:44:06.230829 | controller | ok: 7 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-03-19 12:44:06.230854 | 
2026-03-19 12:44:06.302401 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2026-03-19 12:44:06.303326 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2026-03-19 12:44:06.827127 | 
2026-03-19 12:44:06.827236 | PLAY [Run ci/playbooks/molecule-test.yml]
2026-03-19 12:44:06.847673 | 
2026-03-19 12:44:06.847750 | TASK [Gather required facts]
2026-03-19 12:44:07.343527 | controller | ok
2026-03-19 12:44:07.348858 | 
2026-03-19 12:44:07.348946 | TASK [Load environment var if instructed to]
2026-03-19 12:44:07.372895 | controller | skipping: Conditional result was False
2026-03-19 12:44:07.378102 | 
2026-03-19 12:44:07.378168 | TASK [Ensure group_vars dir exists]
2026-03-19 12:44:07.689583 | controller | ok
2026-03-19 12:44:07.695659 | 
2026-03-19 12:44:07.695734 | TASK [Print related variables]
2026-03-19 12:44:07.723852 | controller | ok:
2026-03-19 12:44:07.723981 | controller | mol_config_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config_local.yml
2026-03-19 12:44:07.724012 | controller | roles_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno
2026-03-19 12:44:07.728858 | 
2026-03-19 12:44:07.728922 | TASK [Run molecule]
2026-03-19 12:44:08.701995 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2026-03-19 12:44:08.781081 | controller | INFO     Running bm_redfish > prepare
2026-03-19 12:44:09.425736 | controller |
2026-03-19 12:44:09.425801 | controller | PLAY [Prepare mock iDRAC server] ***********************************************
2026-03-19 12:44:09.425922 | controller |
2026-03-19 12:44:09.426041 | controller | TASK [Create mock server directory] ********************************************
2026-03-19 12:44:09.426489 | controller | Thursday 19 March 2026  12:44:09 +0000 (0:00:00.023)       0:00:00.023 ********
2026-03-19 12:44:09.750648 | controller | changed: [instance]
2026-03-19 12:44:09.750692 | controller |
2026-03-19 12:44:09.750769 | controller | TASK [Generate self-signed TLS certificate] ************************************
2026-03-19 12:44:09.750864 | controller | Thursday 19 March 2026  12:44:09 +0000 (0:00:00.325)       0:00:00.349 ********
2026-03-19 12:44:10.074315 | controller | changed: [instance]
2026-03-19 12:44:10.074377 | controller |
2026-03-19 12:44:10.074487 | controller | TASK [Copy mock iDRAC server script] *******************************************
2026-03-19 12:44:10.074588 | controller | Thursday 19 March 2026  12:44:10 +0000 (0:00:00.323)       0:00:00.672 ********
2026-03-19 12:44:10.595088 | controller | changed: [instance]
2026-03-19 12:44:10.595163 | controller |
2026-03-19 12:44:10.595266 | controller | TASK [Start mock iDRAC server] *************************************************
2026-03-19 12:44:10.595361 | controller | Thursday 19 March 2026  12:44:10 +0000 (0:00:00.520)       0:00:01.193 ********
2026-03-19 12:44:10.773963 | controller | changed: [instance]
2026-03-19 12:44:10.774070 | controller |
2026-03-19 12:44:10.774194 | controller | TASK [Record mock server PID] **************************************************
2026-03-19 12:44:10.774292 | controller | Thursday 19 March 2026  12:44:10 +0000 (0:00:00.179)       0:00:01.372 ********
2026-03-19 12:44:10.965111 | controller | ok: [instance]
2026-03-19 12:44:10.965179 | controller |
2026-03-19 12:44:10.965285 | controller | TASK [Wait for mock iDRAC to respond] ******************************************
2026-03-19 12:44:10.965389 | controller | Thursday 19 March 2026  12:44:10 +0000 (0:00:00.190)       0:00:01.563 ********
2026-03-19 12:44:11.381596 | controller | ok: [instance]
2026-03-19 12:44:11.381650 | controller |
2026-03-19 12:44:11.381753 | controller | PLAY RECAP *********************************************************************
2026-03-19 12:44:11.381850 | controller | instance                   : ok=6    changed=4    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2026-03-19 12:44:11.381950 | controller |
2026-03-19 12:44:11.382076 | controller | Thursday 19 March 2026  12:44:11 +0000 (0:00:00.417)       0:00:01.980 ********
2026-03-19 12:44:11.382168 | controller | ===============================================================================
2026-03-19 12:44:11.382264 | controller | Copy mock iDRAC server script ------------------------------------------- 0.52s
2026-03-19 12:44:11.382356 | controller | Wait for mock iDRAC to respond ------------------------------------------ 0.42s
2026-03-19 12:44:11.382455 | controller | Create mock server directory -------------------------------------------- 0.33s
2026-03-19 12:44:11.382541 | controller | Generate self-signed TLS certificate ------------------------------------ 0.32s
2026-03-19 12:44:11.382631 | controller | Record mock server PID -------------------------------------------------- 0.19s
2026-03-19 12:44:11.382726 | controller | Start mock iDRAC server ------------------------------------------------- 0.18s
2026-03-19 12:44:11.437946 | controller | INFO     Running bm_redfish > converge
2026-03-19 12:44:11.858804 | controller |
2026-03-19 12:44:11.858880 | controller | PLAY [Converge -- test bm_* Redfish tasks against mock iDRAC] ******************
2026-03-19 12:44:11.858983 | controller |
2026-03-19 12:44:11.859106 | controller | TASK [Test bm_power_off] *******************************************************
2026-03-19 12:44:11.859207 | controller | Thursday 19 March 2026  12:44:11 +0000 (0:00:00.047)       0:00:00.047 ********
2026-03-19 12:44:11.879862 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/molecule/bm_redfish/tasks/test_power_off.yml for instance
2026-03-19 12:44:11.879945 | controller |
2026-03-19 12:44:11.880045 | controller | TASK [Reset mock to power Off] *************************************************
2026-03-19 12:44:11.880166 | controller | Thursday 19 March 2026  12:44:11 +0000 (0:00:00.021)       0:00:00.069 ********
2026-03-19 12:44:12.271998 | controller | ok: [instance]
2026-03-19 12:44:12.272082 | controller |
2026-03-19 12:44:12.272225 | controller | TASK [Include bm_power_off] ****************************************************
2026-03-19 12:44:12.272320 | controller | Thursday 19 March 2026  12:44:12 +0000 (0:00:00.391)       0:00:00.460 ********
2026-03-19 12:44:12.296274 | controller |
2026-03-19 12:44:12.296395 | controller | TASK [bm_sno : Query current power state] **************************************
2026-03-19 12:44:12.296498 | controller | Thursday 19 March 2026  12:44:12 +0000 (0:00:00.024)       0:00:00.485 ********
2026-03-19 12:44:12.575902 | controller | ok: [instance]
2026-03-19 12:44:12.575974 | controller |
2026-03-19 12:44:12.576105 | controller | TASK [bm_sno : Force power off via Redfish] ************************************
2026-03-19 12:44:12.576207 | controller | Thursday 19 March 2026  12:44:12 +0000 (0:00:00.279)       0:00:00.764 ********
2026-03-19 12:44:12.592780 | controller | skipping: [instance]
2026-03-19 12:44:12.592866 | controller |
2026-03-19 12:44:12.592986 | controller | TASK [bm_sno : Wait for host to power off] *************************************
2026-03-19 12:44:12.593111 | controller | Thursday 19 March 2026  12:44:12 +0000 (0:00:00.017)       0:00:00.782 ********
2026-03-19 12:44:12.613383 | controller | skipping: [instance]
2026-03-19 12:44:12.613462 | controller |
2026-03-19 12:44:12.613559 | controller | TASK [Query mock state after power_off (already off)] **************************
2026-03-19 12:44:12.613653 | controller | Thursday 19 March 2026  12:44:12 +0000 (0:00:00.020)       0:00:00.802 ********
2026-03-19 12:44:12.898237 | controller | ok: [instance]
2026-03-19 12:44:12.898617 | controller |
2026-03-19 12:44:12.917264 | controller | TASK [Assert host is still Off] ************************************************
2026-03-19 12:44:12.917289 | controller | Thursday 19 March 2026  12:44:12 +0000 (0:00:00.284)       0:00:01.086 ********
2026-03-19 12:44:12.917304 | controller | ok: [instance] => {
2026-03-19 12:44:13.199131 | controller |     "changed": false,
2026-03-19 12:44:13.199163 | controller |     "msg": "All assertions passed"
2026-03-19 12:44:13.199175 | controller | }
2026-03-19 12:44:13.199181 | controller |
2026-03-19 12:44:13.199187 | controller | TASK [Reset mock to power On] **************************************************
2026-03-19 12:44:13.199193 | controller | Thursday 19 March 2026  12:44:12 +0000 (0:00:00.018)       0:00:01.105 ********
2026-03-19 12:44:13.199203 | controller | ok: [instance]
2026-03-19 12:44:13.221140 | controller |
2026-03-19 12:44:13.221175 | controller | TASK [Include bm_power_off] ****************************************************
2026-03-19 12:44:13.221183 | controller | Thursday 19 March 2026  12:44:13 +0000 (0:00:00.281)       0:00:01.387 ********
2026-03-19 12:44:13.221194 | controller |
2026-03-19 12:44:13.504553 | controller | TASK [bm_sno : Query current power state] **************************************
2026-03-19 12:44:13.504586 | controller | Thursday 19 March 2026  12:44:13 +0000 (0:00:00.022)       0:00:01.410 ********
2026-03-19 12:44:13.504600 | controller | ok: [instance]
2026-03-19 12:44:13.787028 | controller |
2026-03-19 12:44:13.787076 | controller | TASK [bm_sno : Force power off via Redfish] ************************************
2026-03-19 12:44:13.787087 | controller | Thursday 19 March 2026  12:44:13 +0000 (0:00:00.282)       0:00:01.693 ********
2026-03-19 12:44:13.787097 | controller | ok: [instance]
2026-03-19 12:44:14.071982 | controller |
2026-03-19 12:44:14.072014 | controller | TASK [bm_sno : Wait for host to power off] *************************************
2026-03-19 12:44:14.072022 | controller | Thursday 19 March 2026  12:44:13 +0000 (0:00:00.282)       0:00:01.975 ********
2026-03-19 12:44:14.072032 | controller | ok: [instance]
2026-03-19 12:44:14.365706 | controller |
2026-03-19 12:44:14.365739 | controller | TASK [Query mock state after power_off (was on)] *******************************
2026-03-19 12:44:14.365747 | controller | Thursday 19 March 2026  12:44:14 +0000 (0:00:00.284)       0:00:02.260 ********
2026-03-19 12:44:14.365757 | controller | ok: [instance]
2026-03-19 12:44:14.384775 | controller |
2026-03-19 12:44:14.384795 | controller | TASK [Assert host is now Off] **************************************************
2026-03-19 12:44:14.384803 | controller | Thursday 19 March 2026  12:44:14 +0000 (0:00:00.293)       0:00:02.554 ********
2026-03-19 12:44:14.384812 | controller | ok: [instance] => {
2026-03-19 12:44:14.409547 | controller |     "changed": false,
2026-03-19 12:44:14.409566 | controller |     "msg": "All assertions passed"
2026-03-19 12:44:14.409583 | controller | }
2026-03-19 12:44:14.409590 | controller |
2026-03-19 12:44:14.409596 | controller | TASK [Test bm_power_on] ********************************************************
2026-03-19 12:44:14.409601 | controller | Thursday 19 March 2026  12:44:14 +0000 (0:00:00.019)       0:00:02.573 ********
2026-03-19 12:44:14.409614 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/molecule/bm_redfish/tasks/test_power_on.yml for instance
2026-03-19 12:44:14.696924 | controller |
2026-03-19 12:44:14.696967 | controller | TASK [Reset mock to power On] **************************************************
2026-03-19 12:44:14.696976 | controller | Thursday 19 March 2026  12:44:14 +0000 (0:00:00.025)       0:00:02.598 ********
2026-03-19 12:44:14.696986 | controller | ok: [instance]
2026-03-19 12:44:14.720914 | controller |
2026-03-19 12:44:14.720949 | controller | TASK [Include bm_power_on] *****************************************************
2026-03-19 12:44:14.720957 | controller | Thursday 19 March 2026  12:44:14 +0000 (0:00:00.287)       0:00:02.885 ********
2026-03-19 12:44:14.720967 | controller |
2026-03-19 12:44:15.007119 | controller | TASK [bm_sno : Query current power state] **************************************
2026-03-19 12:44:15.007151 | controller | Thursday 19 March 2026  12:44:14 +0000 (0:00:00.024)       0:00:02.910 ********
2026-03-19 12:44:15.007163 | controller | ok: [instance]
2026-03-19 12:44:15.007389 | controller |
2026-03-19 12:44:15.007403 | controller | TASK [bm_sno : Power on bare metal host] ***************************************
2026-03-19 12:44:15.024439 | controller | Thursday 19 March 2026  12:44:15 +0000 (0:00:00.285)       0:00:03.196 ********
2026-03-19 12:44:15.024458 | controller | skipping: [instance]
2026-03-19 12:44:15.319602 | controller |
2026-03-19 12:44:15.319633 | controller | TASK [bm_sno : Wait for host POST to complete] *********************************
2026-03-19 12:44:15.319641 | controller | Thursday 19 March 2026  12:44:15 +0000 (0:00:00.017)       0:00:03.213 ********
2026-03-19 12:44:15.319651 | controller | ok: [instance]
2026-03-19 12:44:15.353134 | controller |
2026-03-19 12:44:15.353169 | controller | TASK [bm_sno : Show POST state] ************************************************
2026-03-19 12:44:15.353177 | controller | Thursday 19 March 2026  12:44:15 +0000 (0:00:00.294)       0:00:03.508 ********
2026-03-19 12:44:15.353187 | controller | ok: [instance] => {
2026-03-19 12:44:15.639131 | controller |     "msg": "POST state: FinishedPost"
2026-03-19 12:44:15.639167 | controller | }
2026-03-19 12:44:15.639175 | controller |
2026-03-19 12:44:15.639181 | controller | TASK [Query mock state after power_on (already on)] ****************************
2026-03-19 12:44:15.639187 | controller | Thursday 19 March 2026  12:44:15 +0000 (0:00:00.033)       0:00:03.541 ********
2026-03-19 12:44:15.639197 | controller | ok: [instance]
2026-03-19 12:44:15.660766 | controller |
2026-03-19 12:44:15.660800 | controller | TASK [Assert host is still On with POST complete] ******************************
2026-03-19 12:44:15.660808 | controller | Thursday 19 March 2026  12:44:15 +0000 (0:00:00.286)       0:00:03.827 ********
2026-03-19 12:44:15.660819 | controller | ok: [instance] => {
2026-03-19 12:44:15.942123 | controller |     "changed": false,
2026-03-19 12:44:15.942153 | controller |     "msg": "All assertions passed"
2026-03-19 12:44:15.942161 | controller | }
2026-03-19 12:44:15.942167 | controller |
2026-03-19 12:44:15.942174 | controller | TASK [Reset mock to power Off] *************************************************
2026-03-19 12:44:15.942184 | controller | Thursday 19 March 2026  12:44:15 +0000 (0:00:00.021)       0:00:03.849 ********
2026-03-19 12:44:15.942194 | controller | ok: [instance]
2026-03-19 12:44:15.942220 | controller |
2026-03-19 12:44:15.942242 | controller | TASK [Include bm_power_on] *****************************************************
2026-03-19 12:44:15.942400 | controller | Thursday 19 March 2026  12:44:15 +0000 (0:00:00.281)       0:00:04.131 ********
2026-03-19 12:44:15.965301 | controller |
2026-03-19 12:44:16.250793 | controller | TASK [bm_sno : Query current power state] **************************************
2026-03-19 12:44:16.250824 | controller | Thursday 19 March 2026  12:44:15 +0000 (0:00:00.023)       0:00:04.154 ********
2026-03-19 12:44:16.250836 | controller | ok: [instance]
2026-03-19 12:44:16.530163 | controller |
2026-03-19 12:44:16.530198 | controller | TASK [bm_sno : Power on bare metal host] ***************************************
2026-03-19 12:44:16.530208 | controller | Thursday 19 March 2026  12:44:16 +0000 (0:00:00.285)       0:00:04.439 ********
2026-03-19 12:44:16.530228 | controller | ok: [instance]
2026-03-19 12:44:16.530255 | controller |
2026-03-19 12:44:16.530265 | controller | TASK [bm_sno : Wait for host POST to complete] *********************************
2026-03-19 12:44:16.530360 | controller | Thursday 19 March 2026  12:44:16 +0000 (0:00:00.279)       0:00:04.719 ********
2026-03-19 12:44:16.821917 | controller | ok: [instance]
2026-03-19 12:44:16.855135 | controller |
2026-03-19 12:44:16.855160 | controller | TASK [bm_sno : Show POST state] ************************************************
2026-03-19 12:44:16.855170 | controller | Thursday 19 March 2026  12:44:16 +0000 (0:00:00.291)       0:00:05.010 ********
2026-03-19 12:44:16.855181 | controller | ok: [instance] => {
2026-03-19 12:44:16.855207 | controller |     "msg": "POST state: FinishedPost"
2026-03-19 12:44:16.855215 | controller | }
2026-03-19 12:44:16.855225 | controller |
2026-03-19 12:44:16.855400 | controller | TASK [Query mock state after power_on (was off)] *******************************
2026-03-19 12:44:17.133129 | controller | Thursday 19 March 2026  12:44:16 +0000 (0:00:00.033)       0:00:05.044 ********
2026-03-19 12:44:17.133164 | controller | ok: [instance]
2026-03-19 12:44:17.133184 | controller |
2026-03-19 12:44:17.133385 | controller | TASK [Assert host is now On with POST complete] ********************************
2026-03-19 12:44:17.155013 | controller | Thursday 19 March 2026  12:44:17 +0000 (0:00:00.277)       0:00:05.322 ********
2026-03-19 12:44:17.155032 | controller | ok: [instance] => {
2026-03-19 12:44:17.437180 | controller |     "changed": false,
2026-03-19 12:44:17.437214 | controller |     "msg": "All assertions passed"
2026-03-19 12:44:17.437222 | controller | }
2026-03-19 12:44:17.437228 | controller |
2026-03-19 12:44:17.437235 | controller | TASK [Reset mock to power Off without PostState support] ***********************
2026-03-19 12:44:17.437241 | controller | Thursday 19 March 2026  12:44:17 +0000 (0:00:00.021)       0:00:05.343 ********
2026-03-19 12:44:17.437251 | controller | ok: [instance]
2026-03-19 12:44:17.437257 | controller |
2026-03-19 12:44:17.437262 | controller | TASK [Include bm_power_on] *****************************************************
2026-03-19 12:44:17.437270 | controller | Thursday 19 March 2026  12:44:17 +0000 (0:00:00.282)       0:00:05.626 ********
2026-03-19 12:44:17.462808 | controller |
2026-03-19 12:44:17.742835 | controller | TASK [bm_sno : Query current power state] **************************************
2026-03-19 12:44:17.742865 | controller | Thursday 19 March 2026  12:44:17 +0000 (0:00:00.025)       0:00:05.651 ********
2026-03-19 12:44:17.742877 | controller | ok: [instance]
2026-03-19 12:44:18.022122 | controller |
2026-03-19 12:44:18.022154 | controller | TASK [bm_sno : Power on bare metal host] ***************************************
2026-03-19 12:44:18.022162 | controller | Thursday 19 March 2026  12:44:17 +0000 (0:00:00.279)       0:00:05.931 ********
2026-03-19 12:44:18.022173 | controller | ok: [instance]
2026-03-19 12:44:18.022196 | controller |
2026-03-19 12:44:18.022401 | controller | TASK [bm_sno : Wait for host POST to complete] *********************************
2026-03-19 12:44:18.321421 | controller | Thursday 19 March 2026  12:44:18 +0000 (0:00:00.279)       0:00:06.211 ********
2026-03-19 12:44:18.321457 | controller | ok: [instance]
2026-03-19 12:44:18.355118 | controller |
2026-03-19 12:44:18.355139 | controller | TASK [bm_sno : Show POST state] ************************************************
2026-03-19 12:44:18.355147 | controller | Thursday 19 March 2026  12:44:18 +0000 (0:00:00.298)       0:00:06.510 ********
2026-03-19 12:44:18.355157 | controller | ok: [instance] => {
2026-03-19 12:44:18.355570 | controller |     "msg": "POST state: not supported by firmware, used PowerState=On"
2026-03-19 12:44:18.632016 | controller | }
2026-03-19 12:44:18.632066 | controller |
2026-03-19 12:44:18.632075 | controller | TASK [Query mock state after power_on (no PostState)] **************************
2026-03-19 12:44:18.632082 | controller | Thursday 19 March 2026  12:44:18 +0000 (0:00:00.034)       0:00:06.544 ********
2026-03-19 12:44:18.632095 | controller | ok: [instance]
2026-03-19 12:44:18.652975 | controller |
2026-03-19 12:44:18.652997 | controller | TASK [Assert host is On (PostState stays null)] ********************************
2026-03-19 12:44:18.653004 | controller | Thursday 19 March 2026  12:44:18 +0000 (0:00:00.276)       0:00:06.820 ********
2026-03-19 12:44:18.653019 | controller | ok: [instance] => {
2026-03-19 12:44:18.677133 | controller |     "changed": false,
2026-03-19 12:44:18.677161 | controller |     "msg": "All assertions passed"
2026-03-19 12:44:18.677171 | controller | }
2026-03-19 12:44:18.677186 | controller |
2026-03-19 12:44:18.677194 | controller | TASK [Test bm_check_usb_boot] **************************************************
2026-03-19 12:44:18.677201 | controller | Thursday 19 March 2026  12:44:18 +0000 (0:00:00.021)       0:00:06.841 ********
2026-03-19 12:44:18.677212 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/molecule/bm_redfish/tasks/test_check_usb_boot.yml for instance
2026-03-19 12:44:18.677242 | controller |
2026-03-19 12:44:18.677252 | controller | TASK [Reset mock with usb_boot Enabled] ****************************************
2026-03-19 12:44:18.677343 | controller | Thursday 19 March 2026  12:44:18 +0000 (0:00:00.024)       0:00:06.866 ********
2026-03-19 12:44:18.961784 | controller | ok: [instance]
2026-03-19 12:44:18.983935 | controller |
2026-03-19 12:44:18.983962 | controller | TASK [Include bm_check_usb_boot] ***********************************************
2026-03-19 12:44:18.983970 | controller | Thursday 19 March 2026  12:44:18 +0000 (0:00:00.284)       0:00:07.150 ********
2026-03-19 12:44:18.983979 | controller |
2026-03-19 12:44:19.269682 | controller | TASK [bm_sno : Read GenericUsbBoot BIOS attribute] *****************************
2026-03-19 12:44:19.269702 | controller | Thursday 19 March 2026  12:44:18 +0000 (0:00:00.022)       0:00:07.173 ********
2026-03-19 12:44:19.269712 | controller | ok: [instance]
2026-03-19 12:44:19.299769 | controller |
2026-03-19 12:44:19.299785 | controller | TASK [bm_sno : Set GenericUsbBoot status fact] *********************************
2026-03-19 12:44:19.299792 | controller | Thursday 19 March 2026  12:44:19 +0000 (0:00:00.285)       0:00:07.458 ********
2026-03-19 12:44:19.299801 | controller | ok: [instance]
2026-03-19 12:44:19.328219 | controller |
2026-03-19 12:44:19.328241 | controller | TASK [bm_sno : Fail if GenericUsbBoot is disabled] *****************************
2026-03-19 12:44:19.328251 | controller | Thursday 19 March 2026  12:44:19 +0000 (0:00:00.029)       0:00:07.488 ********
2026-03-19 12:44:19.328261 | controller | skipping: [instance]
2026-03-19 12:44:19.357040 | controller |
2026-03-19 12:44:19.357077 | controller | TASK [Assert _usb_boot_enabled is true] ****************************************
2026-03-19 12:44:19.357087 | controller | Thursday 19 March 2026  12:44:19 +0000 (0:00:00.028)       0:00:07.517 ********
2026-03-19 12:44:19.357097 | controller | ok: [instance] => {
2026-03-19 12:44:19.636789 | controller |     "changed": false,
2026-03-19 12:44:19.636819 | controller |     "msg": "All assertions passed"
2026-03-19 12:44:19.636826 | controller | }
2026-03-19 12:44:19.636832 | controller |
2026-03-19 12:44:19.636838 | controller | TASK [Reset mock with usb_boot Disabled] ***************************************
2026-03-19 12:44:19.636844 | controller | Thursday 19 March 2026  12:44:19 +0000 (0:00:00.028)       0:00:07.545 ********
2026-03-19 12:44:19.636853 | controller | ok: [instance]
2026-03-19 12:44:19.660181 | controller |
2026-03-19 12:44:19.660217 | controller | TASK [Include bm_check_usb_boot (expect failure)] ******************************
2026-03-19 12:44:19.660228 | controller | Thursday 19 March 2026  12:44:19 +0000 (0:00:00.280)       0:00:07.825 ********
2026-03-19 12:44:19.660248 | controller |
2026-03-19 12:44:19.660273 | controller | TASK [bm_sno : Read GenericUsbBoot BIOS attribute] *****************************
2026-03-19 12:44:19.660413 | controller | Thursday 19 March 2026  12:44:19 +0000 (0:00:00.023)       0:00:07.849 ********
2026-03-19 12:44:19.941182 | controller | ok: [instance]
2026-03-19 12:44:19.971685 | controller |
2026-03-19 12:44:19.971705 | controller | TASK [bm_sno : Set GenericUsbBoot status fact] *********************************
2026-03-19 12:44:19.971713 | controller | Thursday 19 March 2026  12:44:19 +0000 (0:00:00.280)       0:00:08.129 ********
2026-03-19 12:44:19.971722 | controller | ok: [instance]
2026-03-19 12:44:19.996018 | controller |
2026-03-19 12:44:19.996036 | controller | TASK [bm_sno : Fail if GenericUsbBoot is disabled] *****************************
2026-03-19 12:44:19.996045 | controller | Thursday 19 March 2026  12:44:19 +0000 (0:00:00.030)       0:00:08.160 ********
2026-03-19 12:44:19.996072 | controller | fatal: [instance]: FAILED! => {"changed": false, "msg": "GenericUsbBoot is Disabled in BIOS. VirtualMedia cannot boot host localhost:8443."}
2026-03-19 12:44:20.000764 | controller |
2026-03-19 12:44:20.020174 | controller | TASK [Assert failure was about GenericUsbBoot] *********************************
2026-03-19 12:44:20.020214 | controller | Thursday 19 March 2026  12:44:19 +0000 (0:00:00.029)       0:00:08.189 ********
2026-03-19 12:44:20.020237 | controller | ok: [instance] => {
2026-03-19 12:44:20.020267 | controller |     "changed": false,
2026-03-19 12:44:20.020280 | controller |     "msg": "All assertions passed"
2026-03-19 12:44:20.020288 | controller | }
2026-03-19 12:44:20.020297 | controller |
2026-03-19 12:44:20.020323 | controller | TASK [Test bm_ensure_usb_boot] *************************************************
2026-03-19 12:44:20.020427 | controller | Thursday 19 March 2026  12:44:20 +0000 (0:00:00.019)       0:00:08.209 ********
2026-03-19 12:44:20.063173 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/molecule/bm_redfish/tasks/test_ensure_usb_boot.yml for instance
2026-03-19 12:44:20.349711 | controller |
2026-03-19 12:44:20.349743 | controller | TASK [Reset mock with usb_boot Enabled and host Off] ***************************
2026-03-19 12:44:20.349751 | controller | Thursday 19 March 2026  12:44:20 +0000 (0:00:00.042)       0:00:08.252 ********
2026-03-19 12:44:20.349761 | controller | ok: [instance]
2026-03-19 12:44:20.377576 | controller |
2026-03-19 12:44:20.377598 | controller | TASK [Include bm_ensure_usb_boot] **********************************************
2026-03-19 12:44:20.377613 | controller | Thursday 19 March 2026  12:44:20 +0000 (0:00:00.286)       0:00:08.538 ********
2026-03-19 12:44:20.377625 | controller |
2026-03-19 12:44:20.396832 | controller | TASK [bm_sno : Check current GenericUsbBoot state] *****************************
2026-03-19 12:44:20.396850 | controller | Thursday 19 March 2026  12:44:20 +0000 (0:00:00.028)       0:00:08.566 ********
2026-03-19 12:44:20.396860 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/tasks/bm_check_usb_boot.yml for instance
2026-03-19 12:44:20.691168 | controller |
2026-03-19 12:44:20.691208 | controller | TASK [bm_sno : Read GenericUsbBoot BIOS attribute] *****************************
2026-03-19 12:44:20.691218 | controller | Thursday 19 March 2026  12:44:20 +0000 (0:00:00.019)       0:00:08.585 ********
2026-03-19 12:44:20.691230 | controller | ok: [instance]
2026-03-19 12:44:20.720471 | controller |
2026-03-19 12:44:20.720494 | controller | TASK [bm_sno : Set GenericUsbBoot status fact] *********************************
2026-03-19 12:44:20.720502 | controller | Thursday 19 March 2026  12:44:20 +0000 (0:00:00.294)       0:00:08.880 ********
2026-03-19 12:44:20.720511 | controller | ok: [instance]
2026-03-19 12:44:20.748384 | controller |
2026-03-19 12:44:20.748401 | controller | TASK [bm_sno : Fail if GenericUsbBoot is disabled] *****************************
2026-03-19 12:44:20.748408 | controller | Thursday 19 March 2026  12:44:20 +0000 (0:00:00.029)       0:00:08.909 ********
2026-03-19 12:44:20.748417 | controller | skipping: [instance]
2026-03-19 12:44:21.025619 | controller |
2026-03-19 12:44:21.025649 | controller | TASK [Query mock state] ********************************************************
2026-03-19 12:44:21.025657 | controller | Thursday 19 March 2026  12:44:20 +0000 (0:00:00.027)       0:00:08.937 ********
2026-03-19 12:44:21.025667 | controller | ok: [instance]
2026-03-19 12:44:21.047106 | controller |
2026-03-19 12:44:21.047126 | controller | TASK [Assert host stayed Off (no power cycle needed)] **************************
2026-03-19 12:44:21.047134 | controller | Thursday 19 March 2026  12:44:21 +0000 (0:00:00.276)       0:00:09.214 ********
2026-03-19 12:44:21.047144 | controller | ok: [instance] => {
2026-03-19 12:44:21.047445 | controller |     "changed": false,
2026-03-19 12:44:21.047456 | controller |     "msg": "All assertions passed"
2026-03-19 12:44:21.047463 | controller | }
2026-03-19 12:44:21.047471 | controller |
2026-03-19 12:44:21.329207 | controller | TASK [Reset mock with usb_boot Disabled and host Off] **************************
2026-03-19 12:44:21.329237 | controller | Thursday 19 March 2026  12:44:21 +0000 (0:00:00.021)       0:00:09.236 ********
2026-03-19 12:44:21.329249 | controller | ok: [instance]
2026-03-19 12:44:21.356610 | controller |
2026-03-19 12:44:21.356631 | controller | TASK [Include bm_ensure_usb_boot with auto-enable] *****************************
2026-03-19 12:44:21.356639 | controller | Thursday 19 March 2026  12:44:21 +0000 (0:00:00.281)       0:00:09.517 ********
2026-03-19 12:44:21.356649 | controller |
2026-03-19 12:44:21.376163 | controller | TASK [bm_sno : Check current GenericUsbBoot state] *****************************
2026-03-19 12:44:21.376199 | controller | Thursday 19 March 2026  12:44:21 +0000 (0:00:00.027)       0:00:09.545 ********
2026-03-19 12:44:21.376213 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/tasks/bm_check_usb_boot.yml for instance
2026-03-19 12:44:21.376257 | controller |
2026-03-19 12:44:21.376377 | controller | TASK [bm_sno : Read GenericUsbBoot BIOS attribute] *****************************
2026-03-19 12:44:21.376397 | controller | Thursday 19 March 2026  12:44:21 +0000 (0:00:00.019)       0:00:09.565 ********
2026-03-19 12:44:21.655936 | controller | ok: [instance]
2026-03-19 12:44:21.685725 | controller |
2026-03-19 12:44:21.685745 | controller | TASK [bm_sno : Set GenericUsbBoot status fact] *********************************
2026-03-19 12:44:21.685753 | controller | Thursday 19 March 2026  12:44:21 +0000 (0:00:00.279)       0:00:09.844 ********
2026-03-19 12:44:21.685762 | controller | ok: [instance]
2026-03-19 12:44:21.711597 | controller |
2026-03-19 12:44:21.711615 | controller | TASK [bm_sno : Fail if GenericUsbBoot is disabled] *****************************
2026-03-19 12:44:21.711622 | controller | Thursday 19 March 2026  12:44:21 +0000 (0:00:00.030)       0:00:09.874 ********
2026-03-19 12:44:21.711631 | controller | fatal: [instance]: FAILED! => {"changed": false, "msg": "GenericUsbBoot is Disabled in BIOS. VirtualMedia cannot boot host localhost:8443."}
2026-03-19 12:44:21.716780 | controller |
2026-03-19 12:44:21.743165 | controller | TASK [bm_sno : Fail if auto-enable is off] *************************************
2026-03-19 12:44:21.743182 | controller | Thursday 19 March 2026  12:44:21 +0000 (0:00:00.031)       0:00:09.905 ********
2026-03-19 12:44:21.743193 | controller | skipping: [instance]
2026-03-19 12:44:22.027125 | controller |
2026-03-19 12:44:22.027166 | controller | TASK [bm_sno : Set GenericUsbBoot BIOS attribute] ******************************
2026-03-19 12:44:22.027174 | controller | Thursday 19 March 2026  12:44:21 +0000 (0:00:00.026)       0:00:09.932 ********
2026-03-19 12:44:22.027184 | controller | ok: [instance]
2026-03-19 12:44:22.027203 | controller |
2026-03-19 12:44:22.027407 | controller | TASK [bm_sno : Create BIOS config job to schedule the change] ******************
2026-03-19 12:44:22.312120 | controller | Thursday 19 March 2026  12:44:22 +0000 (0:00:00.283)       0:00:10.216 ********
2026-03-19 12:44:22.312159 | controller | ok: [instance]
2026-03-19 12:44:22.312238 | controller |
2026-03-19 12:44:22.312248 | controller | TASK [bm_sno : Power off before applying BIOS change] **************************
2026-03-19 12:44:22.312256 | controller | Thursday 19 March 2026  12:44:22 +0000 (0:00:00.284)       0:00:10.500 ********
2026-03-19 12:44:22.334520 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/tasks/bm_power_off.yml for instance
2026-03-19 12:44:22.616141 | controller |
2026-03-19 12:44:22.616171 | controller | TASK [bm_sno : Query current power state] **************************************
2026-03-19 12:44:22.616179 | controller | Thursday 19 March 2026  12:44:22 +0000 (0:00:00.022)       0:00:10.523 ********
2026-03-19 12:44:22.616189 | controller | ok: [instance]
2026-03-19 12:44:22.633581 | controller |
2026-03-19 12:44:22.633600 | controller | TASK [bm_sno : Force power off via Redfish] ************************************
2026-03-19 12:44:22.633608 | controller | Thursday 19 March 2026  12:44:22 +0000 (0:00:00.281)       0:00:10.804 ********
2026-03-19 12:44:22.633617 | controller | skipping: [instance]
2026-03-19 12:44:22.648449 | controller |
2026-03-19 12:44:22.648468 | controller | TASK [bm_sno : Wait for host to power off] *************************************
2026-03-19 12:44:22.648475 | controller | Thursday 19 March 2026  12:44:22 +0000 (0:00:00.017)       0:00:10.822 ********
2026-03-19 12:44:22.648484 | controller | skipping: [instance]
2026-03-19 12:44:22.671924 | controller |
2026-03-19 12:44:22.671943 | controller | TASK [bm_sno : Power on to apply BIOS config job during POST] ******************
2026-03-19 12:44:22.671950 | controller | Thursday 19 March 2026  12:44:22 +0000 (0:00:00.014)       0:00:10.837 ********
2026-03-19 12:44:22.671959 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/tasks/bm_power_on.yml for instance
2026-03-19 12:44:22.948622 | controller |
2026-03-19 12:44:22.948654 | controller | TASK [bm_sno : Query current power state] **************************************
2026-03-19 12:44:22.948662 | controller | Thursday 19 March 2026  12:44:22 +0000 (0:00:00.023)       0:00:10.861 ********
2026-03-19 12:44:22.948672 | controller | ok: [instance]
2026-03-19 12:44:23.228859 | controller |
2026-03-19 12:44:23.228889 | controller | TASK [bm_sno : Power on bare metal host] ***************************************
2026-03-19 12:44:23.228897 | controller | Thursday 19 March 2026  12:44:22 +0000 (0:00:00.276)       0:00:11.137 ********
2026-03-19 12:44:23.228913 | controller | ok: [instance]
2026-03-19 12:44:23.525222 | controller |
2026-03-19 12:44:23.525252 | controller | TASK [bm_sno : Wait for host POST to complete] *********************************
2026-03-19 12:44:23.525260 | controller | Thursday 19 March 2026  12:44:23 +0000 (0:00:00.280)       0:00:11.417 ********
2026-03-19 12:44:23.525271 | controller | ok: [instance]
2026-03-19 12:44:23.553908 | controller |
2026-03-19 12:44:23.553924 | controller | TASK [bm_sno : Show POST state] ************************************************
2026-03-19 12:44:23.553931 | controller | Thursday 19 March 2026  12:44:23 +0000 (0:00:00.296)       0:00:11.713 ********
2026-03-19 12:44:23.553940 | controller | ok: [instance] => {
2026-03-19 12:44:23.579134 | controller |     "msg": "POST state: FinishedPost"
2026-03-19 12:44:23.579166 | controller | }
2026-03-19 12:44:23.579176 | controller |
2026-03-19 12:44:23.579184 | controller | TASK [bm_sno : Power off after BIOS change applied] ****************************
2026-03-19 12:44:23.579191 | controller | Thursday 19 March 2026  12:44:23 +0000 (0:00:00.028)       0:00:11.742 ********
2026-03-19 12:44:23.579203 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/tasks/bm_power_off.yml for instance
2026-03-19 12:44:23.579237 | controller |
2026-03-19 12:44:23.579459 | controller | TASK [bm_sno : Query current power state] **************************************
2026-03-19 12:44:23.858177 | controller | Thursday 19 March 2026  12:44:23 +0000 (0:00:00.025)       0:00:11.768 ********
2026-03-19 12:44:23.858212 | controller | ok: [instance]
2026-03-19 12:44:24.136312 | controller |
2026-03-19 12:44:24.136343 | controller | TASK [bm_sno : Force power off via Redfish] ************************************
2026-03-19 12:44:24.136351 | controller | Thursday 19 March 2026  12:44:23 +0000 (0:00:00.278)       0:00:12.046 ********
2026-03-19 12:44:24.136361 | controller | ok: [instance]
2026-03-19 12:44:24.422148 | controller |
2026-03-19 12:44:24.422178 | controller | TASK [bm_sno : Wait for host to power off] *************************************
2026-03-19 12:44:24.422187 | controller | Thursday 19 March 2026  12:44:24 +0000 (0:00:00.278)       0:00:12.325 ********
2026-03-19 12:44:24.422197 | controller | ok: [instance]
2026-03-19 12:44:24.700903 | controller |
2026-03-19 12:44:24.700935 | controller | TASK [Query mock state after auto-enable] **************************************
2026-03-19 12:44:24.700943 | controller | Thursday 19 March 2026  12:44:24 +0000 (0:00:00.285)       0:00:12.610 ********
2026-03-19 12:44:24.700953 | controller | ok: [instance]
2026-03-19 12:44:24.722612 | controller |
2026-03-19 12:44:24.722632 | controller | TASK [Assert BIOS updated and host left Off] ***********************************
2026-03-19 12:44:24.722640 | controller | Thursday 19 March 2026  12:44:24 +0000 (0:00:00.278)       0:00:12.889 ********
2026-03-19 12:44:24.722649 | controller | ok: [instance] => {
2026-03-19 12:44:25.007334 | controller |     "changed": false,
2026-03-19 12:44:25.007365 | controller |     "msg": "All assertions passed"
2026-03-19 12:44:25.007373 | controller | }
2026-03-19 12:44:25.007379 | controller |
2026-03-19 12:44:25.007384 | controller | TASK [Reset mock with usb_boot Disabled] ***************************************
2026-03-19 12:44:25.007395 | controller | Thursday 19 March 2026  12:44:24 +0000 (0:00:00.021)       0:00:12.911 ********
2026-03-19 12:44:25.007405 | controller | ok: [instance]
2026-03-19 12:44:25.035439 | controller |
2026-03-19 12:44:25.035474 | controller | TASK [Include bm_ensure_usb_boot without auto-enable (expect failure)] *********
2026-03-19 12:44:25.035482 | controller | Thursday 19 March 2026  12:44:25 +0000 (0:00:00.284)       0:00:13.196 ********
2026-03-19 12:44:25.035493 | controller |
2026-03-19 12:44:25.054855 | controller | TASK [bm_sno : Check current GenericUsbBoot state] *****************************
2026-03-19 12:44:25.054880 | controller | Thursday 19 March 2026  12:44:25 +0000 (0:00:00.028)       0:00:13.224 ********
2026-03-19 12:44:25.054892 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/tasks/bm_check_usb_boot.yml for instance
2026-03-19 12:44:25.333733 | controller |
2026-03-19 12:44:25.333766 | controller | TASK [bm_sno : Read GenericUsbBoot BIOS attribute] *****************************
2026-03-19 12:44:25.333774 | controller | Thursday 19 March 2026  12:44:25 +0000 (0:00:00.019)       0:00:13.243 ********
2026-03-19 12:44:25.333785 | controller | ok: [instance]
2026-03-19 12:44:25.363462 | controller |
2026-03-19 12:44:25.363497 | controller | TASK [bm_sno : Set GenericUsbBoot status fact] *********************************
2026-03-19 12:44:25.363505 | controller | Thursday 19 March 2026  12:44:25 +0000 (0:00:00.278)       0:00:13.522 ********
2026-03-19 12:44:25.363516 | controller | ok: [instance]
2026-03-19 12:44:25.388649 | controller |
2026-03-19 12:44:25.388677 | controller | TASK [bm_sno : Fail if GenericUsbBoot is disabled] *****************************
2026-03-19 12:44:25.388685 | controller | Thursday 19 March 2026  12:44:25 +0000 (0:00:00.029)       0:00:13.552 ********
2026-03-19 12:44:25.388695 | controller | fatal: [instance]: FAILED! => {"changed": false, "msg": "GenericUsbBoot is Disabled in BIOS. VirtualMedia cannot boot host localhost:8443."}
2026-03-19 12:44:25.393262 | controller |
2026-03-19 12:44:25.417626 | controller | TASK [bm_sno : Fail if auto-enable is off] *************************************
2026-03-19 12:44:25.417644 | controller | Thursday 19 March 2026  12:44:25 +0000 (0:00:00.030)       0:00:13.582 ********
2026-03-19 12:44:25.417654 | 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-19 12:44:25.422477 | controller |
2026-03-19 12:44:25.442413 | controller | TASK [Assert failure mentions GenericUsbBoot or auto-enable] *******************
2026-03-19 12:44:25.442430 | controller | Thursday 19 March 2026  12:44:25 +0000 (0:00:00.029)       0:00:13.611 ********
2026-03-19 12:44:25.442440 | controller | ok: [instance] => {
2026-03-19 12:44:25.472086 | controller |     "changed": false,
2026-03-19 12:44:25.472112 | controller |     "msg": "All assertions passed"
2026-03-19 12:44:25.472121 | controller | }
2026-03-19 12:44:25.472129 | controller |
2026-03-19 12:44:25.472136 | controller | TASK [Test bm_eject_vmedia] ****************************************************
2026-03-19 12:44:25.472143 | controller | Thursday 19 March 2026  12:44:25 +0000 (0:00:00.019)       0:00:13.631 ********
2026-03-19 12:44:25.472153 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/molecule/bm_redfish/tasks/test_eject_vmedia.yml for instance
2026-03-19 12:44:25.472335 | controller |
2026-03-19 12:44:25.472484 | controller | TASK [Reset mock with VirtualMedia inserted] ***********************************
2026-03-19 12:44:25.472618 | controller | Thursday 19 March 2026  12:44:25 +0000 (0:00:00.030)       0:00:13.661 ********
2026-03-19 12:44:25.755103 | controller | ok: [instance]
2026-03-19 12:44:25.780514 | controller |
2026-03-19 12:44:25.780536 | controller | TASK [Include bm_eject_vmedia] *************************************************
2026-03-19 12:44:25.780546 | controller | Thursday 19 March 2026  12:44:25 +0000 (0:00:00.282)       0:00:13.943 ********
2026-03-19 12:44:25.780558 | controller |
2026-03-19 12:44:26.062123 | controller | TASK [bm_sno : Eject VirtualMedia] *********************************************
2026-03-19 12:44:26.062153 | controller | Thursday 19 March 2026  12:44:25 +0000 (0:00:00.025)       0:00:13.969 ********
2026-03-19 12:44:26.062164 | controller | ok: [instance]
2026-03-19 12:44:26.062189 | controller |
2026-03-19 12:44:26.062415 | controller | TASK [bm_sno : Wait for VirtualMedia eject to settle] **************************
2026-03-19 12:44:31.082203 | controller | Thursday 19 March 2026  12:44:26 +0000 (0:00:00.281)       0:00:14.251 ********
2026-03-19 12:44:31.082249 | controller | Pausing for 5 seconds
2026-03-19 12:44:31.082278 | controller | ok: [instance]
2026-03-19 12:44:31.082285 | controller |
2026-03-19 12:44:31.082292 | controller | TASK [bm_sno : Check Remote File Share status] *********************************
2026-03-19 12:44:31.353072 | controller | Thursday 19 March 2026  12:44:31 +0000 (0:00:05.019)       0:00:19.270 ********
2026-03-19 12:44:31.353109 | controller | fatal: [instance]: FAILED! => {"censored": "the output has been hidden due to the fact that 'no_log: true' was specified for this result", "changed": true}
2026-03-19 12:44:31.357126 | controller |
2026-03-19 12:44:31.357417 | controller | PLAY RECAP *********************************************************************
2026-03-19 12:44:31.357429 | controller | instance                   : ok=76   changed=0    unreachable=0    failed=1    skipped=8    rescued=4    ignored=0
2026-03-19 12:44:31.357436 | controller |
2026-03-19 12:44:31.357441 | controller | Thursday 19 March 2026  12:44:31 +0000 (0:00:00.273)       0:00:19.544 ********
2026-03-19 12:44:31.357451 | controller | ===============================================================================
2026-03-19 12:44:31.357456 | controller | bm_sno : Wait for VirtualMedia eject to settle -------------------------- 5.02s
2026-03-19 12:44:31.357466 | controller | Reset mock to power Off ------------------------------------------------- 0.39s
2026-03-19 12:44:31.357471 | controller | bm_sno : Wait for host POST to complete --------------------------------- 0.30s
2026-03-19 12:44:31.357477 | controller | bm_sno : Wait for host POST to complete --------------------------------- 0.30s
2026-03-19 12:44:31.357482 | controller | bm_sno : Wait for host POST to complete --------------------------------- 0.29s
2026-03-19 12:44:31.357487 | controller | bm_sno : Read GenericUsbBoot BIOS attribute ----------------------------- 0.29s
2026-03-19 12:44:31.357493 | controller | Query mock state after power_off (was on) ------------------------------- 0.29s
2026-03-19 12:44:31.357498 | controller | bm_sno : Wait for host POST to complete --------------------------------- 0.29s
2026-03-19 12:44:31.357503 | controller | Reset mock to power On -------------------------------------------------- 0.29s
2026-03-19 12:44:31.357508 | controller | Reset mock with usb_boot Enabled and host Off --------------------------- 0.29s
2026-03-19 12:44:31.357513 | controller | Query mock state after power_on (already on) ---------------------------- 0.29s
2026-03-19 12:44:31.357519 | controller | bm_sno : Query current power state -------------------------------------- 0.29s
2026-03-19 12:44:31.357524 | controller | bm_sno : Wait for host to power off ------------------------------------- 0.29s
2026-03-19 12:44:31.357529 | controller | bm_sno : Read GenericUsbBoot BIOS attribute ----------------------------- 0.29s
2026-03-19 12:44:31.357534 | controller | bm_sno : Query current power state -------------------------------------- 0.29s
2026-03-19 12:44:31.357539 | controller | bm_sno : Wait for host to power off ------------------------------------- 0.28s
2026-03-19 12:44:31.357545 | controller | bm_sno : Create BIOS config job to schedule the change ------------------ 0.28s
2026-03-19 12:44:31.357552 | controller | Reset mock with usb_boot Disabled --------------------------------------- 0.28s
2026-03-19 12:44:31.405333 | controller | Query mock state after power_off (already off) -------------------------- 0.28s
2026-03-19 12:44:31.405364 | controller | Reset mock with usb_boot Enabled ---------------------------------------- 0.28s
2026-03-19 12:44:31.405378 | controller | CRITICAL Ansible return code was 2, command was: ['ansible-playbook', '--inventory', '/home/zuul/.cache/molecule/bm_sno/bm_redfish/inventory', '--skip-tags', 'molecule-notest,notest', '/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/bm_sno/molecule/bm_redfish/converge.yml']
2026-03-19 12:44:31.405790 | controller | WARNING  An error occurred during the test sequence action: 'converge'. Cleaning up.
2026-03-19 12:44:31.414077 | controller | INFO     Running bm_redfish > cleanup
2026-03-19 12:44:31.826105 | controller |
2026-03-19 12:44:32.106526 | controller | PLAY [Cleanup mock iDRAC server] ***********************************************
2026-03-19 12:44:32.106558 | controller |
2026-03-19 12:44:32.106565 | controller | TASK [Stop mock iDRAC server] **************************************************
2026-03-19 12:44:32.106571 | controller | Thursday 19 March 2026  12:44:31 +0000 (0:00:00.022)       0:00:00.022 ********
2026-03-19 12:44:32.106581 | controller | ok: [instance]
2026-03-19 12:44:32.283547 | controller |
2026-03-19 12:44:32.283573 | controller | TASK [Show mock server log] ****************************************************
2026-03-19 12:44:32.283582 | controller | Thursday 19 March 2026  12:44:32 +0000 (0:00:00.280)       0:00:00.303 ********
2026-03-19 12:44:32.283592 | controller | ok: [instance]
2026-03-19 12:44:32.328099 | controller |
2026-03-19 12:44:32.328119 | controller | TASK [Print mock server log] ***************************************************
2026-03-19 12:44:32.328127 | controller | Thursday 19 March 2026  12:44:32 +0000 (0:00:00.177)       0:00:00.480 ********
2026-03-19 12:44:32.328137 | controller | ok: [instance] => {
2026-03-19 12:44:32.328227 | controller |     "_mock_log.stdout_lines": [
2026-03-19 12:44:32.328237 | controller |         "Mock iDRAC listening on https://0.0.0.0:8443",
2026-03-19 12:44:32.328243 | controller |         "[mock-idrac] \"GET /test/state HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328256 | controller |         "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328262 | controller |         "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328267 | controller |         "[mock-idrac] \"GET /test/state HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328278 | controller |         "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328283 | controller |         "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328289 | controller |         "[mock-idrac] \"POST /redfish/v1/Systems/System.Embedded.1/Actions/ComputerSystem.Reset HTTP/1.1\" 204 -",
2026-03-19 12:44:32.328294 | controller |         "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328300 | controller |         "[mock-idrac] \"GET /test/state HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328305 | controller |         "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328310 | controller |         "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328320 | controller |         "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328325 | controller |         "[mock-idrac] \"GET /test/state HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328331 | controller |         "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328336 | controller |         "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328341 | controller |         "[mock-idrac] \"POST /redfish/v1/Systems/System.Embedded.1/Actions/ComputerSystem.Reset HTTP/1.1\" 204 -",
2026-03-19 12:44:32.328346 | controller |         "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328352 | controller |         "[mock-idrac] \"GET /test/state HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328357 | controller |         "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328362 | controller |         "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328367 | controller |         "[mock-idrac] \"POST /redfish/v1/Systems/System.Embedded.1/Actions/ComputerSystem.Reset HTTP/1.1\" 204 -",
2026-03-19 12:44:32.328373 | controller |         "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328378 | controller |         "[mock-idrac] \"GET /test/state HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328383 | controller |         "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328388 | controller |         "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1/Bios HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328394 | controller |         "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328401 | controller |         "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1/Bios HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328551 | controller |         "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328688 | controller |         "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1/Bios HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328821 | controller |         "[mock-idrac] \"GET /test/state HTTP/1.1\" 200 -",
2026-03-19 12:44:32.328952 | controller |         "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
2026-03-19 12:44:32.329116 | controller |         "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1/Bios HTTP/1.1\" 200 -",
2026-03-19 12:44:32.329258 | controller |         "[mock-idrac] \"PATCH /redfish/v1/Systems/System.Embedded.1/Bios/Settings HTTP/1.1\" 200 -",
2026-03-19 12:44:32.329390 | controller |         "[mock-idrac] \"POST /redfish/v1/Managers/iDRAC.Embedded.1/Jobs HTTP/1.1\" 200 -",
2026-03-19 12:44:32.329520 | controller |         "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
2026-03-19 12:44:32.329648 | controller |         "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
2026-03-19 12:44:32.329783 | controller |         "[mock-idrac] \"POST /redfish/v1/Systems/System.Embedded.1/Actions/ComputerSystem.Reset HTTP/1.1\" 204 -",
2026-03-19 12:44:32.329917 | controller |         "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
2026-03-19 12:44:32.330079 | controller |         "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
2026-03-19 12:44:32.330240 | controller |         "[mock-idrac] \"POST /redfish/v1/Systems/System.Embedded.1/Actions/ComputerSystem.Reset HTTP/1.1\" 204 -",
2026-03-19 12:44:32.330376 | controller |         "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1 HTTP/1.1\" 200 -",
2026-03-19 12:44:32.330505 | controller |         "[mock-idrac] \"GET /test/state HTTP/1.1\" 200 -",
2026-03-19 12:44:32.330639 | controller |         "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
2026-03-19 12:44:32.330772 | controller |         "[mock-idrac] \"GET /redfish/v1/Systems/System.Embedded.1/Bios HTTP/1.1\" 200 -",
2026-03-19 12:44:32.330908 | controller |         "[mock-idrac] \"POST /test/reset HTTP/1.1\" 200 -",
2026-03-19 12:44:32.331069 | controller |         "[mock-idrac] \"POST /redfish/v1/Managers/iDRAC.Embedded.1/VirtualMedia/CD/Actions/VirtualMedia.EjectMedia HTTP/1.1\" 204 -"
2026-03-19 12:44:32.331220 | controller |     ]
2026-03-19 12:44:32.331354 | controller | }
2026-03-19 12:44:32.331485 | controller |
2026-03-19 12:44:32.331611 | controller | PLAY RECAP *********************************************************************
2026-03-19 12:44:32.331744 | controller | instance                   : ok=3    changed=0    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2026-03-19 12:44:32.331861 | controller |
2026-03-19 12:44:32.331988 | controller | Thursday 19 March 2026  12:44:32 +0000 (0:00:00.042)       0:00:00.523 ********
2026-03-19 12:44:32.332146 | controller | ===============================================================================
2026-03-19 12:44:32.332280 | controller | Stop mock iDRAC server -------------------------------------------------- 0.28s
2026-03-19 12:44:32.332407 | controller | Show mock server log ---------------------------------------------------- 0.18s
2026-03-19 12:44:32.332533 | controller | Print mock server log --------------------------------------------------- 0.04s
2026-03-19 12:44:32.381491 | controller | INFO     Running bm_redfish > destroy
2026-03-19 12:44:32.381865 | controller | WARNING  Skipping, instances are delegated.
2026-03-19 12:44:32.382234 | controller | INFO     Pruning extra files from scenario ephemeral directory
2026-03-19 12:44:32.383708 | controller | INFO     Writing /tmp/report.html report.
2026-03-19 12:44:32.783656 | controller | ERROR
2026-03-19 12:44:32.783775 | controller | {
2026-03-19 12:44:32.783817 | controller |   "delta": "0:00:24.387746",
2026-03-19 12:44:32.783838 | controller |   "end": "2026-03-19 12:44:32.429683",
2026-03-19 12:44:32.783855 | controller |   "msg": "non-zero return code",
2026-03-19 12:44:32.783870 | controller |   "rc": 1,
2026-03-19 12:44:32.783885 | controller |   "start": "2026-03-19 12:44:08.041937"
2026-03-19 12:44:32.783900 | controller | }
failure
2026-03-19 12:44:32.789066 | 
2026-03-19 12:44:32.789116 | PLAY RECAP
2026-03-19 12:44:32.789157 | controller | ok: 3 changed: 0 unreachable: 0 failed: 1 skipped: 1 rescued: 0 ignored: 0
2026-03-19 12:44:32.789179 | 
2026-03-19 12:44:32.857045 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2026-03-19 12:44:32.858127 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2026-03-19 12:44:33.389185 | 
2026-03-19 12:44:33.389312 | PLAY [Run ci/playbooks/collect-logs.yml]
2026-03-19 12:44:33.409988 | 
2026-03-19 12:44:33.410065 | TASK [Filter out host if needed]
2026-03-19 12:44:33.418640 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2026-03-19 12:44:33.423117 | 
2026-03-19 12:44:33.423186 | TASK [Ensure file is present]
2026-03-19 12:44:33.726189 | controller | ok
2026-03-19 12:44:33.732951 | 
2026-03-19 12:44:33.733018 | TASK [Manage molecule report file]
2026-03-19 12:44:34.255193 | controller | changed
2026-03-19 12:44:34.260393 | 
2026-03-19 12:44:34.260458 | TASK [Check if we get ci-framework-data basedir]
2026-03-19 12:44:34.451310 | controller | ok
2026-03-19 12:44:34.456373 | 
2026-03-19 12:44:34.456439 | TASK [Create ci-framework-data log directory for zuul]
2026-03-19 12:44:34.780094 | controller | changed
2026-03-19 12:44:34.785468 | 
2026-03-19 12:44:34.785538 | TASK [Copy ci-framework interesting files]
2026-03-19 12:44:34.978629 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory
2026-03-19 12:44:35.312114 | controller | changed
2026-03-19 12:44:35.317687 | 
2026-03-19 12:44:35.317768 | TASK [Get SELinux listing]
2026-03-19 12:44:35.843106 | controller | changed
2026-03-19 12:44:35.848602 | 
2026-03-19 12:44:35.848666 | TASK [Generate log index]
2026-03-19 12:44:36.506103 | controller | changed
2026-03-19 12:44:36.511010 | 
2026-03-19 12:44:36.511073 | TASK [Get some env related data]
2026-03-19 12:44:37.045861 | controller | /home/zuul/.local/bin/ansible
2026-03-19 12:44:38.039793 | controller | changed
2026-03-19 12:44:38.045162 | 
2026-03-19 12:44:38.045224 | TASK [Generate list of logs to collect in home directory]
2026-03-19 12:44:38.327548 | controller | ok: All paths examined
2026-03-19 12:44:38.332552 | 
2026-03-19 12:44:38.332615 | LOOP [Copy logs from home directory]
2026-03-19 12:44:38.637421 | controller | changed:
2026-03-19 12:44:38.637533 | controller | {
2026-03-19 12:44:38.637560 | controller |   "atime": 1773924229.5239334,
2026-03-19 12:44:38.637581 | controller |   "ctime": 1773924245.7501473,
2026-03-19 12:44:38.637599 | controller |   "dev": 64513,
2026-03-19 12:44:38.637616 | controller |   "gid": 1000,
2026-03-19 12:44:38.637633 | controller |   "gr_name": "zuul",
2026-03-19 12:44:38.637650 | controller |   "inode": 54810,
2026-03-19 12:44:38.637666 | controller |   "isblk": false,
2026-03-19 12:44:38.637682 | controller |   "ischr": false,
2026-03-19 12:44:38.637696 | controller |   "isdir": false,
2026-03-19 12:44:38.637711 | controller |   "isfifo": false,
2026-03-19 12:44:38.637726 | controller |   "isgid": false,
2026-03-19 12:44:38.637740 | controller |   "islnk": false,
2026-03-19 12:44:38.637755 | controller |   "isreg": true,
2026-03-19 12:44:38.637769 | controller |   "issock": false,
2026-03-19 12:44:38.637784 | controller |   "isuid": false,
2026-03-19 12:44:38.637798 | controller |   "mode": "0644",
2026-03-19 12:44:38.637812 | controller |   "mtime": 1773924245.7501473,
2026-03-19 12:44:38.637826 | controller |   "nlink": 1,
2026-03-19 12:44:38.637841 | controller |   "path": "/home/zuul/ansible.log",
2026-03-19 12:44:38.637857 | controller |   "pw_name": "zuul",
2026-03-19 12:44:38.637872 | controller |   "rgrp": true,
2026-03-19 12:44:38.637887 | controller |   "roth": true,
2026-03-19 12:44:38.637902 | controller |   "rusr": true,
2026-03-19 12:44:38.637918 | controller |   "size": 6749,
2026-03-19 12:44:38.637949 | controller |   "uid": 1000,
2026-03-19 12:44:38.637965 | controller |   "wgrp": false,
2026-03-19 12:44:38.637981 | controller |   "woth": false,
2026-03-19 12:44:38.637998 | controller |   "wusr": true,
2026-03-19 12:44:38.638014 | controller |   "xgrp": false,
2026-03-19 12:44:38.638029 | controller |   "xoth": false,
2026-03-19 12:44:38.638044 | controller |   "xusr": false
2026-03-19 12:44:38.638058 | controller | }
2026-03-19 12:44:38.651827 | 
2026-03-19 12:44:38.651954 | TASK [Copy crio stats log file]
2026-03-19 12:44:38.666113 | controller | skipping: Conditional result was False
2026-03-19 12:44:38.671631 | 
2026-03-19 12:44:38.671711 | TASK [Get SELinux related data]
2026-03-19 12:44:38.877932 | controller | <no matches>
2026-03-19 12:44:39.198677 | controller | ERROR
2026-03-19 12:44:39.198890 | controller | {
2026-03-19 12:44:39.198940 | controller |   "delta": "0:00:00.009110",
2026-03-19 12:44:39.198965 | controller |   "end": "2026-03-19 12:44:38.879376",
2026-03-19 12:44:39.198986 | controller |   "msg": "non-zero return code",
2026-03-19 12:44:39.199004 | controller |   "rc": 1,
2026-03-19 12:44:39.199020 | controller |   "start": "2026-03-19 12:44:38.870266"
2026-03-19 12:44:39.199036 | controller | }
2026-03-19 12:44:39.199058 | controller | ERROR: Ignoring Errors
2026-03-19 12:44:39.204545 | 
2026-03-19 12:44:39.204608 | TASK [Create system configuration directory]
2026-03-19 12:44:39.385244 | controller | changed
2026-03-19 12:44:39.390113 | 
2026-03-19 12:44:39.390176 | TASK [Get some of the system configurations]
2026-03-19 12:44:39.916262 | controller | changed
2026-03-19 12:44:39.921443 | 
2026-03-19 12:44:39.921505 | TASK [Copy generated documentation if available]
2026-03-19 12:44:39.935093 | controller | skipping: Conditional result was False
2026-03-19 12:44:39.940672 | 
2026-03-19 12:44:39.940732 | TASK [Copy generated AsciiDoc documentation if available]
2026-03-19 12:44:39.954003 | controller | skipping: Conditional result was False
2026-03-19 12:44:39.959803 | 
2026-03-19 12:44:39.959864 | TASK [Compress logs bigger than 2MB]
2026-03-19 12:44:40.485433 | controller | changed
2026-03-19 12:44:40.491036 | 
2026-03-19 12:44:40.491100 | TASK [Copy files from workspace on node]
2026-03-19 12:44:40.509530 | controller | ok
2026-03-19 12:44:40.531692 | 
2026-03-19 12:44:40.531758 | TASK [fetch-output : Set log path for multiple nodes]
2026-03-19 12:44:40.555531 | controller | skipping: Conditional result was False
2026-03-19 12:44:40.560834 | 
2026-03-19 12:44:40.560901 | TASK [fetch-output : Set log path for single node]
2026-03-19 12:44:40.588943 | controller | ok
2026-03-19 12:44:40.595072 | 
2026-03-19 12:44:40.595134 | LOOP [fetch-output : Ensure local output dirs]
2026-03-19 12:44:40.797545 | controller -> localhost | ok: "/var/lib/zuul/builds/cd8ff0e6062f4fd3b8b02c28055504c2/work/logs"
2026-03-19 12:44:40.797782 | controller -> localhost | changed: All items complete
2026-03-19 12:44:40.797821 | 
2026-03-19 12:44:40.983615 | controller -> localhost | changed: "/var/lib/zuul/builds/cd8ff0e6062f4fd3b8b02c28055504c2/work/artifacts"
2026-03-19 12:44:41.161666 | controller -> localhost | changed: "/var/lib/zuul/builds/cd8ff0e6062f4fd3b8b02c28055504c2/work/docs"
2026-03-19 12:44:41.173718 | 
2026-03-19 12:44:41.173826 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-03-19 12:44:41.696671 | controller | changed:
2026-03-19 12:44:41.696893 | controller | .d..t...... ./
2026-03-19 12:44:41.696938 | controller | >f+++++++++ README.html
2026-03-19 12:44:41.696962 | controller | >f+++++++++ ansible-execution.log
2026-03-19 12:44:41.696982 | controller | >f+++++++++ ansible.log
2026-03-19 12:44:41.696999 | controller | >f+++++++++ dmesg.log
2026-03-19 12:44:41.697016 | controller | >f+++++++++ installed-pkgs.log
2026-03-19 12:44:41.697035 | controller | >f+++++++++ python.log
2026-03-19 12:44:41.697053 | controller | >f+++++++++ registries.conf
2026-03-19 12:44:41.697071 | controller | >f+++++++++ report.html
2026-03-19 12:44:41.697091 | controller | >f+++++++++ selinux-denials.log
2026-03-19 12:44:41.697108 | controller | >f+++++++++ selinux-listing.log
2026-03-19 12:44:41.697125 | controller | cd+++++++++ ci-framework-data/
2026-03-19 12:44:41.697141 | controller | cd+++++++++ ci-framework-data/artifacts/
2026-03-19 12:44:41.697158 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2026-03-19 12:44:41.697175 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2026-03-19 12:44:41.697191 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2026-03-19 12:44:41.697214 | controller | cd+++++++++ ci-framework-data/logs/
2026-03-19 12:44:41.697231 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2026-03-19 12:44:41.697246 | controller | cd+++++++++ registries.conf.d/
2026-03-19 12:44:41.697260 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2026-03-19 12:44:41.697275 | controller | cd+++++++++ system-config/
2026-03-19 12:44:41.697290 | controller | cd+++++++++ system-config/libvirt/
2026-03-19 12:44:41.697329 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2026-03-19 12:44:41.697347 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2026-03-19 12:44:42.066940 | controller | changed: .d..t...... ./
2026-03-19 12:44:42.441267 | controller | changed: .d..t...... ./
2026-03-19 12:44:42.453389 | 
2026-03-19 12:44:42.453455 | TASK [Return artifact to Zuul]
2026-03-19 12:44:42.482792 | controller | ok
2026-03-19 12:44:42.501385 | 
2026-03-19 12:44:42.501445 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2026-03-19 12:44:42.501551 | 
2026-03-19 12:44:42.501578 | PLAY RECAP
2026-03-19 12:44:42.501613 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2026-03-19 12:44:42.501634 | 
2026-03-19 12:44:42.575230 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2026-03-19 12:44:42.576052 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2026-03-19 12:44:43.096103 | 
2026-03-19 12:44:43.096214 | PLAY [all]
2026-03-19 12:44:43.114452 | 
2026-03-19 12:44:43.114527 | TASK [include_role : fetch-output]
2026-03-19 12:44:43.142576 | controller | ok
2026-03-19 12:44:43.158780 | 
2026-03-19 12:44:43.158867 | TASK [fetch-output : Set log path for multiple nodes]
2026-03-19 12:44:43.202450 | controller | skipping: Conditional result was False
2026-03-19 12:44:43.207819 | 
2026-03-19 12:44:43.207888 | TASK [fetch-output : Set log path for single node]
2026-03-19 12:44:43.236100 | controller | ok
2026-03-19 12:44:43.240965 | 
2026-03-19 12:44:43.241034 | LOOP [fetch-output : Ensure local output dirs]
2026-03-19 12:44:43.556792 | controller -> localhost | ok: "/var/lib/zuul/builds/cd8ff0e6062f4fd3b8b02c28055504c2/work/logs"
2026-03-19 12:44:43.746144 | controller -> localhost | ok: "/var/lib/zuul/builds/cd8ff0e6062f4fd3b8b02c28055504c2/work/artifacts"
2026-03-19 12:44:43.938263 | controller -> localhost | ok: "/var/lib/zuul/builds/cd8ff0e6062f4fd3b8b02c28055504c2/work/docs"
2026-03-19 12:44:43.950448 | 
2026-03-19 12:44:43.950516 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-03-19 12:44:44.466231 | controller | ok
2026-03-19 12:44:44.466460 | controller | ok: All items complete
2026-03-19 12:44:44.466491 | 
2026-03-19 12:44:44.841469 | controller | ok
2026-03-19 12:44:45.221498 | controller | ok
2026-03-19 12:44:45.236361 | 
2026-03-19 12:44:45.236563 | TASK [include_role : fetch-output-openshift]
2026-03-19 12:44:45.253494 | controller | skipping: Conditional result was False
2026-03-19 12:44:45.260863 | 
2026-03-19 12:44:45.260945 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-03-19 12:44:45.624855 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.009616
2026-03-19 12:44:45.839796 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.011644
2026-03-19 12:44:45.872140 | 
2026-03-19 12:44:45.872349 | PLAY [all]
2026-03-19 12:44:45.886459 | 
2026-03-19 12:44:45.886534 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-03-19 12:44:46.285604 | controller | changed
2026-03-19 12:44:46.307043 | 
2026-03-19 12:44:46.307101 | PLAY RECAP
2026-03-19 12:44:46.307154 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2026-03-19 12:44:46.307176 | 
2026-03-19 12:44:46.403224 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2026-03-19 12:44:46.403985 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2026-03-19 12:44:46.980180 | 
2026-03-19 12:44:46.980366 | PLAY [localhost]
2026-03-19 12:44:46.998256 | 
2026-03-19 12:44:46.998355 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-03-19 12:44:47.324246 | localhost | changed
2026-03-19 12:44:47.330473 | 
2026-03-19 12:44:47.330564 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-03-19 12:44:47.361550 | localhost | ok
2026-03-19 12:44:47.369699 | 
2026-03-19 12:44:47.369774 | TASK [add-fileserver : Create SSH private key tempfile]
2026-03-19 12:44:47.684939 | localhost | changed
2026-03-19 12:44:47.692054 | 
2026-03-19 12:44:47.692179 | TASK [add-fileserver : Create SSH private key from secret]
2026-03-19 12:44:48.252327 | localhost | changed
2026-03-19 12:44:48.258226 | 
2026-03-19 12:44:48.258344 | TASK [add-fileserver : Add fileserver ssh key]
2026-03-19 12:44:48.591072 | localhost | Identity added: /var/lib/zuul/builds/cd8ff0e6062f4fd3b8b02c28055504c2/work/tmp/ansible.6grp15bt (/var/lib/zuul/builds/cd8ff0e6062f4fd3b8b02c28055504c2/work/tmp/ansible.6grp15bt)
2026-03-19 12:44:48.591260 | localhost | ok: Runtime: 0:00:00.007120
2026-03-19 12:44:48.595566 | 
2026-03-19 12:44:48.595638 | TASK [add-fileserver : Remove SSH private key from disk]
2026-03-19 12:44:48.816384 | localhost | ok: Runtime: 0:00:00.005313
2026-03-19 12:44:48.821456 | 
2026-03-19 12:44:48.821558 | TASK [add-fileserver : Add fileserver to inventory]
2026-03-19 12:44:48.871136 | localhost | changed
2026-03-19 12:44:48.875436 | 
2026-03-19 12:44:48.875514 | TASK [add-fileserver : Add fileserver server to known hosts]
2026-03-19 12:44:49.197020 | localhost | changed
2026-03-19 12:44:49.216093 | 
2026-03-19 12:44:49.216163 | PLAY [localhost]
2026-03-19 12:44:49.227142 | 
2026-03-19 12:44:49.227207 | TASK [Generate bulk log download script]
2026-03-19 12:44:49.245575 | localhost | ok
2026-03-19 12:44:49.256801 | 
2026-03-19 12:44:49.256868 | TASK [local-log-download : Check API endpoint is defined]
2026-03-19 12:44:49.284546 | localhost | ok: All assertions passed
2026-03-19 12:44:49.288949 | 
2026-03-19 12:44:49.289014 | TASK [local-log-download : Create download script]
2026-03-19 12:44:49.646817 | localhost -> localhost | changed
2026-03-19 12:44:49.655485 | 
2026-03-19 12:44:49.655569 | TASK [Register quick-download link]
2026-03-19 12:44:49.672272 | localhost | ok
2026-03-19 12:44:49.705852 | 
2026-03-19 12:44:49.705952 | PLAY [logserver.rdoproject.org]
2026-03-19 12:44:49.717525 | 
2026-03-19 12:44:49.717759 | TASK [Set zuul-log-path fact]
2026-03-19 12:44:49.737766 | logserver.rdoproject.org | ok
2026-03-19 12:44:49.747140 | 
2026-03-19 12:44:49.747217 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-03-19 12:44:49.774130 | logserver.rdoproject.org | ok
2026-03-19 12:44:49.779437 | 
2026-03-19 12:44:49.779504 | TASK [upload-logs : Create log directories]
2026-03-19 12:44:51.442655 | logserver.rdoproject.org | changed
2026-03-19 12:44:51.445964 | 
2026-03-19 12:44:51.446045 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-03-19 12:44:51.674004 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.005000
2026-03-19 12:44:51.678939 | 
2026-03-19 12:44:51.679020 | TASK [upload-logs : Upload logs to log server]
2026-03-19 12:44:53.147817 | logserver.rdoproject.org | Output suppressed because no_log was given
2026-03-19 12:44:53.150634 | 
2026-03-19 12:44:53.150697 | LOOP [upload-logs : Compress console log and json output]
2026-03-19 12:44:53.188561 | logserver.rdoproject.org | skipping: Conditional result was False
2026-03-19 12:44:53.196528 | logserver.rdoproject.org | skipping: Conditional result was False
2026-03-19 12:44:53.208062 | 
2026-03-19 12:44:53.208132 | LOOP [upload-logs : Upload compressed console log and json output]
2026-03-19 12:44:53.241853 | logserver.rdoproject.org | skipping: Conditional result was False
2026-03-19 12:44:53.242071 | 
2026-03-19 12:44:53.245629 | logserver.rdoproject.org | skipping: Conditional result was False
2026-03-19 12:44:53.256062 | 
2026-03-19 12:44:53.256133 | LOOP [upload-logs : Upload console log and json output]