2026-03-17 19:46:29.995110 | Job console starting 2026-03-17 19:46:30.199000 | Updating git repos 2026-03-17 19:46:30.262278 | Cloning repos into workspace 2026-03-17 19:46:31.312879 | Restoring repo states 2026-03-17 19:46:31.321703 | Merging changes 2026-03-17 19:46:32.390794 | Checking out repos 2026-03-17 19:46:32.805044 | Preparing playbooks 2026-03-17 19:46:39.452334 | Running Ansible setup 2026-03-17 19:46:44.242564 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main] 2026-03-17 19:46:44.951651 | 2026-03-17 19:46:44.951850 | PLAY [localhost] 2026-03-17 19:46:44.960668 | 2026-03-17 19:46:44.960793 | TASK [Gathering Facts] 2026-03-17 19:46:45.967223 | localhost | ok 2026-03-17 19:46:45.974739 | 2026-03-17 19:46:45.974878 | TASK [Setup log path fact] 2026-03-17 19:46:45.991983 | localhost | ok 2026-03-17 19:46:46.016234 | 2026-03-17 19:46:46.016359 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-03-17 19:46:46.049079 | localhost | ok 2026-03-17 19:46:46.060587 | 2026-03-17 19:46:46.060720 | TASK [emit-job-header : Print job information] 2026-03-17 19:46:46.100135 | # Job Information 2026-03-17 19:46:46.100293 | Ansible Version: 2.16.16 2026-03-17 19:46:46.100325 | Job: ansible-collection-kubernetes-molecule-aio-rockylinux-9 2026-03-17 19:46:46.100347 | Pipeline: check 2026-03-17 19:46:46.100368 | Executor: 0a8996d2b663 2026-03-17 19:46:46.100387 | Triggered by: https://github.com/vexxhost/ansible-collection-kubernetes/pull/238 2026-03-17 19:46:46.100410 | Event ID: b11771e0-2239-11f1-9cf9-cf3d0ed948e5 2026-03-17 19:46:46.103230 | 2026-03-17 19:46:46.103302 | LOOP [emit-job-header : Print node information] 2026-03-17 19:46:46.185852 | localhost | ok: 2026-03-17 19:46:46.186048 | localhost | # Node Information 2026-03-17 19:46:46.186086 | localhost | Inventory Hostname: controller 2026-03-17 19:46:46.186115 | localhost | Hostname: np0000159556 2026-03-17 19:46:46.186143 | localhost | Username: zuul 2026-03-17 19:46:46.186176 | localhost | Distro: Rocky 9.7 2026-03-17 19:46:46.186205 | localhost | Provider: yul1 2026-03-17 19:46:46.186232 | localhost | Region: ca-ymq-1 2026-03-17 19:46:46.186258 | localhost | Label: rockylinux-9 2026-03-17 19:46:46.186285 | localhost | Product Name: OpenStack Nova 2026-03-17 19:46:46.186312 | localhost | Interface IP: 199.19.213.136 2026-03-17 19:46:46.204523 | 2026-03-17 19:46:46.204646 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-03-17 19:46:46.859503 | localhost -> localhost | changed 2026-03-17 19:46:46.864233 | 2026-03-17 19:46:46.864307 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-03-17 19:46:48.076577 | localhost -> localhost | changed 2026-03-17 19:46:48.158374 | 2026-03-17 19:46:48.158475 | PLAY [all] 2026-03-17 19:46:48.170383 | 2026-03-17 19:46:48.170486 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-03-17 19:46:48.420508 | controller -> localhost | ok 2026-03-17 19:46:48.453931 | 2026-03-17 19:46:48.454306 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-03-17 19:46:48.494680 | controller | ok 2026-03-17 19:46:48.557029 | controller | included: /var/lib/zuul/builds/51995517306542abbd978f7c60083bed/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-03-17 19:46:48.567783 | 2026-03-17 19:46:48.567875 | TASK [add-build-sshkey : Create Temp SSH key] 2026-03-17 19:46:51.590236 | controller -> localhost | Generating public/private rsa key pair. 2026-03-17 19:46:51.590388 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/51995517306542abbd978f7c60083bed/work/51995517306542abbd978f7c60083bed_id_rsa 2026-03-17 19:46:51.590418 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/51995517306542abbd978f7c60083bed/work/51995517306542abbd978f7c60083bed_id_rsa.pub 2026-03-17 19:46:51.590441 | controller -> localhost | The key fingerprint is: 2026-03-17 19:46:51.590462 | controller -> localhost | SHA256:6Htfw6Y7vBENZlq/UJO+fAbgqpYmBEcZc8WfIkmlLiY zuul-build-sshkey 2026-03-17 19:46:51.590713 | controller -> localhost | The key's randomart image is: 2026-03-17 19:46:51.590743 | controller -> localhost | +---[RSA 3072]----+ 2026-03-17 19:46:51.590771 | controller -> localhost | | oo.+o | 2026-03-17 19:46:51.590795 | controller -> localhost | | oo... . | 2026-03-17 19:46:51.590819 | controller -> localhost | | . ... .*.+ | 2026-03-17 19:46:51.590841 | controller -> localhost | | . ..o..*oB . | 2026-03-17 19:46:51.590863 | controller -> localhost | | Eoo o.S.+ = | 2026-03-17 19:46:51.590885 | controller -> localhost | | o.o . = + | 2026-03-17 19:46:51.590906 | controller -> localhost | | . ..... O o | 2026-03-17 19:46:51.590926 | controller -> localhost | | . +o. o= + | 2026-03-17 19:46:51.590948 | controller -> localhost | | +o. .=+ | 2026-03-17 19:46:51.590968 | controller -> localhost | +----[SHA256]-----+ 2026-03-17 19:46:51.591011 | controller -> localhost | ok: Runtime: 0:00:02.556195 2026-03-17 19:46:51.595625 | 2026-03-17 19:46:51.595688 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-03-17 19:46:51.625110 | controller | ok 2026-03-17 19:46:51.640825 | controller | included: /var/lib/zuul/builds/51995517306542abbd978f7c60083bed/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-03-17 19:46:51.649645 | 2026-03-17 19:46:51.649724 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-03-17 19:46:51.673789 | controller | skipping: Conditional result was False 2026-03-17 19:46:51.683987 | 2026-03-17 19:46:51.684126 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-03-17 19:46:52.160638 | controller | changed 2026-03-17 19:46:52.168613 | 2026-03-17 19:46:52.168786 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-03-17 19:46:52.430951 | controller | ok 2026-03-17 19:46:52.440748 | 2026-03-17 19:46:52.440827 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-03-17 19:46:53.342565 | controller | changed 2026-03-17 19:46:53.347252 | 2026-03-17 19:46:53.347336 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-03-17 19:46:54.272061 | controller | changed 2026-03-17 19:46:54.328439 | 2026-03-17 19:46:54.328531 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-03-17 19:46:54.342126 | controller | skipping: Conditional result was False 2026-03-17 19:46:54.349254 | 2026-03-17 19:46:54.349370 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-03-17 19:46:54.709359 | controller -> localhost | changed 2026-03-17 19:46:54.719854 | 2026-03-17 19:46:54.745932 | TASK [add-build-sshkey : Add back temp key] 2026-03-17 19:46:55.012357 | controller -> localhost | Identity added: /var/lib/zuul/builds/51995517306542abbd978f7c60083bed/work/51995517306542abbd978f7c60083bed_id_rsa (zuul-build-sshkey) 2026-03-17 19:46:55.012575 | controller -> localhost | ok: Runtime: 0:00:00.010995 2026-03-17 19:46:55.019478 | 2026-03-17 19:46:55.019565 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-03-17 19:46:55.379197 | controller | ok 2026-03-17 19:46:55.385275 | 2026-03-17 19:46:55.385344 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-03-17 19:46:55.410228 | controller | skipping: Conditional result was False 2026-03-17 19:46:55.425807 | 2026-03-17 19:46:55.425927 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-03-17 19:46:55.839248 | controller | ok 2026-03-17 19:46:55.848345 | 2026-03-17 19:46:55.848450 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-03-17 19:46:57.011210 | controller | Output suppressed because no_log was given 2026-03-17 19:46:57.022127 | 2026-03-17 19:46:57.022209 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-03-17 19:46:57.270574 | controller | ok: "logs" 2026-03-17 19:46:57.270952 | controller | ok: All items complete 2026-03-17 19:46:57.271002 | 2026-03-17 19:46:57.487868 | controller | ok: "artifacts" 2026-03-17 19:46:57.742761 | controller | ok: "docs" 2026-03-17 19:46:57.757472 | 2026-03-17 19:46:57.757614 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-03-17 19:46:57.996857 | controller | changed: "logs" 2026-03-17 19:46:58.225258 | controller | changed: "artifacts" 2026-03-17 19:46:58.451285 | controller | changed: "docs" 2026-03-17 19:46:58.464075 | 2026-03-17 19:46:58.464213 | PLAY RECAP 2026-03-17 19:46:58.464276 | controller | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0 2026-03-17 19:46:58.464315 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-03-17 19:46:58.464343 | 2026-03-17 19:46:58.592372 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main] 2026-03-17 19:46:58.595031 | PRE-RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main] 2026-03-17 19:46:59.196777 | 2026-03-17 19:46:59.196935 | PLAY [all] 2026-03-17 19:46:59.208727 | 2026-03-17 19:46:59.208805 | TASK [setup-uv : Extract archive] 2026-03-17 19:47:01.850111 | controller | changed 2026-03-17 19:47:01.855368 | 2026-03-17 19:47:01.855446 | TASK [setup-uv : Print version] 2026-03-17 19:47:01.876559 | [controller] Waiting on logger 2026-03-17 19:47:02.388077 | controller | ok: Runtime: 0:00:00.014268 2026-03-17 19:47:02.393830 | 2026-03-17 19:47:02.393878 | PLAY RECAP 2026-03-17 19:47:02.393921 | controller | ok: 2 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-03-17 19:47:02.393945 | 2026-03-17 19:47:02.481688 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main] 2026-03-17 19:47:02.483398 | RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main] 2026-03-17 19:47:03.065210 | 2026-03-17 19:47:03.065326 | PLAY [all] 2026-03-17 19:47:03.075463 | 2026-03-17 19:47:03.075536 | TASK [Copy inventory file for Zuul] 2026-03-17 19:47:04.394639 | controller | changed 2026-03-17 19:47:04.401366 | 2026-03-17 19:47:04.401468 | TASK [Switch "ansible_host" to private IP] 2026-03-17 19:47:04.749804 | controller | changed: 1 replacements made 2026-03-17 19:47:04.757062 | 2026-03-17 19:47:04.757197 | TASK [Run Molecule scenario] 2026-03-17 19:47:04.779042 | [controller] Waiting on logger 2026-03-17 19:47:12.907030 | [controller] Waiting on logger 2026-03-17 19:47:23.077917 | [controller] Waiting on logger 2026-03-17 19:47:33.254178 | [controller] Waiting on logger 2026-03-17 19:47:43.430023 | [controller] Waiting on logger 2026-03-17 19:47:53.605805 | [controller] Waiting on logger 2026-03-17 19:48:03.786818 | [controller] Waiting on logger 2026-03-17 19:48:12.945232 | [controller] Waiting on logger 2026-03-17 19:48:23.109893 | [controller] Waiting on logger 2026-03-17 19:48:33.286098 | [controller] Waiting on logger 2026-03-17 19:48:43.461982 | [controller] Waiting on logger 2026-03-17 19:48:53.638201 | [controller] Waiting on logger 2026-03-17 19:49:03.813758 | [controller] Waiting on logger 2026-03-17 19:49:12.970983 | [controller] Waiting on logger 2026-03-17 19:49:23.141915 | [controller] Waiting on logger 2026-03-17 19:49:33.318100 | [controller] Waiting on logger 2026-03-17 19:49:43.493896 | [controller] Waiting on logger 2026-03-17 19:49:53.669850 | [controller] Waiting on logger 2026-03-17 19:50:03.846996 | [controller] Waiting on logger 2026-03-17 19:50:12.997996 | [controller] Waiting on logger 2026-03-17 19:50:23.173683 | [controller] Waiting on logger 2026-03-17 19:50:33.349752 | [controller] Waiting on logger 2026-03-17 19:50:43.529934 | [controller] Waiting on logger 2026-03-17 19:50:53.701974 | [controller] Waiting on logger 2026-03-17 19:51:03.878093 | [controller] Waiting on logger 2026-03-17 19:51:13.029940 | [controller] Waiting on logger 2026-03-17 19:51:23.209778 | [controller] Waiting on logger 2026-03-17 19:51:33.382003 | [controller] Waiting on logger 2026-03-17 19:51:43.558112 | [controller] Waiting on logger 2026-03-17 19:51:53.733912 | [controller] Waiting on logger 2026-03-17 19:52:02.891759 | [controller] Waiting on logger 2026-03-17 19:52:13.061921 | [controller] Waiting on logger 2026-03-17 19:52:22.125743 | controller | ERROR 2026-03-17 19:52:22.126034 | controller | { 2026-03-17 19:52:22.126100 | controller | "delta": "0:05:16.116639", 2026-03-17 19:52:22.126147 | controller | "end": "2026-03-17 19:52:21.392469", 2026-03-17 19:52:22.126192 | controller | "msg": "non-zero return code", 2026-03-17 19:52:22.126232 | controller | "rc": 2, 2026-03-17 19:52:22.126276 | controller | "start": "2026-03-17 19:47:05.275830" 2026-03-17 19:52:22.126316 | controller | } failure 2026-03-17 19:52:22.136194 | 2026-03-17 19:52:22.136244 | PLAY RECAP 2026-03-17 19:52:22.136288 | controller | ok: 2 changed: 2 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0 2026-03-17 19:52:22.136310 | 2026-03-17 19:52:22.276328 | RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main] 2026-03-17 19:52:22.277732 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main] 2026-03-17 19:52:22.844988 | 2026-03-17 19:52:22.845127 | PLAY [all] 2026-03-17 19:52:22.855647 | 2026-03-17 19:52:22.855727 | TASK [fetch-output : Set log path for multiple nodes] 2026-03-17 19:52:22.900798 | controller | skipping: Conditional result was False 2026-03-17 19:52:22.908759 | 2026-03-17 19:52:22.908877 | TASK [fetch-output : Set log path for single node] 2026-03-17 19:52:22.953529 | controller | ok 2026-03-17 19:52:22.958970 | 2026-03-17 19:52:22.959039 | LOOP [fetch-output : Ensure local output dirs] 2026-03-17 19:52:23.314666 | controller -> localhost | ok: "/var/lib/zuul/builds/51995517306542abbd978f7c60083bed/work/logs" 2026-03-17 19:52:23.523264 | controller -> localhost | changed: "/var/lib/zuul/builds/51995517306542abbd978f7c60083bed/work/artifacts" 2026-03-17 19:52:23.734494 | controller -> localhost | changed: "/var/lib/zuul/builds/51995517306542abbd978f7c60083bed/work/docs" 2026-03-17 19:52:23.750026 | 2026-03-17 19:52:23.750182 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-03-17 19:52:24.449846 | controller | ok 2026-03-17 19:52:24.450051 | controller | changed: All items complete 2026-03-17 19:52:24.450086 | 2026-03-17 19:52:24.975016 | controller | changed: .d..t...... ./ 2026-03-17 19:52:25.521131 | controller | changed: .d..t...... ./ 2026-03-17 19:52:25.536207 | 2026-03-17 19:52:25.536270 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-03-17 19:52:25.932109 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.006093 2026-03-17 19:52:26.139653 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.007987 2026-03-17 19:52:26.151872 | 2026-03-17 19:52:26.151929 | PLAY [all] 2026-03-17 19:52:26.157208 | 2026-03-17 19:52:26.157271 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2026-03-17 19:52:26.641806 | controller | changed 2026-03-17 19:52:26.647593 | 2026-03-17 19:52:26.647642 | PLAY RECAP 2026-03-17 19:52:26.647686 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2026-03-17 19:52:26.647708 | 2026-03-17 19:52:26.739891 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main] 2026-03-17 19:52:26.742472 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main] 2026-03-17 19:52:27.264985 | 2026-03-17 19:52:27.265150 | PLAY [localhost] 2026-03-17 19:52:27.274817 | 2026-03-17 19:52:27.274887 | TASK [Generate Zuul manifest] 2026-03-17 19:52:27.294549 | localhost | ok 2026-03-17 19:52:27.310971 | 2026-03-17 19:52:27.311048 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-03-17 19:52:27.629798 | localhost | changed 2026-03-17 19:52:27.640169 | 2026-03-17 19:52:27.640242 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-03-17 19:52:27.672030 | localhost | ok 2026-03-17 19:52:27.680567 | 2026-03-17 19:52:27.680642 | TASK [Upload logs] 2026-03-17 19:52:27.699057 | localhost | ok 2026-03-17 19:52:27.756221 | 2026-03-17 19:52:27.756316 | TASK [Set zuul-log-path fact] 2026-03-17 19:52:27.776943 | localhost | ok 2026-03-17 19:52:27.789697 | 2026-03-17 19:52:27.789787 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-03-17 19:52:27.821221 | localhost | ok 2026-03-17 19:52:27.829236 | 2026-03-17 19:52:27.829317 | TASK [upload-logs : Create log directories] 2026-03-17 19:52:28.236163 | localhost | changed 2026-03-17 19:52:28.242836 | 2026-03-17 19:52:28.242940 | TASK [upload-logs : Ensure logs are readable before uploading] 2026-03-17 19:52:28.631476 | localhost -> localhost | ok: Runtime: 0:00:00.005429 2026-03-17 19:52:28.638604 | 2026-03-17 19:52:28.638670 | TASK [upload-logs : Upload logs to log server] 2026-03-17 19:52:29.086531 | localhost | Output suppressed because no_log was given 2026-03-17 19:52:29.091378 | 2026-03-17 19:52:29.091464 | LOOP [upload-logs : Compress console log and json output] 2026-03-17 19:52:29.140721 | localhost | skipping: Conditional result was False 2026-03-17 19:52:29.147449 | localhost | skipping: Conditional result was False 2026-03-17 19:52:29.156371 | 2026-03-17 19:52:29.156512 | LOOP [upload-logs : Upload compressed console log and json output] 2026-03-17 19:52:29.201849 | localhost | skipping: Conditional result was False 2026-03-17 19:52:29.202272 | 2026-03-17 19:52:29.206011 | localhost | skipping: Conditional result was False 2026-03-17 19:52:29.219226 | 2026-03-17 19:52:29.219383 | LOOP [upload-logs : Upload console log and json output]