2026-03-11 23:17:18.298374 | Job console starting 2026-03-11 23:17:18.305478 | Updating git repos 2026-03-11 23:17:18.342518 | Cloning repos into workspace 2026-03-11 23:17:18.392838 | Restoring repo states 2026-03-11 23:17:18.405851 | Merging changes 2026-03-11 23:17:19.096599 | Checking out repos 2026-03-11 23:17:19.302029 | Preparing playbooks 2026-03-11 23:17:20.620422 | Running Ansible setup 2026-03-11 23:17:24.259093 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main] 2026-03-11 23:17:24.825387 | 2026-03-11 23:17:24.825512 | PLAY [localhost] 2026-03-11 23:17:24.832738 | 2026-03-11 23:17:24.832805 | TASK [Gathering Facts] 2026-03-11 23:17:25.677265 | localhost | ok 2026-03-11 23:17:25.687826 | 2026-03-11 23:17:25.687916 | TASK [Setup log path fact] 2026-03-11 23:17:25.706711 | localhost | ok 2026-03-11 23:17:25.720156 | 2026-03-11 23:17:25.720245 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-03-11 23:17:25.749897 | localhost | ok 2026-03-11 23:17:25.758687 | 2026-03-11 23:17:25.758758 | TASK [emit-job-header : Print job information] 2026-03-11 23:17:25.799730 | # Job Information 2026-03-11 23:17:25.799918 | Ansible Version: 2.16.16 2026-03-11 23:17:25.799964 | Job: ansible-collection-kubernetes-molecule-aio-rockylinux-9 2026-03-11 23:17:25.799996 | Pipeline: check 2026-03-11 23:17:25.800027 | Executor: 0a8996d2b663 2026-03-11 23:17:25.800056 | Triggered by: https://github.com/vexxhost/ansible-collection-kubernetes/pull/238 2026-03-11 23:17:25.800089 | Event ID: 2a19e8f0-1da0-11f1-90c2-31080bc8066f 2026-03-11 23:17:25.804127 | 2026-03-11 23:17:25.804215 | LOOP [emit-job-header : Print node information] 2026-03-11 23:17:25.892460 | localhost | ok: 2026-03-11 23:17:25.892854 | localhost | # Node Information 2026-03-11 23:17:25.892928 | localhost | Inventory Hostname: controller 2026-03-11 23:17:25.892978 | localhost | Hostname: np0000158531 2026-03-11 23:17:25.893069 | localhost | Username: zuul 2026-03-11 23:17:25.893132 | localhost | Distro: Rocky 9.7 2026-03-11 23:17:25.893176 | localhost | Provider: yul1 2026-03-11 23:17:25.893219 | localhost | Region: ca-ymq-1 2026-03-11 23:17:25.893260 | localhost | Label: rockylinux-9 2026-03-11 23:17:25.893300 | localhost | Product Name: OpenStack Nova 2026-03-11 23:17:25.893341 | localhost | Interface IP: 199.204.45.244 2026-03-11 23:17:25.914338 | 2026-03-11 23:17:25.914475 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-03-11 23:17:26.277374 | localhost -> localhost | changed 2026-03-11 23:17:26.282565 | 2026-03-11 23:17:26.282634 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-03-11 23:17:27.087623 | localhost -> localhost | changed 2026-03-11 23:17:27.098552 | 2026-03-11 23:17:27.098609 | PLAY [all] 2026-03-11 23:17:27.106307 | 2026-03-11 23:17:27.106392 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-03-11 23:17:27.343727 | controller -> localhost | ok 2026-03-11 23:17:27.352427 | 2026-03-11 23:17:27.352514 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-03-11 23:17:27.386497 | controller | ok 2026-03-11 23:17:27.399998 | controller | included: /var/lib/zuul/builds/2c7a2affafd5429bad5ad1239db0ace8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-03-11 23:17:27.405309 | 2026-03-11 23:17:27.405367 | TASK [add-build-sshkey : Create Temp SSH key] 2026-03-11 23:17:28.225252 | controller -> localhost | Generating public/private rsa key pair. 2026-03-11 23:17:28.225498 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/2c7a2affafd5429bad5ad1239db0ace8/work/2c7a2affafd5429bad5ad1239db0ace8_id_rsa 2026-03-11 23:17:28.225540 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/2c7a2affafd5429bad5ad1239db0ace8/work/2c7a2affafd5429bad5ad1239db0ace8_id_rsa.pub 2026-03-11 23:17:28.225573 | controller -> localhost | The key fingerprint is: 2026-03-11 23:17:28.225603 | controller -> localhost | SHA256:aJN1VW6Uls3OZ35adFfBZ/XVCF9RzsoIFG0NTcIFxWk zuul-build-sshkey 2026-03-11 23:17:28.225647 | controller -> localhost | The key's randomart image is: 2026-03-11 23:17:28.225677 | controller -> localhost | +---[RSA 3072]----+ 2026-03-11 23:17:28.225713 | controller -> localhost | | o+*%BX@| 2026-03-11 23:17:28.225743 | controller -> localhost | | . .+=E=X| 2026-03-11 23:17:28.225773 | controller -> localhost | | . o. o++*| 2026-03-11 23:17:28.225802 | controller -> localhost | | + . . + .O| 2026-03-11 23:17:28.225830 | controller -> localhost | | = S . o++| 2026-03-11 23:17:28.225859 | controller -> localhost | | . . +| 2026-03-11 23:17:28.225886 | controller -> localhost | | o.| 2026-03-11 23:17:28.225914 | controller -> localhost | | . | 2026-03-11 23:17:28.225946 | controller -> localhost | | | 2026-03-11 23:17:28.225975 | controller -> localhost | +----[SHA256]-----+ 2026-03-11 23:17:28.226047 | controller -> localhost | ok: Runtime: 0:00:00.428353 2026-03-11 23:17:28.231697 | 2026-03-11 23:17:28.231768 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-03-11 23:17:28.264235 | controller | ok 2026-03-11 23:17:28.275156 | controller | included: /var/lib/zuul/builds/2c7a2affafd5429bad5ad1239db0ace8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-03-11 23:17:28.282495 | 2026-03-11 23:17:28.282557 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-03-11 23:17:28.307581 | controller | skipping: Conditional result was False 2026-03-11 23:17:28.314401 | 2026-03-11 23:17:28.314487 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-03-11 23:17:28.794706 | controller | changed 2026-03-11 23:17:28.800885 | 2026-03-11 23:17:28.801008 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-03-11 23:17:29.059148 | controller | ok 2026-03-11 23:17:29.065492 | 2026-03-11 23:17:29.065559 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-03-11 23:17:30.005321 | controller | changed 2026-03-11 23:17:30.010250 | 2026-03-11 23:17:30.010318 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-03-11 23:17:30.924204 | controller | changed 2026-03-11 23:17:30.929098 | 2026-03-11 23:17:30.929162 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-03-11 23:17:30.954384 | controller | skipping: Conditional result was False 2026-03-11 23:17:30.962806 | 2026-03-11 23:17:30.962902 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-03-11 23:17:31.372096 | controller -> localhost | changed 2026-03-11 23:17:31.386271 | 2026-03-11 23:17:31.386362 | TASK [add-build-sshkey : Add back temp key] 2026-03-11 23:17:31.655987 | controller -> localhost | Identity added: /var/lib/zuul/builds/2c7a2affafd5429bad5ad1239db0ace8/work/2c7a2affafd5429bad5ad1239db0ace8_id_rsa (zuul-build-sshkey) 2026-03-11 23:17:31.656172 | controller -> localhost | ok: Runtime: 0:00:00.014797 2026-03-11 23:17:31.660669 | 2026-03-11 23:17:31.660736 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-03-11 23:17:32.046124 | controller | ok 2026-03-11 23:17:32.051800 | 2026-03-11 23:17:32.051883 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-03-11 23:17:32.076201 | controller | skipping: Conditional result was False 2026-03-11 23:17:32.089563 | 2026-03-11 23:17:32.089624 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-03-11 23:17:32.465459 | controller | ok 2026-03-11 23:17:32.473306 | 2026-03-11 23:17:32.473367 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-03-11 23:17:33.709655 | controller | Output suppressed because no_log was given 2026-03-11 23:17:34.090480 | 2026-03-11 23:17:34.090636 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-03-11 23:17:34.344911 | controller | ok: "logs" 2026-03-11 23:17:34.345181 | controller | ok: All items complete 2026-03-11 23:17:34.345220 | 2026-03-11 23:17:34.573556 | controller | ok: "artifacts" 2026-03-11 23:17:34.806339 | controller | ok: "docs" 2026-03-11 23:17:34.826754 | 2026-03-11 23:17:34.826918 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-03-11 23:17:35.084090 | controller | changed: "logs" 2026-03-11 23:17:35.305337 | controller | changed: "artifacts" 2026-03-11 23:17:35.538925 | controller | changed: "docs" 2026-03-11 23:17:35.551920 | 2026-03-11 23:17:35.552034 | PLAY RECAP 2026-03-11 23:17:35.552083 | controller | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0 2026-03-11 23:17:35.552111 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-03-11 23:17:35.552133 | 2026-03-11 23:17:35.665101 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main] 2026-03-11 23:17:35.666876 | PRE-RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main] 2026-03-11 23:17:36.242656 | 2026-03-11 23:17:36.242802 | PLAY [all] 2026-03-11 23:17:36.254572 | 2026-03-11 23:17:36.254650 | TASK [setup-uv : Extract archive] 2026-03-11 23:17:39.111068 | controller | changed 2026-03-11 23:17:39.118485 | 2026-03-11 23:17:39.118591 | TASK [setup-uv : Print version] 2026-03-11 23:17:39.142771 | [controller] Waiting on logger 2026-03-11 23:17:39.658592 | controller | ok: Runtime: 0:00:00.014399 2026-03-11 23:17:39.666294 | 2026-03-11 23:17:39.666343 | PLAY RECAP 2026-03-11 23:17:39.666389 | controller | ok: 2 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-03-11 23:17:39.666413 | 2026-03-11 23:17:39.793671 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main] 2026-03-11 23:17:39.795488 | RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main] 2026-03-11 23:17:40.386082 | 2026-03-11 23:17:40.386246 | PLAY [all] 2026-03-11 23:17:40.397942 | 2026-03-11 23:17:40.398028 | TASK [Copy inventory file for Zuul] 2026-03-11 23:17:41.727115 | controller | changed 2026-03-11 23:17:41.733366 | 2026-03-11 23:17:41.733496 | TASK [Switch "ansible_host" to private IP] 2026-03-11 23:17:42.080114 | controller | changed: 1 replacements made 2026-03-11 23:17:42.084940 | 2026-03-11 23:17:42.085043 | TASK [Run Molecule scenario] 2026-03-11 23:17:42.106542 | [controller] Waiting on logger 2026-03-11 23:17:50.251611 | [controller] Waiting on logger 2026-03-11 23:18:00.422539 | [controller] Waiting on logger 2026-03-11 23:18:10.598110 | [controller] Waiting on logger 2026-03-11 23:18:20.773930 | [controller] Waiting on logger 2026-03-11 23:18:30.950028 | [controller] Waiting on logger 2026-03-11 23:18:41.126142 | [controller] Waiting on logger 2026-03-11 23:18:50.278089 | [controller] Waiting on logger 2026-03-11 23:19:00.454229 | [controller] Waiting on logger 2026-03-11 23:19:10.630171 | [controller] Waiting on logger 2026-03-11 23:19:20.422185 | [controller] Waiting on logger 2026-03-11 23:19:30.598664 | [controller] Waiting on logger 2026-03-11 23:19:40.774179 | [controller] Waiting on logger 2026-03-11 23:19:50.950044 | [controller] Waiting on logger 2026-03-11 23:20:01.126168 | [controller] Waiting on logger 2026-03-11 23:20:10.278005 | [controller] Waiting on logger 2026-03-11 23:20:20.458055 | [controller] Waiting on logger 2026-03-11 23:20:30.630048 | [controller] Waiting on logger 2026-03-11 23:20:40.806303 | [controller] Waiting on logger 2026-03-11 23:20:50.982012 | [controller] Waiting on logger 2026-03-11 23:21:01.158013 | [controller] Waiting on logger 2026-03-11 23:21:10.310045 | [controller] Waiting on logger 2026-03-11 23:21:20.486112 | [controller] Waiting on logger 2026-03-11 23:21:30.661919 | [controller] Waiting on logger 2026-03-11 23:21:40.838130 | [controller] Waiting on logger 2026-03-11 23:21:51.014236 | [controller] Waiting on logger 2026-03-11 23:22:00.171285 | [controller] Waiting on logger 2026-03-11 23:22:10.342328 | [controller] Waiting on logger 2026-03-11 23:22:20.522234 | [controller] Waiting on logger 2026-03-11 23:22:30.694006 | [controller] Waiting on logger 2026-03-11 23:22:40.870554 | [controller] Waiting on logger 2026-03-11 23:22:51.046078 | [controller] Waiting on logger 2026-03-11 23:23:00.204047 | [controller] Waiting on logger 2026-03-11 23:23:04.686454 | controller | ERROR 2026-03-11 23:23:04.686749 | controller | { 2026-03-11 23:23:04.686790 | controller | "delta": "0:05:21.024227", 2026-03-11 23:23:04.686819 | controller | "end": "2026-03-11 23:23:03.546547", 2026-03-11 23:23:04.686846 | controller | "msg": "non-zero return code", 2026-03-11 23:23:04.686872 | controller | "rc": 2, 2026-03-11 23:23:04.686900 | controller | "start": "2026-03-11 23:17:42.522320" 2026-03-11 23:23:04.686926 | controller | } failure 2026-03-11 23:23:04.697154 | 2026-03-11 23:23:04.697203 | PLAY RECAP 2026-03-11 23:23:04.697248 | controller | ok: 2 changed: 2 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0 2026-03-11 23:23:04.697268 | 2026-03-11 23:23:04.827587 | RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main] 2026-03-11 23:23:04.828928 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main] 2026-03-11 23:23:05.409723 | 2026-03-11 23:23:05.409869 | PLAY [all] 2026-03-11 23:23:05.420751 | 2026-03-11 23:23:05.420827 | TASK [fetch-output : Set log path for multiple nodes] 2026-03-11 23:23:05.466843 | controller | skipping: Conditional result was False 2026-03-11 23:23:05.475503 | 2026-03-11 23:23:05.475586 | TASK [fetch-output : Set log path for single node] 2026-03-11 23:23:05.519979 | controller | ok 2026-03-11 23:23:05.524191 | 2026-03-11 23:23:05.524258 | LOOP [fetch-output : Ensure local output dirs] 2026-03-11 23:23:05.930647 | controller -> localhost | ok: "/var/lib/zuul/builds/2c7a2affafd5429bad5ad1239db0ace8/work/logs" 2026-03-11 23:23:06.142989 | controller -> localhost | changed: "/var/lib/zuul/builds/2c7a2affafd5429bad5ad1239db0ace8/work/artifacts" 2026-03-11 23:23:06.355100 | controller -> localhost | changed: "/var/lib/zuul/builds/2c7a2affafd5429bad5ad1239db0ace8/work/docs" 2026-03-11 23:23:06.369418 | 2026-03-11 23:23:06.369589 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-03-11 23:23:07.039020 | controller | ok 2026-03-11 23:23:07.039309 | controller | changed: All items complete 2026-03-11 23:23:07.039348 | 2026-03-11 23:23:07.549271 | controller | changed: .d..t...... ./ 2026-03-11 23:23:08.058663 | controller | changed: .d..t...... ./ 2026-03-11 23:23:08.082221 | 2026-03-11 23:23:08.082385 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-03-11 23:23:08.511250 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007001 2026-03-11 23:23:08.745411 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.007913 2026-03-11 23:23:08.766722 | 2026-03-11 23:23:08.766877 | PLAY [all] 2026-03-11 23:23:08.772553 | 2026-03-11 23:23:08.772619 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2026-03-11 23:23:09.274167 | controller | changed 2026-03-11 23:23:09.281985 | 2026-03-11 23:23:09.282040 | PLAY RECAP 2026-03-11 23:23:09.282088 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2026-03-11 23:23:09.282119 | 2026-03-11 23:23:09.412859 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main] 2026-03-11 23:23:09.415350 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main] 2026-03-11 23:23:09.952368 | 2026-03-11 23:23:09.952487 | PLAY [localhost] 2026-03-11 23:23:09.962075 | 2026-03-11 23:23:09.962150 | TASK [Generate Zuul manifest] 2026-03-11 23:23:09.985288 | localhost | ok 2026-03-11 23:23:09.999319 | 2026-03-11 23:23:09.999395 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-03-11 23:23:10.315997 | localhost | changed 2026-03-11 23:23:10.327020 | 2026-03-11 23:23:10.327092 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-03-11 23:23:10.795433 | localhost | ok 2026-03-11 23:23:10.805142 | 2026-03-11 23:23:10.805234 | TASK [Upload logs] 2026-03-11 23:23:10.826671 | localhost | ok 2026-03-11 23:23:10.885417 | 2026-03-11 23:23:10.885534 | TASK [Set zuul-log-path fact] 2026-03-11 23:23:10.905527 | localhost | ok 2026-03-11 23:23:10.918269 | 2026-03-11 23:23:10.918340 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-03-11 23:23:10.949010 | localhost | ok 2026-03-11 23:23:10.956501 | 2026-03-11 23:23:10.956565 | TASK [upload-logs : Create log directories] 2026-03-11 23:23:11.345681 | localhost | changed 2026-03-11 23:23:11.351096 | 2026-03-11 23:23:11.351171 | TASK [upload-logs : Ensure logs are readable before uploading] 2026-03-11 23:23:11.756982 | localhost -> localhost | ok: Runtime: 0:00:00.005085 2026-03-11 23:23:11.763502 | 2026-03-11 23:23:11.763711 | TASK [upload-logs : Upload logs to log server] 2026-03-11 23:23:12.242753 | localhost | Output suppressed because no_log was given 2026-03-11 23:23:12.248815 | 2026-03-11 23:23:12.248884 | LOOP [upload-logs : Compress console log and json output] 2026-03-11 23:23:12.298834 | localhost | skipping: Conditional result was False 2026-03-11 23:23:12.305633 | localhost | skipping: Conditional result was False 2026-03-11 23:23:12.323819 | 2026-03-11 23:23:12.323970 | LOOP [upload-logs : Upload compressed console log and json output] 2026-03-11 23:23:12.370685 | localhost | skipping: Conditional result was False 2026-03-11 23:23:12.371091 | 2026-03-11 23:23:12.375094 | localhost | skipping: Conditional result was False 2026-03-11 23:23:12.390129 | 2026-03-11 23:23:12.390371 | LOOP [upload-logs : Upload console log and json output]