2026-03-11 20:48:06.096648 | Job console starting 2026-03-11 20:48:06.109439 | Updating git repos 2026-03-11 20:48:06.156339 | Cloning repos into workspace 2026-03-11 20:48:06.240235 | Restoring repo states 2026-03-11 20:48:06.261275 | Merging changes 2026-03-11 20:48:07.042945 | Checking out repos 2026-03-11 20:48:07.242308 | Preparing playbooks 2026-03-11 20:48:08.638596 | Running Ansible setup 2026-03-11 20:48:12.267025 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main] 2026-03-11 20:48:12.815569 | 2026-03-11 20:48:12.815699 | PLAY [localhost] 2026-03-11 20:48:12.822778 | 2026-03-11 20:48:12.822848 | TASK [Gathering Facts] 2026-03-11 20:48:13.751535 | localhost | ok 2026-03-11 20:48:13.762996 | 2026-03-11 20:48:13.763077 | TASK [Setup log path fact] 2026-03-11 20:48:13.784763 | localhost | ok 2026-03-11 20:48:13.798783 | 2026-03-11 20:48:13.798881 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-03-11 20:48:13.839226 | localhost | ok 2026-03-11 20:48:13.846848 | 2026-03-11 20:48:13.846929 | TASK [emit-job-header : Print job information] 2026-03-11 20:48:13.887011 | # Job Information 2026-03-11 20:48:13.887262 | Ansible Version: 2.16.16 2026-03-11 20:48:13.887330 | Job: ansible-collection-kubernetes-molecule-aio-rockylinux-9 2026-03-11 20:48:13.887378 | Pipeline: check 2026-03-11 20:48:13.887423 | Executor: 0a8996d2b663 2026-03-11 20:48:13.887465 | Triggered by: https://github.com/vexxhost/ansible-collection-kubernetes/pull/238 2026-03-11 20:48:13.887513 | Event ID: 70d60590-1d8b-11f1-9fc9-983abfa91ba5 2026-03-11 20:48:13.891824 | 2026-03-11 20:48:13.891921 | LOOP [emit-job-header : Print node information] 2026-03-11 20:48:13.992370 | localhost | ok: 2026-03-11 20:48:13.992603 | localhost | # Node Information 2026-03-11 20:48:13.992642 | localhost | Inventory Hostname: controller 2026-03-11 20:48:13.992670 | localhost | Hostname: np0000158492 2026-03-11 20:48:13.992697 | localhost | Username: zuul 2026-03-11 20:48:13.992729 | localhost | Distro: Rocky 9.7 2026-03-11 20:48:13.992756 | localhost | Provider: yul1 2026-03-11 20:48:13.992782 | localhost | Region: ca-ymq-1 2026-03-11 20:48:13.992808 | localhost | Label: rockylinux-9 2026-03-11 20:48:13.992833 | localhost | Product Name: OpenStack Nova 2026-03-11 20:48:13.992857 | localhost | Interface IP: 199.204.45.169 2026-03-11 20:48:14.011460 | 2026-03-11 20:48:14.011561 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-03-11 20:48:14.552530 | localhost -> localhost | changed 2026-03-11 20:48:14.563168 | 2026-03-11 20:48:14.563325 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-03-11 20:48:15.494396 | localhost -> localhost | changed 2026-03-11 20:48:15.505620 | 2026-03-11 20:48:15.505677 | PLAY [all] 2026-03-11 20:48:15.513502 | 2026-03-11 20:48:15.513571 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-03-11 20:48:15.751809 | controller -> localhost | ok 2026-03-11 20:48:15.761686 | 2026-03-11 20:48:15.761756 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-03-11 20:48:15.797474 | controller | ok 2026-03-11 20:48:15.813208 | controller | included: /var/lib/zuul/builds/fb51c80948df4ea6914852ed05ac530e/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-03-11 20:48:15.818361 | 2026-03-11 20:48:15.818421 | TASK [add-build-sshkey : Create Temp SSH key] 2026-03-11 20:48:16.888610 | controller -> localhost | Generating public/private rsa key pair. 2026-03-11 20:48:16.888833 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/fb51c80948df4ea6914852ed05ac530e/work/fb51c80948df4ea6914852ed05ac530e_id_rsa 2026-03-11 20:48:16.888865 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/fb51c80948df4ea6914852ed05ac530e/work/fb51c80948df4ea6914852ed05ac530e_id_rsa.pub 2026-03-11 20:48:16.888888 | controller -> localhost | The key fingerprint is: 2026-03-11 20:48:16.888911 | controller -> localhost | SHA256:df4QiGdUmkOUAOGOePMJ1A4BKrYuFkwgOKhjWvr1SRc zuul-build-sshkey 2026-03-11 20:48:16.888968 | controller -> localhost | The key's randomart image is: 2026-03-11 20:48:16.888995 | controller -> localhost | +---[RSA 3072]----+ 2026-03-11 20:48:16.889023 | controller -> localhost | |= ... oo.o+o. | 2026-03-11 20:48:16.889046 | controller -> localhost | |*. + +.+ | 2026-03-11 20:48:16.889066 | controller -> localhost | |++ o o . O o | 2026-03-11 20:48:16.889087 | controller -> localhost | |B.oo = E+ + . | 2026-03-11 20:48:16.889107 | controller -> localhost | |oB. = o S. o | 2026-03-11 20:48:16.889128 | controller -> localhost | |+ ...+... o | 2026-03-11 20:48:16.889148 | controller -> localhost | |.+ . ooo . | 2026-03-11 20:48:16.889168 | controller -> localhost | |o . o | 2026-03-11 20:48:16.889192 | controller -> localhost | | | 2026-03-11 20:48:16.889213 | controller -> localhost | +----[SHA256]-----+ 2026-03-11 20:48:16.889271 | controller -> localhost | ok: Runtime: 0:00:00.640471 2026-03-11 20:48:16.894084 | 2026-03-11 20:48:16.894150 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-03-11 20:48:16.929250 | controller | ok 2026-03-11 20:48:16.939840 | controller | included: /var/lib/zuul/builds/fb51c80948df4ea6914852ed05ac530e/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-03-11 20:48:16.947900 | 2026-03-11 20:48:16.947966 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-03-11 20:48:16.973761 | controller | skipping: Conditional result was False 2026-03-11 20:48:16.982837 | 2026-03-11 20:48:16.982942 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-03-11 20:48:17.477702 | controller | changed 2026-03-11 20:48:17.494036 | 2026-03-11 20:48:17.494133 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-03-11 20:48:17.748983 | controller | ok 2026-03-11 20:48:17.787861 | 2026-03-11 20:48:17.788032 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-03-11 20:48:18.712584 | controller | changed 2026-03-11 20:48:18.717269 | 2026-03-11 20:48:18.717332 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-03-11 20:48:19.630115 | controller | changed 2026-03-11 20:48:19.642357 | 2026-03-11 20:48:19.642528 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-03-11 20:48:19.658101 | controller | skipping: Conditional result was False 2026-03-11 20:48:19.666634 | 2026-03-11 20:48:19.666733 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-03-11 20:48:20.036298 | controller -> localhost | changed 2026-03-11 20:48:20.047853 | 2026-03-11 20:48:20.047961 | TASK [add-build-sshkey : Add back temp key] 2026-03-11 20:48:20.350625 | controller -> localhost | Identity added: /var/lib/zuul/builds/fb51c80948df4ea6914852ed05ac530e/work/fb51c80948df4ea6914852ed05ac530e_id_rsa (zuul-build-sshkey) 2026-03-11 20:48:20.350818 | controller -> localhost | ok: Runtime: 0:00:00.014215 2026-03-11 20:48:20.355444 | 2026-03-11 20:48:20.355505 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-03-11 20:48:20.717951 | controller | ok 2026-03-11 20:48:20.724029 | 2026-03-11 20:48:20.724161 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-03-11 20:48:20.749117 | controller | skipping: Conditional result was False 2026-03-11 20:48:20.777808 | 2026-03-11 20:48:20.778006 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-03-11 20:48:21.185531 | controller | ok 2026-03-11 20:48:21.222107 | 2026-03-11 20:48:21.222225 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-03-11 20:48:22.297841 | controller | Output suppressed because no_log was given 2026-03-11 20:48:22.325490 | 2026-03-11 20:48:22.325593 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-03-11 20:48:22.559479 | controller | ok: "logs" 2026-03-11 20:48:22.611187 | controller | ok: All items complete 2026-03-11 20:48:22.611312 | 2026-03-11 20:48:22.772169 | controller | ok: "artifacts" 2026-03-11 20:48:23.000578 | controller | ok: "docs" 2026-03-11 20:48:23.018807 | 2026-03-11 20:48:23.018991 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-03-11 20:48:23.301282 | controller | changed: "logs" 2026-03-11 20:48:23.552207 | controller | changed: "artifacts" 2026-03-11 20:48:23.784462 | controller | changed: "docs" 2026-03-11 20:48:23.809801 | 2026-03-11 20:48:23.809889 | PLAY RECAP 2026-03-11 20:48:23.809936 | controller | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0 2026-03-11 20:48:23.809963 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-03-11 20:48:23.809983 | 2026-03-11 20:48:23.955022 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main] 2026-03-11 20:48:23.956884 | PRE-RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main] 2026-03-11 20:48:24.589037 | 2026-03-11 20:48:24.589202 | PLAY [all] 2026-03-11 20:48:24.600575 | 2026-03-11 20:48:24.600665 | TASK [setup-uv : Extract archive] 2026-03-11 20:48:27.363679 | controller | changed 2026-03-11 20:48:27.370645 | 2026-03-11 20:48:27.370755 | TASK [setup-uv : Print version] 2026-03-11 20:48:27.395274 | [controller] Waiting on logger 2026-03-11 20:48:27.908574 | controller | ok: Runtime: 0:00:00.013572 2026-03-11 20:48:27.925843 | 2026-03-11 20:48:27.925959 | PLAY RECAP 2026-03-11 20:48:27.926021 | controller | ok: 2 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-03-11 20:48:27.926056 | 2026-03-11 20:48:28.020327 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main] 2026-03-11 20:48:28.022021 | RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main] 2026-03-11 20:48:28.641454 | 2026-03-11 20:48:28.641583 | PLAY [all] 2026-03-11 20:48:28.651463 | 2026-03-11 20:48:28.651535 | TASK [Copy inventory file for Zuul] 2026-03-11 20:48:29.932005 | controller | changed 2026-03-11 20:48:30.095751 | 2026-03-11 20:48:30.095943 | TASK [Switch "ansible_host" to private IP] 2026-03-11 20:48:30.465245 | controller | changed: 1 replacements made 2026-03-11 20:48:30.470110 | 2026-03-11 20:48:30.470179 | TASK [Run Molecule scenario] 2026-03-11 20:48:30.503548 | [controller] Waiting on logger 2026-03-11 20:48:38.629972 | [controller] Waiting on logger 2026-03-11 20:48:48.809983 | [controller] Waiting on logger 2026-03-11 20:48:58.982103 | [controller] Waiting on logger 2026-03-11 20:49:09.158056 | [controller] Waiting on logger 2026-03-11 20:49:19.333959 | [controller] Waiting on logger 2026-03-11 20:49:28.491058 | [controller] Waiting on logger 2026-03-11 20:49:38.661904 | [controller] Waiting on logger 2026-03-11 20:49:48.841768 | [controller] Waiting on logger 2026-03-11 20:49:59.014013 | [controller] Waiting on logger 2026-03-11 20:50:09.189840 | [controller] Waiting on logger 2026-03-11 20:50:19.369836 | [controller] Waiting on logger 2026-03-11 20:50:28.518112 | [controller] Waiting on logger 2026-03-11 20:50:38.694119 | [controller] Waiting on logger 2026-03-11 20:50:48.869792 | [controller] Waiting on logger 2026-03-11 20:50:59.045896 | [controller] Waiting on logger 2026-03-11 20:51:09.225839 | [controller] Waiting on logger 2026-03-11 20:51:19.398047 | [controller] Waiting on logger 2026-03-11 20:51:28.549949 | [controller] Waiting on logger 2026-03-11 20:51:38.726003 | [controller] Waiting on logger 2026-03-11 20:51:48.902494 | [controller] Waiting on logger 2026-03-11 20:51:59.078035 | [controller] Waiting on logger 2026-03-11 20:52:09.257808 | [controller] Waiting on logger 2026-03-11 20:52:18.411270 | [controller] Waiting on logger 2026-03-11 20:52:28.582105 | [controller] Waiting on logger 2026-03-11 20:52:38.762136 | [controller] Waiting on logger 2026-03-11 20:52:48.934306 | [controller] Waiting on logger 2026-03-11 20:52:59.110148 | [controller] Waiting on logger 2026-03-11 20:53:09.286431 | [controller] Waiting on logger 2026-03-11 20:53:18.443323 | [controller] Waiting on logger 2026-03-11 20:53:27.403315 | controller | ERROR 2026-03-11 20:53:27.403568 | controller | { 2026-03-11 20:53:27.403598 | controller | "delta": "0:04:56.029482", 2026-03-11 20:53:27.403620 | controller | "end": "2026-03-11 20:53:26.356239", 2026-03-11 20:53:27.403639 | controller | "msg": "non-zero return code", 2026-03-11 20:53:27.403657 | controller | "rc": 2, 2026-03-11 20:53:27.403677 | controller | "start": "2026-03-11 20:48:30.326757" 2026-03-11 20:53:27.403695 | controller | } failure 2026-03-11 20:53:27.431462 | 2026-03-11 20:53:27.431567 | PLAY RECAP 2026-03-11 20:53:27.431634 | controller | ok: 2 changed: 2 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0 2026-03-11 20:53:27.431665 | 2026-03-11 20:53:27.576650 | RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main] 2026-03-11 20:53:27.579566 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main] 2026-03-11 20:53:28.143545 | 2026-03-11 20:53:28.144464 | PLAY [all] 2026-03-11 20:53:28.155004 | 2026-03-11 20:53:28.155075 | TASK [fetch-output : Set log path for multiple nodes] 2026-03-11 20:53:28.199690 | controller | skipping: Conditional result was False 2026-03-11 20:53:28.207341 | 2026-03-11 20:53:28.207449 | TASK [fetch-output : Set log path for single node] 2026-03-11 20:53:28.260906 | controller | ok 2026-03-11 20:53:28.268179 | 2026-03-11 20:53:28.268278 | LOOP [fetch-output : Ensure local output dirs] 2026-03-11 20:53:28.652488 | controller -> localhost | ok: "/var/lib/zuul/builds/fb51c80948df4ea6914852ed05ac530e/work/logs" 2026-03-11 20:53:28.851392 | controller -> localhost | changed: "/var/lib/zuul/builds/fb51c80948df4ea6914852ed05ac530e/work/artifacts" 2026-03-11 20:53:29.062298 | controller -> localhost | changed: "/var/lib/zuul/builds/fb51c80948df4ea6914852ed05ac530e/work/docs" 2026-03-11 20:53:29.084391 | 2026-03-11 20:53:29.084541 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-03-11 20:53:29.761754 | controller | changed: .d..t...... ./ 2026-03-11 20:53:29.761967 | controller | changed: All items complete 2026-03-11 20:53:29.761994 | 2026-03-11 20:53:30.270722 | controller | changed: .d..t...... ./ 2026-03-11 20:53:30.824545 | controller | changed: .d..t...... ./ 2026-03-11 20:53:30.849371 | 2026-03-11 20:53:30.849519 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-03-11 20:53:31.295843 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007503 2026-03-11 20:53:31.511320 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.007921 2026-03-11 20:53:31.531542 | 2026-03-11 20:53:31.531700 | PLAY [all] 2026-03-11 20:53:31.537634 | 2026-03-11 20:53:31.537699 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2026-03-11 20:53:32.037153 | controller | changed 2026-03-11 20:53:32.045065 | 2026-03-11 20:53:32.045113 | PLAY RECAP 2026-03-11 20:53:32.045160 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2026-03-11 20:53:32.045181 | 2026-03-11 20:53:32.142509 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main] 2026-03-11 20:53:32.145152 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main] 2026-03-11 20:53:32.719728 | 2026-03-11 20:53:32.720300 | PLAY [localhost] 2026-03-11 20:53:32.730426 | 2026-03-11 20:53:32.730497 | TASK [Generate Zuul manifest] 2026-03-11 20:53:32.754345 | localhost | ok 2026-03-11 20:53:32.770073 | 2026-03-11 20:53:32.770151 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-03-11 20:53:33.118475 | localhost | changed 2026-03-11 20:53:33.131256 | 2026-03-11 20:53:33.131334 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-03-11 20:53:33.163038 | localhost | ok 2026-03-11 20:53:33.171756 | 2026-03-11 20:53:33.171842 | TASK [Upload logs] 2026-03-11 20:53:33.194201 | localhost | ok 2026-03-11 20:53:33.262306 | 2026-03-11 20:53:33.262476 | TASK [Set zuul-log-path fact] 2026-03-11 20:53:33.280337 | localhost | ok 2026-03-11 20:53:33.291201 | 2026-03-11 20:53:33.291272 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-03-11 20:53:33.319547 | localhost | ok 2026-03-11 20:53:33.327041 | 2026-03-11 20:53:33.327107 | TASK [upload-logs : Create log directories] 2026-03-11 20:53:33.753544 | localhost | changed 2026-03-11 20:53:33.759500 | 2026-03-11 20:53:33.759571 | TASK [upload-logs : Ensure logs are readable before uploading] 2026-03-11 20:53:34.167427 | localhost -> localhost | ok: Runtime: 0:00:00.005557 2026-03-11 20:53:34.174593 | 2026-03-11 20:53:34.174663 | TASK [upload-logs : Upload logs to log server] 2026-03-11 20:53:34.660627 | localhost | Output suppressed because no_log was given 2026-03-11 20:53:34.665788 | 2026-03-11 20:53:34.665892 | LOOP [upload-logs : Compress console log and json output] 2026-03-11 20:53:34.712894 | localhost | skipping: Conditional result was False 2026-03-11 20:53:34.720213 | localhost | skipping: Conditional result was False 2026-03-11 20:53:34.730460 | 2026-03-11 20:53:34.730601 | LOOP [upload-logs : Upload compressed console log and json output] 2026-03-11 20:53:34.775110 | localhost | skipping: Conditional result was False 2026-03-11 20:53:34.775584 | 2026-03-11 20:53:34.779527 | localhost | skipping: Conditional result was False 2026-03-11 20:53:34.793974 | 2026-03-11 20:53:34.794069 | LOOP [upload-logs : Upload console log and json output]