2026-03-17 14:01:38.761927 | Job console starting 2026-03-17 14:01:38.797965 | Updating git repos 2026-03-17 14:01:38.828007 | Cloning repos into workspace 2026-03-17 14:01:38.976352 | Restoring repo states 2026-03-17 14:01:39.037150 | Merging changes 2026-03-17 14:01:39.768043 | Checking out repos 2026-03-17 14:01:40.087325 | Preparing playbooks 2026-03-17 14:01:41.229671 | Running Ansible setup 2026-03-17 14:01:45.238370 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main] 2026-03-17 14:01:45.813792 | 2026-03-17 14:01:45.813898 | PLAY [localhost] 2026-03-17 14:01:45.821126 | 2026-03-17 14:01:45.821196 | TASK [Gathering Facts] 2026-03-17 14:01:46.678997 | localhost | ok 2026-03-17 14:01:46.689971 | 2026-03-17 14:01:46.690072 | TASK [Setup log path fact] 2026-03-17 14:01:46.709002 | localhost | ok 2026-03-17 14:01:46.722404 | 2026-03-17 14:01:46.722480 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-03-17 14:01:46.751494 | localhost | ok 2026-03-17 14:01:46.761828 | 2026-03-17 14:01:46.761927 | TASK [emit-job-header : Print job information] 2026-03-17 14:01:46.802046 | # Job Information 2026-03-17 14:01:46.802294 | Ansible Version: 2.16.16 2026-03-17 14:01:46.802400 | Job: ansible-collection-kubernetes-molecule-aio-rockylinux-9 2026-03-17 14:01:46.802447 | Pipeline: check 2026-03-17 14:01:46.802476 | Executor: 0a8996d2b663 2026-03-17 14:01:46.802503 | Triggered by: https://github.com/vexxhost/ansible-collection-kubernetes/pull/238 2026-03-17 14:01:46.802534 | Event ID: 99ded8b0-2207-11f1-8026-f2420cbb33b9 2026-03-17 14:01:46.806222 | 2026-03-17 14:01:46.806306 | LOOP [emit-job-header : Print node information] 2026-03-17 14:01:46.891620 | localhost | ok: 2026-03-17 14:01:46.891983 | localhost | # Node Information 2026-03-17 14:01:46.892054 | localhost | Inventory Hostname: controller 2026-03-17 14:01:46.892123 | localhost | Hostname: np0000159363 2026-03-17 14:01:46.892167 | localhost | Username: zuul 2026-03-17 14:01:46.892215 | localhost | Distro: Rocky 9.7 2026-03-17 14:01:46.892258 | localhost | Provider: yul1 2026-03-17 14:01:46.892299 | localhost | Region: ca-ymq-1 2026-03-17 14:01:46.892340 | localhost | Label: rockylinux-9 2026-03-17 14:01:46.892381 | localhost | Product Name: OpenStack Nova 2026-03-17 14:01:46.892421 | localhost | Interface IP: 199.19.213.157 2026-03-17 14:01:46.911644 | 2026-03-17 14:01:46.911789 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-03-17 14:01:47.281594 | localhost -> localhost | changed 2026-03-17 14:01:47.289575 | 2026-03-17 14:01:47.289674 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-03-17 14:01:48.389642 | localhost -> localhost | changed 2026-03-17 14:01:48.399606 | 2026-03-17 14:01:48.399686 | PLAY [all] 2026-03-17 14:01:48.408314 | 2026-03-17 14:01:48.408378 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-03-17 14:01:48.649662 | controller -> localhost | ok 2026-03-17 14:01:48.663822 | 2026-03-17 14:01:48.663927 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-03-17 14:01:48.695235 | controller | ok 2026-03-17 14:01:48.708356 | controller | included: /var/lib/zuul/builds/d886473299a1455db7d3716a69d68eac/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-03-17 14:01:48.713558 | 2026-03-17 14:01:48.713623 | TASK [add-build-sshkey : Create Temp SSH key] 2026-03-17 14:01:49.907443 | controller -> localhost | Generating public/private rsa key pair. 2026-03-17 14:01:49.907624 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/d886473299a1455db7d3716a69d68eac/work/d886473299a1455db7d3716a69d68eac_id_rsa 2026-03-17 14:01:49.907667 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/d886473299a1455db7d3716a69d68eac/work/d886473299a1455db7d3716a69d68eac_id_rsa.pub 2026-03-17 14:01:49.907701 | controller -> localhost | The key fingerprint is: 2026-03-17 14:01:49.907733 | controller -> localhost | SHA256:j72mSJyskviCAEw81lW/5g+8kNLKz0CFPxl23wC7sOU zuul-build-sshkey 2026-03-17 14:01:49.907778 | controller -> localhost | The key's randomart image is: 2026-03-17 14:01:49.907809 | controller -> localhost | +---[RSA 3072]----+ 2026-03-17 14:01:49.907843 | controller -> localhost | |. . .... . | 2026-03-17 14:01:49.907875 | controller -> localhost | | = . . . o | 2026-03-17 14:01:49.907906 | controller -> localhost | |+ . . = = . | 2026-03-17 14:01:49.907936 | controller -> localhost | |.. + O + o | 2026-03-17 14:01:49.907966 | controller -> localhost | |. . =SE . . | 2026-03-17 14:01:49.907995 | controller -> localhost | |. .o..*+ | 2026-03-17 14:01:49.908024 | controller -> localhost | |o. . o=+.+o | 2026-03-17 14:01:49.908053 | controller -> localhost | |+ o .o=.. =. | 2026-03-17 14:01:49.908085 | controller -> localhost | | o...ooo.+.. | 2026-03-17 14:01:49.908116 | controller -> localhost | +----[SHA256]-----+ 2026-03-17 14:01:49.908173 | controller -> localhost | ok: Runtime: 0:00:00.787060 2026-03-17 14:01:49.914788 | 2026-03-17 14:01:49.914875 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-03-17 14:01:49.945827 | controller | ok 2026-03-17 14:01:49.955848 | controller | included: /var/lib/zuul/builds/d886473299a1455db7d3716a69d68eac/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-03-17 14:01:49.962626 | 2026-03-17 14:01:49.962688 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-03-17 14:01:49.986026 | controller | skipping: Conditional result was False 2026-03-17 14:01:49.995562 | 2026-03-17 14:01:49.995690 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-03-17 14:01:50.453058 | controller | changed 2026-03-17 14:01:50.459696 | 2026-03-17 14:01:50.459787 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-03-17 14:01:50.712276 | controller | ok 2026-03-17 14:01:50.719737 | 2026-03-17 14:01:50.719820 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-03-17 14:01:51.666591 | controller | changed 2026-03-17 14:01:51.672193 | 2026-03-17 14:01:51.672255 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-03-17 14:01:52.575658 | controller | changed 2026-03-17 14:01:52.582955 | 2026-03-17 14:01:52.583042 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-03-17 14:01:52.606851 | controller | skipping: Conditional result was False 2026-03-17 14:01:52.612041 | 2026-03-17 14:01:52.612108 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-03-17 14:01:52.981953 | controller -> localhost | changed 2026-03-17 14:01:52.997356 | 2026-03-17 14:01:52.997419 | TASK [add-build-sshkey : Add back temp key] 2026-03-17 14:01:53.294550 | controller -> localhost | Identity added: /var/lib/zuul/builds/d886473299a1455db7d3716a69d68eac/work/d886473299a1455db7d3716a69d68eac_id_rsa (zuul-build-sshkey) 2026-03-17 14:01:53.294794 | controller -> localhost | ok: Runtime: 0:00:00.014714 2026-03-17 14:01:53.301253 | 2026-03-17 14:01:53.301321 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-03-17 14:01:53.699087 | controller | ok 2026-03-17 14:01:53.705323 | 2026-03-17 14:01:53.705432 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-03-17 14:01:53.730890 | controller | skipping: Conditional result was False 2026-03-17 14:01:53.745974 | 2026-03-17 14:01:53.746100 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-03-17 14:01:54.133849 | controller | ok 2026-03-17 14:01:54.142708 | 2026-03-17 14:01:54.142796 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-03-17 14:01:55.211272 | controller | Output suppressed because no_log was given 2026-03-17 14:01:55.221104 | 2026-03-17 14:01:55.221231 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-03-17 14:01:55.480704 | controller | ok: "logs" 2026-03-17 14:01:55.480942 | controller | ok: All items complete 2026-03-17 14:01:55.481014 | 2026-03-17 14:01:55.683105 | controller | ok: "artifacts" 2026-03-17 14:01:55.899646 | controller | ok: "docs" 2026-03-17 14:01:55.917268 | 2026-03-17 14:01:55.917411 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-03-17 14:01:56.174172 | controller | changed: "logs" 2026-03-17 14:01:56.406819 | controller | changed: "artifacts" 2026-03-17 14:01:56.635720 | controller | changed: "docs" 2026-03-17 14:01:56.648657 | 2026-03-17 14:01:56.648725 | PLAY RECAP 2026-03-17 14:01:56.648782 | controller | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0 2026-03-17 14:01:56.648821 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-03-17 14:01:56.648849 | 2026-03-17 14:01:56.758977 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main] 2026-03-17 14:01:56.761598 | PRE-RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main] 2026-03-17 14:01:57.329444 | 2026-03-17 14:01:57.330022 | PLAY [all] 2026-03-17 14:01:57.341099 | 2026-03-17 14:01:57.341219 | TASK [setup-uv : Extract archive] 2026-03-17 14:02:00.072853 | controller | changed 2026-03-17 14:02:00.079088 | 2026-03-17 14:02:00.079169 | TASK [setup-uv : Print version] 2026-03-17 14:02:00.100862 | [controller] Waiting on logger 2026-03-17 14:02:00.614930 | controller | ok: Runtime: 0:00:00.015457 2026-03-17 14:02:00.624684 | 2026-03-17 14:02:00.624745 | PLAY RECAP 2026-03-17 14:02:00.624792 | controller | ok: 2 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-03-17 14:02:00.624819 | 2026-03-17 14:02:00.737745 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main] 2026-03-17 14:02:00.740452 | RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main] 2026-03-17 14:02:01.289318 | 2026-03-17 14:02:01.289442 | PLAY [all] 2026-03-17 14:02:01.299997 | 2026-03-17 14:02:01.300092 | TASK [Copy inventory file for Zuul] 2026-03-17 14:02:02.614283 | controller | changed 2026-03-17 14:02:02.619632 | 2026-03-17 14:02:02.619748 | TASK [Switch "ansible_host" to private IP] 2026-03-17 14:02:02.958916 | controller | changed: 1 replacements made 2026-03-17 14:02:02.964103 | 2026-03-17 14:02:02.964170 | TASK [Run Molecule scenario] 2026-03-17 14:02:02.984714 | [controller] Waiting on logger 2026-03-17 14:02:11.114942 | [controller] Waiting on logger 2026-03-17 14:02:21.286061 | [controller] Waiting on logger 2026-03-17 14:02:31.462049 | [controller] Waiting on logger 2026-03-17 14:02:41.638099 | [controller] Waiting on logger 2026-03-17 14:02:51.814170 | [controller] Waiting on logger 2026-03-17 14:03:01.990115 | [controller] Waiting on logger 2026-03-17 14:03:11.147039 | [controller] Waiting on logger 2026-03-17 14:03:21.321918 | [controller] Waiting on logger 2026-03-17 14:03:31.494132 | [controller] Waiting on logger 2026-03-17 14:03:41.670243 | [controller] Waiting on logger 2026-03-17 14:03:51.845821 | [controller] Waiting on logger 2026-03-17 14:04:02.053925 | [controller] Waiting on logger 2026-03-17 14:04:11.211775 | [controller] Waiting on logger 2026-03-17 14:04:21.382035 | [controller] Waiting on logger 2026-03-17 14:04:31.557941 | [controller] Waiting on logger 2026-03-17 14:04:41.734106 | [controller] Waiting on logger 2026-03-17 14:04:51.910104 | [controller] Waiting on logger 2026-03-17 14:05:02.085996 | [controller] Waiting on logger 2026-03-17 14:05:11.270287 | [controller] Waiting on logger 2026-03-17 14:05:21.457621 | [controller] Waiting on logger 2026-03-17 14:05:31.622056 | [controller] Waiting on logger 2026-03-17 14:05:41.798011 | [controller] Waiting on logger 2026-03-17 14:05:51.974328 | [controller] Waiting on logger 2026-03-17 14:06:01.131399 | [controller] Waiting on logger 2026-03-17 14:06:11.334114 | [controller] Waiting on logger 2026-03-17 14:06:21.509872 | [controller] Waiting on logger 2026-03-17 14:06:31.689901 | [controller] Waiting on logger 2026-03-17 14:06:42.489234 | localhost | Timeout exception waiting for the logger. Please check connectivity to [199.19.213.157:19885] 2026-03-17 14:06:57.936353 | controller | ERROR 2026-03-17 14:06:57.936562 | controller | { 2026-03-17 14:06:57.936605 | controller | "delta": "0:04:54.532585", 2026-03-17 14:06:57.936636 | controller | "end": "2026-03-17 14:06:56.676581", 2026-03-17 14:06:57.936665 | controller | "msg": "non-zero return code", 2026-03-17 14:06:57.936692 | controller | "rc": 2, 2026-03-17 14:06:57.936720 | controller | "start": "2026-03-17 14:02:02.143996" 2026-03-17 14:06:57.936744 | controller | } failure 2026-03-17 14:06:57.948231 | 2026-03-17 14:06:57.948346 | PLAY RECAP 2026-03-17 14:06:57.948459 | controller | ok: 2 changed: 2 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0 2026-03-17 14:06:57.948515 | 2026-03-17 14:06:58.046250 | RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main] 2026-03-17 14:06:58.048097 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main] 2026-03-17 14:06:58.601958 | 2026-03-17 14:06:58.602475 | PLAY [all] 2026-03-17 14:06:58.612280 | 2026-03-17 14:06:58.612350 | TASK [fetch-output : Set log path for multiple nodes] 2026-03-17 14:06:58.656314 | controller | skipping: Conditional result was False 2026-03-17 14:06:58.664010 | 2026-03-17 14:06:58.664111 | TASK [fetch-output : Set log path for single node] 2026-03-17 14:06:58.705975 | controller | ok 2026-03-17 14:06:58.711245 | 2026-03-17 14:06:58.711307 | LOOP [fetch-output : Ensure local output dirs] 2026-03-17 14:06:59.062833 | controller -> localhost | ok: "/var/lib/zuul/builds/d886473299a1455db7d3716a69d68eac/work/logs" 2026-03-17 14:06:59.263827 | controller -> localhost | changed: "/var/lib/zuul/builds/d886473299a1455db7d3716a69d68eac/work/artifacts" 2026-03-17 14:06:59.528918 | controller -> localhost | changed: "/var/lib/zuul/builds/d886473299a1455db7d3716a69d68eac/work/docs" 2026-03-17 14:06:59.547584 | 2026-03-17 14:06:59.547728 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-03-17 14:07:00.224455 | controller | changed: .d..t...... ./ 2026-03-17 14:07:00.224800 | controller | changed: All items complete 2026-03-17 14:07:00.224841 | 2026-03-17 14:07:00.739044 | controller | changed: .d..t...... ./ 2026-03-17 14:07:01.248331 | controller | changed: .d..t...... ./ 2026-03-17 14:07:01.285775 | 2026-03-17 14:07:01.285887 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-03-17 14:07:01.705954 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.006507 2026-03-17 14:07:01.909324 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.006677 2026-03-17 14:07:01.932224 | 2026-03-17 14:07:01.932316 | PLAY [all] 2026-03-17 14:07:01.949675 | 2026-03-17 14:07:01.952120 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2026-03-17 14:07:02.423716 | controller | changed 2026-03-17 14:07:02.440448 | 2026-03-17 14:07:02.440551 | PLAY RECAP 2026-03-17 14:07:02.440601 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2026-03-17 14:07:02.440624 | 2026-03-17 14:07:02.562279 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main] 2026-03-17 14:07:02.565002 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main] 2026-03-17 14:07:03.127500 | 2026-03-17 14:07:03.127642 | PLAY [localhost] 2026-03-17 14:07:03.137916 | 2026-03-17 14:07:03.138051 | TASK [Generate Zuul manifest] 2026-03-17 14:07:03.159024 | localhost | ok 2026-03-17 14:07:03.174368 | 2026-03-17 14:07:03.174510 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-03-17 14:07:03.494565 | localhost | changed 2026-03-17 14:07:03.507136 | 2026-03-17 14:07:03.507222 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-03-17 14:07:03.537576 | localhost | ok 2026-03-17 14:07:03.546450 | 2026-03-17 14:07:03.546514 | TASK [Upload logs] 2026-03-17 14:07:03.563585 | localhost | ok 2026-03-17 14:07:03.676569 | 2026-03-17 14:07:03.676686 | TASK [Set zuul-log-path fact] 2026-03-17 14:07:03.696361 | localhost | ok 2026-03-17 14:07:03.707317 | 2026-03-17 14:07:03.707383 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-03-17 14:07:03.738541 | localhost | ok 2026-03-17 14:07:03.748775 | 2026-03-17 14:07:03.748910 | TASK [upload-logs : Create log directories] 2026-03-17 14:07:04.135715 | localhost | changed 2026-03-17 14:07:04.141823 | 2026-03-17 14:07:04.141917 | TASK [upload-logs : Ensure logs are readable before uploading] 2026-03-17 14:07:04.530157 | localhost -> localhost | ok: Runtime: 0:00:00.003882 2026-03-17 14:07:04.536947 | 2026-03-17 14:07:04.537055 | TASK [upload-logs : Upload logs to log server] 2026-03-17 14:07:04.993801 | localhost | Output suppressed because no_log was given 2026-03-17 14:07:04.999315 | 2026-03-17 14:07:04.999425 | LOOP [upload-logs : Compress console log and json output] 2026-03-17 14:07:05.044548 | localhost | skipping: Conditional result was False 2026-03-17 14:07:05.052374 | localhost | skipping: Conditional result was False 2026-03-17 14:07:05.070425 | 2026-03-17 14:07:05.070566 | LOOP [upload-logs : Upload compressed console log and json output] 2026-03-17 14:07:05.110023 | localhost | skipping: Conditional result was False 2026-03-17 14:07:05.110352 | 2026-03-17 14:07:05.114357 | localhost | skipping: Conditional result was False 2026-03-17 14:07:05.121124 | 2026-03-17 14:07:05.121281 | LOOP [upload-logs : Upload console log and json output]