2026-02-28 03:49:53.846654 | Job console starting 2026-02-28 03:49:53.855288 | Updating git repos 2026-02-28 03:49:53.896428 | Cloning repos into workspace 2026-02-28 03:49:53.964796 | Restoring repo states 2026-02-28 03:49:54.018293 | Merging changes 2026-02-28 03:49:54.624671 | Checking out repos 2026-02-28 03:49:55.163038 | Preparing playbooks 2026-02-28 03:49:56.531324 | Running Ansible setup 2026-02-28 03:50:00.026346 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main] 2026-02-28 03:50:00.655560 | 2026-02-28 03:50:00.655716 | PLAY [localhost] 2026-02-28 03:50:00.663912 | 2026-02-28 03:50:00.663985 | TASK [Gathering Facts] 2026-02-28 03:50:01.573116 | localhost | ok 2026-02-28 03:50:01.583346 | 2026-02-28 03:50:01.583455 | TASK [Setup log path fact] 2026-02-28 03:50:01.601757 | localhost | ok 2026-02-28 03:50:01.616031 | 2026-02-28 03:50:01.616097 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-28 03:50:01.645156 | localhost | ok 2026-02-28 03:50:01.652809 | 2026-02-28 03:50:01.652876 | TASK [emit-job-header : Print job information] 2026-02-28 03:50:01.691961 | # Job Information 2026-02-28 03:50:01.692122 | Ansible Version: 2.16.16 2026-02-28 03:50:01.692167 | Job: ansible-collection-kubernetes-molecule-aio-rockylinux-9 2026-02-28 03:50:01.692198 | Pipeline: check 2026-02-28 03:50:01.692228 | Executor: 0a8996d2b663 2026-02-28 03:50:01.692256 | Triggered by: https://github.com/vexxhost/ansible-collection-kubernetes/pull/228 2026-02-28 03:50:01.692287 | Event ID: 6fc3b350-1458-11f1-8c58-29f65cadad4c 2026-02-28 03:50:01.695948 | 2026-02-28 03:50:01.696035 | LOOP [emit-job-header : Print node information] 2026-02-28 03:50:01.782562 | localhost | ok: 2026-02-28 03:50:01.782783 | localhost | # Node Information 2026-02-28 03:50:01.782833 | localhost | Inventory Hostname: controller 2026-02-28 03:50:01.782874 | localhost | Hostname: np0000157460 2026-02-28 03:50:01.782910 | localhost | Username: zuul 2026-02-28 03:50:01.782948 | localhost | Distro: Rocky 9.7 2026-02-28 03:50:01.782984 | localhost | Provider: yul1 2026-02-28 03:50:01.783018 | localhost | Region: ca-ymq-1 2026-02-28 03:50:01.783052 | localhost | Label: rockylinux-9 2026-02-28 03:50:01.783084 | localhost | Product Name: OpenStack Nova 2026-02-28 03:50:01.783118 | localhost | Interface IP: 199.204.45.116 2026-02-28 03:50:01.792315 | 2026-02-28 03:50:01.792468 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-02-28 03:50:02.225266 | localhost -> localhost | changed 2026-02-28 03:50:02.233678 | 2026-02-28 03:50:02.233825 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-02-28 03:50:03.106991 | localhost -> localhost | changed 2026-02-28 03:50:03.114747 | 2026-02-28 03:50:03.114840 | PLAY [all] 2026-02-28 03:50:03.122253 | 2026-02-28 03:50:03.122317 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-28 03:50:03.360914 | controller -> localhost | ok 2026-02-28 03:50:03.368338 | 2026-02-28 03:50:03.368423 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-28 03:50:03.415571 | controller | ok 2026-02-28 03:50:03.429156 | controller | included: /var/lib/zuul/builds/7b417d7c457d420c922f54eb34613f3e/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-28 03:50:03.434288 | 2026-02-28 03:50:03.434351 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-28 03:50:04.288650 | controller -> localhost | Generating public/private rsa key pair. 2026-02-28 03:50:04.288811 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/7b417d7c457d420c922f54eb34613f3e/work/7b417d7c457d420c922f54eb34613f3e_id_rsa 2026-02-28 03:50:04.288841 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/7b417d7c457d420c922f54eb34613f3e/work/7b417d7c457d420c922f54eb34613f3e_id_rsa.pub 2026-02-28 03:50:04.288864 | controller -> localhost | The key fingerprint is: 2026-02-28 03:50:04.288885 | controller -> localhost | SHA256:hHh9QLBL/T56xHyLkEZOOQi6qL+hts5sf6hGG68j8vY zuul-build-sshkey 2026-02-28 03:50:04.288919 | controller -> localhost | The key's randomart image is: 2026-02-28 03:50:04.288941 | controller -> localhost | +---[RSA 3072]----+ 2026-02-28 03:50:04.288984 | controller -> localhost | | .oo | 2026-02-28 03:50:04.289007 | controller -> localhost | | .. = . | 2026-02-28 03:50:04.289027 | controller -> localhost | | ...=.+.. | 2026-02-28 03:50:04.289047 | controller -> localhost | | . o.o=o | 2026-02-28 03:50:04.289067 | controller -> localhost | | . . .+S=. | 2026-02-28 03:50:04.289087 | controller -> localhost | |.o. =.+ . | 2026-02-28 03:50:04.289107 | controller -> localhost | |o = . . ooo . | 2026-02-28 03:50:04.289126 | controller -> localhost | |*B.+ . .o.. | 2026-02-28 03:50:04.289149 | controller -> localhost | |O@X+E .. | 2026-02-28 03:50:04.289169 | controller -> localhost | +----[SHA256]-----+ 2026-02-28 03:50:04.289212 | controller -> localhost | ok: Runtime: 0:00:00.392786 2026-02-28 03:50:04.293706 | 2026-02-28 03:50:04.293768 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-28 03:50:04.323176 | controller | ok 2026-02-28 03:50:04.332757 | controller | included: /var/lib/zuul/builds/7b417d7c457d420c922f54eb34613f3e/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-28 03:50:04.340726 | 2026-02-28 03:50:04.340789 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-28 03:50:04.365654 | controller | skipping: Conditional result was False 2026-02-28 03:50:04.374553 | 2026-02-28 03:50:04.374639 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-28 03:50:04.913711 | controller | changed 2026-02-28 03:50:04.919273 | 2026-02-28 03:50:04.919354 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-28 03:50:05.171809 | controller | ok 2026-02-28 03:50:05.251688 | 2026-02-28 03:50:05.251876 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-28 03:50:06.204026 | controller | changed 2026-02-28 03:50:06.307983 | 2026-02-28 03:50:06.308107 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-28 03:50:07.235196 | controller | changed 2026-02-28 03:50:07.241749 | 2026-02-28 03:50:07.241863 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-28 03:50:07.260737 | controller | skipping: Conditional result was False 2026-02-28 03:50:07.272480 | 2026-02-28 03:50:07.272561 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-28 03:50:07.808367 | controller -> localhost | changed 2026-02-28 03:50:07.822079 | 2026-02-28 03:50:07.822162 | TASK [add-build-sshkey : Add back temp key] 2026-02-28 03:50:08.097173 | controller -> localhost | Identity added: /var/lib/zuul/builds/7b417d7c457d420c922f54eb34613f3e/work/7b417d7c457d420c922f54eb34613f3e_id_rsa (zuul-build-sshkey) 2026-02-28 03:50:08.097387 | controller -> localhost | ok: Runtime: 0:00:00.014098 2026-02-28 03:50:08.104224 | 2026-02-28 03:50:08.104286 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-28 03:50:08.502706 | controller | ok 2026-02-28 03:50:08.508637 | 2026-02-28 03:50:08.508724 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-28 03:50:08.550539 | controller | skipping: Conditional result was False 2026-02-28 03:50:08.565841 | 2026-02-28 03:50:08.566538 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-02-28 03:50:08.936019 | controller | ok 2026-02-28 03:50:08.957234 | 2026-02-28 03:50:08.957573 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-02-28 03:50:10.028331 | controller | Output suppressed because no_log was given 2026-02-28 03:50:10.036807 | 2026-02-28 03:50:10.036871 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-02-28 03:50:10.302079 | controller | ok: "logs" 2026-02-28 03:50:10.302354 | controller | ok: All items complete 2026-02-28 03:50:10.302404 | 2026-02-28 03:50:10.516500 | controller | ok: "artifacts" 2026-02-28 03:50:10.737587 | controller | ok: "docs" 2026-02-28 03:50:10.753383 | 2026-02-28 03:50:10.753520 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-02-28 03:50:11.013303 | controller | changed: "logs" 2026-02-28 03:50:11.305064 | controller | changed: "artifacts" 2026-02-28 03:50:11.475976 | controller | changed: "docs" 2026-02-28 03:50:11.490400 | 2026-02-28 03:50:11.490526 | PLAY RECAP 2026-02-28 03:50:11.490578 | controller | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0 2026-02-28 03:50:11.490607 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-02-28 03:50:11.490627 | 2026-02-28 03:50:11.616209 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main] 2026-02-28 03:50:11.640039 | PRE-RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main] 2026-02-28 03:50:12.209637 | 2026-02-28 03:50:12.209771 | PLAY [all] 2026-02-28 03:50:12.220551 | 2026-02-28 03:50:12.220623 | TASK [setup-uv : Extract archive] 2026-02-28 03:50:14.978261 | controller | changed 2026-02-28 03:50:15.061657 | 2026-02-28 03:50:15.061806 | TASK [setup-uv : Print version] 2026-02-28 03:50:15.088283 | [controller] Waiting on logger 2026-02-28 03:50:15.503085 | controller | ok: Runtime: 0:00:00.016581 2026-02-28 03:50:15.511916 | 2026-02-28 03:50:15.511972 | PLAY RECAP 2026-02-28 03:50:15.512023 | controller | ok: 2 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-02-28 03:50:15.512047 | 2026-02-28 03:50:15.659308 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main] 2026-02-28 03:50:15.662126 | RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main] 2026-02-28 03:50:16.340550 | 2026-02-28 03:50:16.340713 | PLAY [all] 2026-02-28 03:50:16.353525 | 2026-02-28 03:50:16.353659 | TASK [Copy inventory file for Zuul] 2026-02-28 03:50:17.662461 | controller | changed 2026-02-28 03:50:17.667725 | 2026-02-28 03:50:17.667799 | TASK [Switch "ansible_host" to private IP] 2026-02-28 03:50:18.016805 | controller | changed: 1 replacements made 2026-02-28 03:50:18.022262 | 2026-02-28 03:50:18.022331 | TASK [Run Molecule scenario] 2026-02-28 03:50:18.043597 | [controller] Waiting on logger 2026-02-28 03:50:25.163161 | [controller] Waiting on logger 2026-02-28 03:50:35.333843 | [controller] Waiting on logger 2026-02-28 03:50:45.509850 | [controller] Waiting on logger 2026-02-28 03:50:55.685967 | [controller] Waiting on logger 2026-02-28 03:51:05.861914 | [controller] Waiting on logger 2026-02-28 03:51:16.037989 | [controller] Waiting on logger 2026-02-28 03:51:25.199279 | [controller] Waiting on logger 2026-02-28 03:51:35.365946 | [controller] Waiting on logger 2026-02-28 03:51:45.541876 | [controller] Waiting on logger 2026-02-28 03:51:55.717809 | [controller] Waiting on logger 2026-02-28 03:52:05.894376 | [controller] Waiting on logger 2026-02-28 03:52:16.070182 | [controller] Waiting on logger 2026-02-28 03:52:25.222115 | [controller] Waiting on logger 2026-02-28 03:52:35.397903 | [controller] Waiting on logger 2026-02-28 03:52:45.574023 | [controller] Waiting on logger 2026-02-28 03:52:55.750069 | [controller] Waiting on logger 2026-02-28 03:53:05.929929 | [controller] Waiting on logger 2026-02-28 03:53:16.105892 | [controller] Waiting on logger 2026-02-28 03:53:25.253918 | [controller] Waiting on logger 2026-02-28 03:53:35.429872 | [controller] Waiting on logger 2026-02-28 03:53:45.606168 | [controller] Waiting on logger 2026-02-28 03:53:55.782130 | [controller] Waiting on logger 2026-02-28 03:54:05.958034 | [controller] Waiting on logger 2026-02-28 03:54:15.115273 | [controller] Waiting on logger 2026-02-28 03:54:25.285898 | [controller] Waiting on logger 2026-02-28 03:54:35.462116 | [controller] Waiting on logger 2026-02-28 03:54:45.638009 | [controller] Waiting on logger 2026-02-28 03:54:55.818020 | [controller] Waiting on logger 2026-02-28 03:55:05.989935 | [controller] Waiting on logger 2026-02-28 03:55:15.147291 | [controller] Waiting on logger 2026-02-28 03:55:18.508605 | controller | ok: Runtime: 0:04:59.963222 2026-02-28 03:55:18.524253 | 2026-02-28 03:55:18.524304 | PLAY RECAP 2026-02-28 03:55:18.524350 | controller | ok: 3 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-02-28 03:55:18.524370 | 2026-02-28 03:55:18.624504 | RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main] 2026-02-28 03:55:18.625891 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main] 2026-02-28 03:55:19.236324 | 2026-02-28 03:55:19.237107 | PLAY [all] 2026-02-28 03:55:19.248903 | 2026-02-28 03:55:19.249116 | TASK [fetch-output : Set log path for multiple nodes] 2026-02-28 03:55:19.295320 | controller | skipping: Conditional result was False 2026-02-28 03:55:19.302546 | 2026-02-28 03:55:19.302661 | TASK [fetch-output : Set log path for single node] 2026-02-28 03:55:19.345129 | controller | ok 2026-02-28 03:55:19.349536 | 2026-02-28 03:55:19.349607 | LOOP [fetch-output : Ensure local output dirs] 2026-02-28 03:55:19.717716 | controller -> localhost | ok: "/var/lib/zuul/builds/7b417d7c457d420c922f54eb34613f3e/work/logs" 2026-02-28 03:55:19.921979 | controller -> localhost | changed: "/var/lib/zuul/builds/7b417d7c457d420c922f54eb34613f3e/work/artifacts" 2026-02-28 03:55:20.136881 | controller -> localhost | changed: "/var/lib/zuul/builds/7b417d7c457d420c922f54eb34613f3e/work/docs" 2026-02-28 03:55:20.154813 | 2026-02-28 03:55:20.154977 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-02-28 03:55:20.894791 | controller | changed: .d..t...... ./ 2026-02-28 03:55:20.895112 | controller | changed: All items complete 2026-02-28 03:55:20.895176 | 2026-02-28 03:55:21.415579 | controller | changed: .d..t...... ./ 2026-02-28 03:55:21.938758 | controller | changed: .d..t...... ./ 2026-02-28 03:55:21.959609 | 2026-02-28 03:55:21.959771 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-02-28 03:55:22.375160 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007939 2026-02-28 03:55:22.616683 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.007671 2026-02-28 03:55:22.640288 | 2026-02-28 03:55:22.640454 | PLAY [all] 2026-02-28 03:55:22.646350 | 2026-02-28 03:55:22.646419 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2026-02-28 03:55:23.124225 | controller | changed 2026-02-28 03:55:23.132517 | 2026-02-28 03:55:23.132570 | PLAY RECAP 2026-02-28 03:55:23.132618 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2026-02-28 03:55:23.132639 | 2026-02-28 03:55:23.241806 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main] 2026-02-28 03:55:23.244877 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main] 2026-02-28 03:55:23.841340 | 2026-02-28 03:55:23.841499 | PLAY [localhost] 2026-02-28 03:55:23.851868 | 2026-02-28 03:55:23.851959 | TASK [Generate Zuul manifest] 2026-02-28 03:55:23.871359 | localhost | ok 2026-02-28 03:55:23.886862 | 2026-02-28 03:55:23.886956 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-02-28 03:55:24.216586 | localhost | changed 2026-02-28 03:55:24.227102 | 2026-02-28 03:55:24.227192 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-02-28 03:55:24.260448 | localhost | ok 2026-02-28 03:55:24.271858 | 2026-02-28 03:55:24.271935 | TASK [Upload logs] 2026-02-28 03:55:24.294859 | localhost | ok 2026-02-28 03:55:24.355804 | 2026-02-28 03:55:24.355961 | TASK [Set zuul-log-path fact] 2026-02-28 03:55:24.388516 | localhost | ok 2026-02-28 03:55:24.402493 | 2026-02-28 03:55:24.402561 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-28 03:55:24.436105 | localhost | ok 2026-02-28 03:55:24.444845 | 2026-02-28 03:55:24.444932 | TASK [upload-logs : Create log directories] 2026-02-28 03:55:24.824348 | localhost | changed 2026-02-28 03:55:24.830427 | 2026-02-28 03:55:24.830506 | TASK [upload-logs : Ensure logs are readable before uploading] 2026-02-28 03:55:25.217726 | localhost -> localhost | ok: Runtime: 0:00:00.005001 2026-02-28 03:55:25.224662 | 2026-02-28 03:55:25.224754 | TASK [upload-logs : Upload logs to log server] 2026-02-28 03:55:25.683660 | localhost | Output suppressed because no_log was given 2026-02-28 03:55:25.689789 | 2026-02-28 03:55:25.689906 | LOOP [upload-logs : Compress console log and json output] 2026-02-28 03:55:25.736383 | localhost | skipping: Conditional result was False 2026-02-28 03:55:25.743656 | localhost | skipping: Conditional result was False 2026-02-28 03:55:25.754913 | 2026-02-28 03:55:25.755058 | LOOP [upload-logs : Upload compressed console log and json output] 2026-02-28 03:55:25.800421 | localhost | skipping: Conditional result was False 2026-02-28 03:55:25.800883 | 2026-02-28 03:55:25.804185 | localhost | skipping: Conditional result was False 2026-02-28 03:55:25.819307 | 2026-02-28 03:55:25.819449 | LOOP [upload-logs : Upload console log and json output]