2026-01-22 21:46:34.325600 | Job console starting 2026-01-22 21:46:34.338199 | Updating git repos 2026-01-22 21:46:34.375197 | Cloning repos into workspace 2026-01-22 21:46:34.433351 | Restoring repo states 2026-01-22 21:46:34.444783 | Merging changes 2026-01-22 21:46:35.015533 | Checking out repos 2026-01-22 21:46:35.197013 | Preparing playbooks 2026-01-22 21:46:36.298161 | Running Ansible setup 2026-01-22 21:46:39.826203 | PRE-RUN START: [trusted : vexxhost.dev/zuul-config/playbooks/base/pre.yaml@main] 2026-01-22 21:46:40.406330 | 2026-01-22 21:46:40.406481 | PLAY [localhost] 2026-01-22 21:46:40.415133 | 2026-01-22 21:46:40.415204 | TASK [Gathering Facts] 2026-01-22 21:46:41.267108 | localhost | ok 2026-01-22 21:46:41.277400 | 2026-01-22 21:46:41.277523 | TASK [Setup log path fact] 2026-01-22 21:46:41.299201 | localhost | ok 2026-01-22 21:46:41.313891 | 2026-01-22 21:46:41.314026 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-01-22 21:46:41.343896 | localhost | ok 2026-01-22 21:46:41.351705 | 2026-01-22 21:46:41.351785 | TASK [emit-job-header : Print job information] 2026-01-22 21:46:41.399482 | # Job Information 2026-01-22 21:46:41.399639 | Ansible Version: 2.16.15 2026-01-22 21:46:41.399673 | Job: ansible-collection-kubernetes-molecule-aio-rockylinux-9 2026-01-22 21:46:41.399696 | Pipeline: check 2026-01-22 21:46:41.399716 | Executor: 3a2793d2bd32 2026-01-22 21:46:41.399735 | Triggered by: https://github.com/vexxhost/ansible-collection-kubernetes/pull/229 2026-01-22 21:46:41.399757 | Event ID: a4636040-f7db-11f0-909d-aaab0d2ecdc5 2026-01-22 21:46:41.402579 | 2026-01-22 21:46:41.402647 | LOOP [emit-job-header : Print node information] 2026-01-22 21:46:41.494929 | localhost | ok: 2026-01-22 21:46:41.495152 | localhost | # Node Information 2026-01-22 21:46:41.495192 | localhost | Inventory Hostname: controller 2026-01-22 21:46:41.495355 | localhost | Hostname: np0000154406 2026-01-22 21:46:41.495415 | localhost | Username: zuul 2026-01-22 21:46:41.495455 | localhost | Distro: Rocky 9.7 2026-01-22 21:46:41.495485 | localhost | Provider: yul1 2026-01-22 21:46:41.495512 | localhost | Region: ca-ymq-1 2026-01-22 21:46:41.495537 | localhost | Label: rockylinux-9 2026-01-22 21:46:41.495562 | localhost | Product Name: OpenStack Nova 2026-01-22 21:46:41.495588 | localhost | Interface IP: 199.19.213.163 2026-01-22 21:46:41.512719 | 2026-01-22 21:46:41.512876 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-01-22 21:46:41.902539 | localhost -> localhost | changed 2026-01-22 21:46:41.908626 | 2026-01-22 21:46:41.908698 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-01-22 21:46:42.728001 | localhost -> localhost | changed 2026-01-22 21:46:42.736899 | 2026-01-22 21:46:42.737004 | PLAY [all] 2026-01-22 21:46:42.744976 | 2026-01-22 21:46:42.745042 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-01-22 21:46:42.971970 | controller -> localhost | ok 2026-01-22 21:46:42.983303 | 2026-01-22 21:46:42.983371 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-01-22 21:46:43.014354 | controller | ok 2026-01-22 21:46:43.029825 | controller | included: /var/lib/zuul/builds/ede18818c5e24fd5a3c82f1527d0ad28/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-01-22 21:46:43.035039 | 2026-01-22 21:46:43.035101 | TASK [add-build-sshkey : Create Temp SSH key] 2026-01-22 21:46:44.667519 | controller -> localhost | Generating public/private rsa key pair. 2026-01-22 21:46:44.668210 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/ede18818c5e24fd5a3c82f1527d0ad28/work/ede18818c5e24fd5a3c82f1527d0ad28_id_rsa 2026-01-22 21:46:44.668273 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/ede18818c5e24fd5a3c82f1527d0ad28/work/ede18818c5e24fd5a3c82f1527d0ad28_id_rsa.pub 2026-01-22 21:46:44.668323 | controller -> localhost | The key fingerprint is: 2026-01-22 21:46:44.668359 | controller -> localhost | SHA256:bRXbSWGSdS2BuTPG/+8vy+7ZvXqsio1C/w9/15fXPDg zuul-build-sshkey 2026-01-22 21:46:44.668410 | controller -> localhost | The key's randomart image is: 2026-01-22 21:46:44.668442 | controller -> localhost | +---[RSA 3072]----+ 2026-01-22 21:46:44.668477 | controller -> localhost | | o=*oo| 2026-01-22 21:46:44.668508 | controller -> localhost | | +B.o.| 2026-01-22 21:46:44.668537 | controller -> localhost | | .o.o. | 2026-01-22 21:46:44.668566 | controller -> localhost | | . .* | 2026-01-22 21:46:44.668594 | controller -> localhost | | S o. + | 2026-01-22 21:46:44.668623 | controller -> localhost | | . . . | 2026-01-22 21:46:44.668650 | controller -> localhost | | . . . oo+| 2026-01-22 21:46:44.668678 | controller -> localhost | | . .+ oE.OX| 2026-01-22 21:46:44.668710 | controller -> localhost | | .o.+oB%=#| 2026-01-22 21:46:44.668739 | controller -> localhost | +----[SHA256]-----+ 2026-01-22 21:46:44.668805 | controller -> localhost | ok: Runtime: 0:00:01.195793 2026-01-22 21:46:44.675253 | 2026-01-22 21:46:44.675319 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-01-22 21:46:44.707599 | controller | ok 2026-01-22 21:46:44.718137 | controller | included: /var/lib/zuul/builds/ede18818c5e24fd5a3c82f1527d0ad28/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-01-22 21:46:44.726021 | 2026-01-22 21:46:44.726081 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-01-22 21:46:44.751002 | controller | skipping: Conditional result was False 2026-01-22 21:46:44.760229 | 2026-01-22 21:46:44.760326 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-01-22 21:46:45.229121 | controller | changed 2026-01-22 21:46:45.235704 | 2026-01-22 21:46:45.235796 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-01-22 21:46:45.480835 | controller | ok 2026-01-22 21:46:45.486516 | 2026-01-22 21:46:45.486581 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-01-22 21:46:46.295507 | controller | changed 2026-01-22 21:46:46.304308 | 2026-01-22 21:46:46.304439 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-01-22 21:46:47.085245 | controller | changed 2026-01-22 21:46:47.091127 | 2026-01-22 21:46:47.091188 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-01-22 21:46:47.115665 | controller | skipping: Conditional result was False 2026-01-22 21:46:47.124675 | 2026-01-22 21:46:47.124765 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-01-22 21:46:47.516675 | controller -> localhost | changed 2026-01-22 21:46:47.530693 | 2026-01-22 21:46:47.530777 | TASK [add-build-sshkey : Add back temp key] 2026-01-22 21:46:47.835082 | controller -> localhost | Identity added: /var/lib/zuul/builds/ede18818c5e24fd5a3c82f1527d0ad28/work/ede18818c5e24fd5a3c82f1527d0ad28_id_rsa (zuul-build-sshkey) 2026-01-22 21:46:47.835331 | controller -> localhost | ok: Runtime: 0:00:00.015057 2026-01-22 21:46:47.843096 | 2026-01-22 21:46:47.843185 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-01-22 21:46:48.244149 | controller | ok 2026-01-22 21:46:48.249853 | 2026-01-22 21:46:48.249939 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-01-22 21:46:48.284507 | controller | skipping: Conditional result was False 2026-01-22 21:46:48.297561 | 2026-01-22 21:46:48.297668 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-01-22 21:46:48.695715 | controller | ok 2026-01-22 21:46:48.700849 | 2026-01-22 21:46:48.700914 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-01-22 21:46:49.748782 | controller | Output suppressed because no_log was given 2026-01-22 21:46:49.756732 | 2026-01-22 21:46:49.756822 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-01-22 21:46:49.990699 | controller | ok: "logs" 2026-01-22 21:46:49.991002 | controller | ok: All items complete 2026-01-22 21:46:49.991053 | 2026-01-22 21:46:50.190203 | controller | ok: "artifacts" 2026-01-22 21:46:50.401450 | controller | ok: "docs" 2026-01-22 21:46:50.409594 | 2026-01-22 21:46:50.409662 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-01-22 21:46:50.650268 | controller | changed: "logs" 2026-01-22 21:46:50.890127 | controller | changed: "artifacts" 2026-01-22 21:46:51.115087 | controller | changed: "docs" 2026-01-22 21:46:51.131234 | 2026-01-22 21:46:51.131297 | PLAY RECAP 2026-01-22 21:46:51.131354 | controller | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0 2026-01-22 21:46:51.131393 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-01-22 21:46:51.131421 | 2026-01-22 21:46:51.248763 | PRE-RUN END RESULT_NORMAL: [trusted : vexxhost.dev/zuul-config/playbooks/base/pre.yaml@main] 2026-01-22 21:46:51.251742 | PRE-RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main] 2026-01-22 21:46:51.819177 | 2026-01-22 21:46:51.819301 | PLAY [all] 2026-01-22 21:46:51.829845 | 2026-01-22 21:46:51.829919 | TASK [setup-uv : Extract archive] 2026-01-22 21:47:05.831719 | controller | changed 2026-01-22 21:47:05.839758 | 2026-01-22 21:47:05.839874 | TASK [setup-uv : Print version] 2026-01-22 21:47:05.867573 | [controller] Waiting on logger 2026-01-22 21:47:06.291161 | controller | ok: Runtime: 0:00:00.011585 2026-01-22 21:47:06.301414 | 2026-01-22 21:47:06.301481 | PLAY RECAP 2026-01-22 21:47:06.301531 | controller | ok: 2 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-01-22 21:47:06.301555 | 2026-01-22 21:47:06.420901 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main] 2026-01-22 21:47:06.422173 | RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main] 2026-01-22 21:47:06.996572 | 2026-01-22 21:47:06.996702 | PLAY [all] 2026-01-22 21:47:07.007828 | 2026-01-22 21:47:07.007990 | TASK [Copy inventory file for Zuul] 2026-01-22 21:47:08.256090 | controller | changed 2026-01-22 21:47:08.261410 | 2026-01-22 21:47:08.261488 | TASK [Switch "ansible_host" to private IP] 2026-01-22 21:47:08.569842 | controller | changed: 1 replacements made 2026-01-22 21:47:08.577324 | 2026-01-22 21:47:08.577436 | TASK [Run Molecule scenario] 2026-01-22 21:47:08.600060 | [controller] Waiting on logger 2026-01-22 21:47:16.741794 | [controller] Waiting on logger 2026-01-22 21:47:25.905854 | [controller] Waiting on logger 2026-01-22 21:47:36.069885 | [controller] Waiting on logger 2026-01-22 21:47:46.245816 | [controller] Waiting on logger 2026-01-22 21:47:56.421841 | [controller] Waiting on logger 2026-01-22 21:48:06.597860 | [controller] Waiting on logger 2026-01-22 21:48:16.775283 | [controller] Waiting on logger 2026-01-22 21:48:25.963017 | [controller] Waiting on logger 2026-01-22 21:48:36.166000 | [controller] Waiting on logger 2026-01-22 21:48:46.341935 | [controller] Waiting on logger 2026-01-22 21:48:56.517889 | [controller] Waiting on logger 2026-01-22 21:49:06.694311 | [controller] Waiting on logger 2026-01-22 21:49:16.869884 | [controller] Waiting on logger 2026-01-22 21:49:26.021934 | [controller] Waiting on logger 2026-01-22 21:49:36.198086 | [controller] Waiting on logger 2026-01-22 21:49:46.374056 | [controller] Waiting on logger 2026-01-22 21:49:56.550071 | [controller] Waiting on logger 2026-01-22 21:50:06.726380 | [controller] Waiting on logger 2026-01-22 21:50:15.883548 | [controller] Waiting on logger 2026-01-22 21:50:26.053850 | [controller] Waiting on logger 2026-01-22 21:50:36.230165 | [controller] Waiting on logger 2026-01-22 21:50:46.409860 | [controller] Waiting on logger 2026-01-22 21:50:56.582114 | [controller] Waiting on logger 2026-01-22 21:51:06.790015 | [controller] Waiting on logger 2026-01-22 21:51:15.947015 | [controller] Waiting on logger 2026-01-22 21:51:26.117738 | [controller] Waiting on logger 2026-01-22 21:51:36.293956 | [controller] Waiting on logger 2026-01-22 21:51:46.473774 | [controller] Waiting on logger 2026-01-22 21:51:56.645968 | [controller] Waiting on logger 2026-01-22 21:52:06.822049 | [controller] Waiting on logger 2026-01-22 21:52:15.978993 | [controller] Waiting on logger 2026-01-22 21:52:26.149872 | [controller] Waiting on logger 2026-01-22 21:52:34.093180 | controller | ok: Runtime: 0:05:23.967906 2026-01-22 21:52:34.109306 | 2026-01-22 21:52:34.109362 | PLAY RECAP 2026-01-22 21:52:34.109408 | controller | ok: 3 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-01-22 21:52:34.109430 | 2026-01-22 21:52:34.224473 | RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main] 2026-01-22 21:52:34.227440 | POST-RUN START: [trusted : vexxhost.dev/zuul-config/playbooks/base/post.yaml@main] 2026-01-22 21:52:34.786203 | 2026-01-22 21:52:34.786348 | PLAY [all] 2026-01-22 21:52:34.797111 | 2026-01-22 21:52:34.797188 | TASK [fetch-output : Set log path for multiple nodes] 2026-01-22 21:52:34.842655 | controller | skipping: Conditional result was False 2026-01-22 21:52:34.851300 | 2026-01-22 21:52:34.851412 | TASK [fetch-output : Set log path for single node] 2026-01-22 21:52:34.896261 | controller | ok 2026-01-22 21:52:34.902986 | 2026-01-22 21:52:34.903064 | LOOP [fetch-output : Ensure local output dirs] 2026-01-22 21:52:35.310864 | controller -> localhost | ok: "/var/lib/zuul/builds/ede18818c5e24fd5a3c82f1527d0ad28/work/logs" 2026-01-22 21:52:35.547453 | controller -> localhost | changed: "/var/lib/zuul/builds/ede18818c5e24fd5a3c82f1527d0ad28/work/artifacts" 2026-01-22 21:52:35.760244 | controller -> localhost | changed: "/var/lib/zuul/builds/ede18818c5e24fd5a3c82f1527d0ad28/work/docs" 2026-01-22 21:52:35.776026 | 2026-01-22 21:52:35.776155 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-01-22 21:52:36.466934 | controller | changed: .d..t...... ./ 2026-01-22 21:52:36.467152 | controller | changed: All items complete 2026-01-22 21:52:36.467179 | 2026-01-22 21:52:36.947261 | controller | changed: .d..t...... ./ 2026-01-22 21:52:37.423340 | controller | changed: .d..t...... ./ 2026-01-22 21:52:37.451161 | 2026-01-22 21:52:37.451336 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-01-22 21:52:37.901275 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007807 2026-01-22 21:52:38.119776 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.008765 2026-01-22 21:52:38.136319 | 2026-01-22 21:52:38.136451 | PLAY [all] 2026-01-22 21:52:38.142101 | 2026-01-22 21:52:38.142169 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2026-01-22 21:52:38.590769 | controller | changed 2026-01-22 21:52:38.597593 | 2026-01-22 21:52:38.598839 | PLAY RECAP 2026-01-22 21:52:38.598951 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2026-01-22 21:52:38.598990 | 2026-01-22 21:52:38.714590 | POST-RUN END RESULT_NORMAL: [trusted : vexxhost.dev/zuul-config/playbooks/base/post.yaml@main] 2026-01-22 21:52:38.717534 | POST-RUN START: [trusted : vexxhost.dev/zuul-config/playbooks/base/post-logs.yaml@main] 2026-01-22 21:52:39.259685 | 2026-01-22 21:52:39.259819 | PLAY [localhost] 2026-01-22 21:52:39.269529 | 2026-01-22 21:52:39.269600 | TASK [Generate Zuul manifest] 2026-01-22 21:52:39.293975 | localhost | ok 2026-01-22 21:52:39.307932 | 2026-01-22 21:52:39.308009 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-01-22 21:52:39.629509 | localhost | changed 2026-01-22 21:52:39.644541 | 2026-01-22 21:52:39.644620 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-01-22 21:52:39.678517 | localhost | ok 2026-01-22 21:52:39.691602 | 2026-01-22 21:52:39.691683 | TASK [Upload logs] 2026-01-22 21:52:39.714779 | localhost | ok 2026-01-22 21:52:39.777654 | 2026-01-22 21:52:39.777764 | TASK [Set zuul-log-path fact] 2026-01-22 21:52:39.798607 | localhost | ok 2026-01-22 21:52:39.812616 | 2026-01-22 21:52:39.812687 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-01-22 21:52:39.845693 | localhost | ok 2026-01-22 21:52:39.856453 | 2026-01-22 21:52:39.856537 | TASK [upload-logs : Create log directories] 2026-01-22 21:52:40.275193 | localhost | changed 2026-01-22 21:52:40.281968 | 2026-01-22 21:52:40.282058 | TASK [upload-logs : Ensure logs are readable before uploading] 2026-01-22 21:52:40.688373 | localhost -> localhost | ok: Runtime: 0:00:00.006124 2026-01-22 21:52:40.695076 | 2026-01-22 21:52:40.695166 | TASK [upload-logs : Upload logs to log server] 2026-01-22 21:52:41.150725 | localhost | Output suppressed because no_log was given 2026-01-22 21:52:41.158227 | 2026-01-22 21:52:41.158367 | LOOP [upload-logs : Compress console log and json output] 2026-01-22 21:52:41.202036 | localhost | skipping: Conditional result was False 2026-01-22 21:52:41.208402 | localhost | skipping: Conditional result was False 2026-01-22 21:52:41.222649 | 2026-01-22 21:52:41.222730 | LOOP [upload-logs : Upload compressed console log and json output] 2026-01-22 21:52:41.260130 | localhost | skipping: Conditional result was False 2026-01-22 21:52:41.260511 | 2026-01-22 21:52:41.263225 | localhost | skipping: Conditional result was False 2026-01-22 21:52:41.276501 | 2026-01-22 21:52:41.276686 | LOOP [upload-logs : Upload console log and json output]