2026-03-09 15:23:13.877274 | Job console starting 2026-03-09 15:23:13.886162 | Updating git repos 2026-03-09 15:23:13.929331 | Cloning repos into workspace 2026-03-09 15:23:14.036310 | Restoring repo states 2026-03-09 15:23:14.058898 | Merging changes 2026-03-09 15:23:14.727202 | Checking out repos 2026-03-09 15:23:15.000039 | Preparing playbooks 2026-03-09 15:23:16.111151 | Running Ansible setup 2026-03-09 15:23:20.185909 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main] 2026-03-09 15:23:20.914242 | 2026-03-09 15:23:20.914383 | PLAY [localhost] 2026-03-09 15:23:20.922698 | 2026-03-09 15:23:20.922775 | TASK [Gathering Facts] 2026-03-09 15:23:22.024594 | localhost | ok 2026-03-09 15:23:22.034813 | 2026-03-09 15:23:22.034945 | TASK [Setup log path fact] 2026-03-09 15:23:22.056805 | localhost | ok 2026-03-09 15:23:22.070865 | 2026-03-09 15:23:22.071183 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-03-09 15:23:22.101269 | localhost | ok 2026-03-09 15:23:22.107877 | 2026-03-09 15:23:22.107954 | TASK [emit-job-header : Print job information] 2026-03-09 15:23:22.149023 | # Job Information 2026-03-09 15:23:22.161688 | Ansible Version: 2.16.16 2026-03-09 15:23:22.161803 | Job: ansible-collection-kubernetes-molecule-aio-rockylinux-9 2026-03-09 15:23:22.161860 | Pipeline: check 2026-03-09 15:23:22.161906 | Executor: 0a8996d2b663 2026-03-09 15:23:22.161948 | Triggered by: https://github.com/vexxhost/ansible-collection-kubernetes/pull/236 2026-03-09 15:23:22.161996 | Event ID: c2871620-1bcb-11f1-9a65-bf7aaf81b926 2026-03-09 15:23:22.168739 | 2026-03-09 15:23:22.168817 | LOOP [emit-job-header : Print node information] 2026-03-09 15:23:22.266850 | localhost | ok: 2026-03-09 15:23:22.267038 | localhost | # Node Information 2026-03-09 15:23:22.267068 | localhost | Inventory Hostname: controller 2026-03-09 15:23:22.267091 | localhost | Hostname: np0000158202 2026-03-09 15:23:22.267112 | localhost | Username: zuul 2026-03-09 15:23:22.267134 | localhost | Distro: Rocky 9.7 2026-03-09 15:23:22.267155 | localhost | Provider: yul1 2026-03-09 15:23:22.267174 | localhost | Region: ca-ymq-1 2026-03-09 15:23:22.267194 | localhost | Label: rockylinux-9 2026-03-09 15:23:22.267213 | localhost | Product Name: OpenStack Nova 2026-03-09 15:23:22.267232 | localhost | Interface IP: 199.204.45.44 2026-03-09 15:23:22.281869 | 2026-03-09 15:23:22.282032 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-03-09 15:23:22.727597 | localhost -> localhost | changed 2026-03-09 15:23:22.734043 | 2026-03-09 15:23:22.734141 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-03-09 15:23:23.920213 | localhost -> localhost | changed 2026-03-09 15:23:23.927480 | 2026-03-09 15:23:23.927556 | PLAY [all] 2026-03-09 15:23:23.936834 | 2026-03-09 15:23:23.936921 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-03-09 15:23:24.330691 | controller -> localhost | ok 2026-03-09 15:23:24.348343 | 2026-03-09 15:23:24.348518 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-03-09 15:23:24.383171 | controller | ok 2026-03-09 15:23:24.451249 | controller | included: /var/lib/zuul/builds/790cc2dd262c4da0b619546a5a4dc726/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-03-09 15:23:24.456791 | 2026-03-09 15:23:24.456856 | TASK [add-build-sshkey : Create Temp SSH key] 2026-03-09 15:23:25.094252 | controller -> localhost | Generating public/private rsa key pair. 2026-03-09 15:23:25.094481 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/790cc2dd262c4da0b619546a5a4dc726/work/790cc2dd262c4da0b619546a5a4dc726_id_rsa 2026-03-09 15:23:25.094524 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/790cc2dd262c4da0b619546a5a4dc726/work/790cc2dd262c4da0b619546a5a4dc726_id_rsa.pub 2026-03-09 15:23:25.094557 | controller -> localhost | The key fingerprint is: 2026-03-09 15:23:25.094587 | controller -> localhost | SHA256:212f2bPytr6z0QgTz+UwQUP6NuSBo89WUnx5ZEGNGlA zuul-build-sshkey 2026-03-09 15:23:25.094633 | controller -> localhost | The key's randomart image is: 2026-03-09 15:23:25.094663 | controller -> localhost | +---[RSA 3072]----+ 2026-03-09 15:23:25.094697 | controller -> localhost | | .oEo*+=| 2026-03-09 15:23:25.094727 | controller -> localhost | | .+.=o| 2026-03-09 15:23:25.094755 | controller -> localhost | | =oB.+| 2026-03-09 15:23:25.094783 | controller -> localhost | | ..X B.| 2026-03-09 15:23:25.094811 | controller -> localhost | | S . + X .| 2026-03-09 15:23:25.094837 | controller -> localhost | | o + B +=| 2026-03-09 15:23:25.094865 | controller -> localhost | | . . = .=+| 2026-03-09 15:23:25.094892 | controller -> localhost | | . . o+| 2026-03-09 15:23:25.094923 | controller -> localhost | | =B=| 2026-03-09 15:23:25.094951 | controller -> localhost | +----[SHA256]-----+ 2026-03-09 15:23:25.095012 | controller -> localhost | ok: Runtime: 0:00:00.195339 2026-03-09 15:23:25.102235 | 2026-03-09 15:23:25.102334 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-03-09 15:23:25.133332 | controller | ok 2026-03-09 15:23:25.146142 | controller | included: /var/lib/zuul/builds/790cc2dd262c4da0b619546a5a4dc726/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-03-09 15:23:25.153527 | 2026-03-09 15:23:25.153599 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-03-09 15:23:25.179138 | controller | skipping: Conditional result was False 2026-03-09 15:23:25.189766 | 2026-03-09 15:23:25.189868 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-03-09 15:23:25.725696 | controller | changed 2026-03-09 15:23:25.733987 | 2026-03-09 15:23:25.734082 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-03-09 15:23:26.039001 | controller | ok 2026-03-09 15:23:26.045508 | 2026-03-09 15:23:26.045587 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-03-09 15:23:26.927490 | controller | changed 2026-03-09 15:23:26.934829 | 2026-03-09 15:23:26.934933 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-03-09 15:23:27.841597 | controller | changed 2026-03-09 15:23:27.848799 | 2026-03-09 15:23:27.848942 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-03-09 15:23:27.874710 | controller | skipping: Conditional result was False 2026-03-09 15:23:27.885812 | 2026-03-09 15:23:27.885917 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-03-09 15:23:28.258703 | controller -> localhost | changed 2026-03-09 15:23:28.271861 | 2026-03-09 15:23:28.271955 | TASK [add-build-sshkey : Add back temp key] 2026-03-09 15:23:28.616586 | controller -> localhost | Identity added: /var/lib/zuul/builds/790cc2dd262c4da0b619546a5a4dc726/work/790cc2dd262c4da0b619546a5a4dc726_id_rsa (zuul-build-sshkey) 2026-03-09 15:23:28.616783 | controller -> localhost | ok: Runtime: 0:00:00.015899 2026-03-09 15:23:28.621454 | 2026-03-09 15:23:28.621525 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-03-09 15:23:29.039530 | controller | ok 2026-03-09 15:23:29.163175 | 2026-03-09 15:23:29.163302 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-03-09 15:23:29.190012 | controller | skipping: Conditional result was False 2026-03-09 15:23:29.203019 | 2026-03-09 15:23:29.203154 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-03-09 15:23:29.623751 | controller | ok 2026-03-09 15:23:29.631342 | 2026-03-09 15:23:29.631418 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-03-09 15:23:30.719113 | controller | Output suppressed because no_log was given 2026-03-09 15:23:30.742652 | 2026-03-09 15:23:30.742776 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-03-09 15:23:30.989353 | controller | ok: "logs" 2026-03-09 15:23:30.989635 | controller | ok: All items complete 2026-03-09 15:23:30.989684 | 2026-03-09 15:23:31.206762 | controller | ok: "artifacts" 2026-03-09 15:23:31.436455 | controller | ok: "docs" 2026-03-09 15:23:31.449346 | 2026-03-09 15:23:31.449520 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-03-09 15:23:31.705838 | controller | changed: "logs" 2026-03-09 15:23:31.930504 | controller | changed: "artifacts" 2026-03-09 15:23:32.150355 | controller | changed: "docs" 2026-03-09 15:23:32.163915 | 2026-03-09 15:23:32.164077 | PLAY RECAP 2026-03-09 15:23:32.164153 | controller | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0 2026-03-09 15:23:32.164195 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-03-09 15:23:32.164225 | 2026-03-09 15:23:32.334437 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main] 2026-03-09 15:23:32.356923 | PRE-RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main] 2026-03-09 15:23:32.978766 | 2026-03-09 15:23:32.978925 | PLAY [all] 2026-03-09 15:23:32.990480 | 2026-03-09 15:23:32.990560 | TASK [setup-uv : Extract archive] 2026-03-09 15:23:35.616566 | controller | changed 2026-03-09 15:23:35.622209 | 2026-03-09 15:23:35.622295 | TASK [setup-uv : Print version] 2026-03-09 15:23:35.648460 | [controller] Waiting on logger 2026-03-09 15:23:36.086593 | controller | ok: Runtime: 0:00:00.012838 2026-03-09 15:23:36.092650 | 2026-03-09 15:23:36.092704 | PLAY RECAP 2026-03-09 15:23:36.092780 | controller | ok: 2 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-03-09 15:23:36.092809 | 2026-03-09 15:23:36.216940 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main] 2026-03-09 15:23:36.218478 | RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main] 2026-03-09 15:23:36.794852 | 2026-03-09 15:23:36.794996 | PLAY [all] 2026-03-09 15:23:36.805391 | 2026-03-09 15:23:36.805462 | TASK [Copy inventory file for Zuul] 2026-03-09 15:23:38.110027 | controller | changed 2026-03-09 15:23:38.116685 | 2026-03-09 15:23:38.116787 | TASK [Switch "ansible_host" to private IP] 2026-03-09 15:23:38.487197 | controller | changed: 1 replacements made 2026-03-09 15:23:38.492270 | 2026-03-09 15:23:38.492339 | TASK [Run Molecule scenario] 2026-03-09 15:23:38.514391 | [controller] Waiting on logger 2026-03-09 15:23:46.661970 | [controller] Waiting on logger 2026-03-09 15:23:55.814059 | [controller] Waiting on logger 2026-03-09 15:24:05.993797 | [controller] Waiting on logger 2026-03-09 15:24:16.165871 | [controller] Waiting on logger 2026-03-09 15:24:26.342082 | [controller] Waiting on logger 2026-03-09 15:24:36.518102 | [controller] Waiting on logger 2026-03-09 15:24:45.738853 | [controller] Waiting on logger 2026-03-09 15:24:55.910038 | [controller] Waiting on logger 2026-03-09 15:25:06.090171 | [controller] Waiting on logger 2026-03-09 15:25:16.266082 | [controller] Waiting on logger 2026-03-09 15:25:26.438386 | [controller] Waiting on logger 2026-03-09 15:25:36.614129 | [controller] Waiting on logger 2026-03-09 15:25:45.770012 | [controller] Waiting on logger 2026-03-09 15:25:55.941850 | [controller] Waiting on logger 2026-03-09 15:26:06.122071 | [controller] Waiting on logger 2026-03-09 15:26:16.293834 | [controller] Waiting on logger 2026-03-09 15:26:26.470076 | [controller] Waiting on logger 2026-03-09 15:26:36.646089 | [controller] Waiting on logger 2026-03-09 15:26:45.802021 | [controller] Waiting on logger 2026-03-09 15:26:55.977972 | [controller] Waiting on logger 2026-03-09 15:27:06.149851 | [controller] Waiting on logger 2026-03-09 15:27:16.326410 | [controller] Waiting on logger 2026-03-09 15:27:26.505998 | [controller] Waiting on logger 2026-03-09 15:27:35.659115 | [controller] Waiting on logger 2026-03-09 15:27:45.834012 | [controller] Waiting on logger 2026-03-09 15:27:56.009893 | [controller] Waiting on logger 2026-03-09 15:28:06.181964 | [controller] Waiting on logger 2026-03-09 15:28:16.358275 | [controller] Waiting on logger 2026-03-09 15:28:26.533969 | [controller] Waiting on logger 2026-03-09 15:28:35.691226 | [controller] Waiting on logger 2026-03-09 15:28:43.534038 | controller | ok: Runtime: 0:05:03.480925 2026-03-09 15:28:43.551773 | 2026-03-09 15:28:43.552082 | PLAY RECAP 2026-03-09 15:28:43.552207 | controller | ok: 3 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-03-09 15:28:43.552261 | 2026-03-09 15:28:43.691021 | RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main] 2026-03-09 15:28:43.693280 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main] 2026-03-09 15:28:44.291163 | 2026-03-09 15:28:44.291280 | PLAY [all] 2026-03-09 15:28:44.301661 | 2026-03-09 15:28:44.301732 | TASK [fetch-output : Set log path for multiple nodes] 2026-03-09 15:28:44.346288 | controller | skipping: Conditional result was False 2026-03-09 15:28:44.355286 | 2026-03-09 15:28:44.355394 | TASK [fetch-output : Set log path for single node] 2026-03-09 15:28:44.399108 | controller | ok 2026-03-09 15:28:44.404693 | 2026-03-09 15:28:44.404781 | LOOP [fetch-output : Ensure local output dirs] 2026-03-09 15:28:44.815951 | controller -> localhost | ok: "/var/lib/zuul/builds/790cc2dd262c4da0b619546a5a4dc726/work/logs" 2026-03-09 15:28:45.020227 | controller -> localhost | changed: "/var/lib/zuul/builds/790cc2dd262c4da0b619546a5a4dc726/work/artifacts" 2026-03-09 15:28:45.277140 | controller -> localhost | changed: "/var/lib/zuul/builds/790cc2dd262c4da0b619546a5a4dc726/work/docs" 2026-03-09 15:28:45.289065 | 2026-03-09 15:28:45.289187 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-03-09 15:28:46.039790 | controller | changed: .d..t...... ./ 2026-03-09 15:28:46.040068 | controller | changed: All items complete 2026-03-09 15:28:46.040111 | 2026-03-09 15:28:46.576281 | controller | changed: .d..t...... ./ 2026-03-09 15:28:47.106120 | controller | changed: .d..t...... ./ 2026-03-09 15:28:47.118616 | 2026-03-09 15:28:47.118753 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-03-09 15:28:47.535288 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.005269 2026-03-09 15:28:47.756772 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.023819 2026-03-09 15:28:47.776055 | 2026-03-09 15:28:47.776395 | PLAY [all] 2026-03-09 15:28:47.793099 | 2026-03-09 15:28:47.793204 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2026-03-09 15:28:48.306729 | controller | changed 2026-03-09 15:28:48.314311 | 2026-03-09 15:28:48.314368 | PLAY RECAP 2026-03-09 15:28:48.314417 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2026-03-09 15:28:48.314448 | 2026-03-09 15:28:48.486159 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main] 2026-03-09 15:28:48.488764 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main] 2026-03-09 15:28:49.085346 | 2026-03-09 15:28:49.085486 | PLAY [localhost] 2026-03-09 15:28:49.095866 | 2026-03-09 15:28:49.095955 | TASK [Generate Zuul manifest] 2026-03-09 15:28:49.117300 | localhost | ok 2026-03-09 15:28:49.135757 | 2026-03-09 15:28:49.135853 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-03-09 15:28:49.492482 | localhost | changed 2026-03-09 15:28:49.516949 | 2026-03-09 15:28:49.517296 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-03-09 15:28:49.557284 | localhost | ok 2026-03-09 15:28:49.566684 | 2026-03-09 15:28:49.566773 | TASK [Upload logs] 2026-03-09 15:28:49.586661 | localhost | ok 2026-03-09 15:28:49.671040 | 2026-03-09 15:28:49.671194 | TASK [Set zuul-log-path fact] 2026-03-09 15:28:49.695113 | localhost | ok 2026-03-09 15:28:49.705728 | 2026-03-09 15:28:49.705796 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-03-09 15:28:49.736605 | localhost | ok 2026-03-09 15:28:49.745558 | 2026-03-09 15:28:49.745621 | TASK [upload-logs : Create log directories] 2026-03-09 15:28:50.165382 | localhost | changed 2026-03-09 15:28:50.172624 | 2026-03-09 15:28:50.172743 | TASK [upload-logs : Ensure logs are readable before uploading] 2026-03-09 15:28:50.579817 | localhost -> localhost | ok: Runtime: 0:00:00.005484 2026-03-09 15:28:50.586864 | 2026-03-09 15:28:50.586938 | TASK [upload-logs : Upload logs to log server] 2026-03-09 15:28:51.065099 | localhost | Output suppressed because no_log was given 2026-03-09 15:28:51.068891 | 2026-03-09 15:28:51.069008 | LOOP [upload-logs : Compress console log and json output] 2026-03-09 15:28:51.120842 | localhost | skipping: Conditional result was False 2026-03-09 15:28:51.128655 | localhost | skipping: Conditional result was False 2026-03-09 15:28:51.143449 | 2026-03-09 15:28:51.143610 | LOOP [upload-logs : Upload compressed console log and json output] 2026-03-09 15:28:51.193132 | localhost | skipping: Conditional result was False 2026-03-09 15:28:51.193552 | 2026-03-09 15:28:51.206512 | localhost | skipping: Conditional result was False 2026-03-09 15:28:51.216207 | 2026-03-09 15:28:51.216398 | LOOP [upload-logs : Upload console log and json output]