2026-05-19 11:49:40.869868 | Job console starting 2026-05-19 11:49:40.879882 | Updating git repos 2026-05-19 11:49:52.464057 | Cloning repos into workspace 2026-05-19 11:49:54.363851 | Restoring repo states 2026-05-19 11:49:54.382023 | Merging changes 2026-05-19 11:49:59.329718 | Checking out repos 2026-05-19 11:49:59.691261 | Preparing playbooks 2026-05-19 11:50:23.654005 | Running Ansible setup 2026-05-19 11:50:28.132386 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main] 2026-05-19 11:50:28.876822 | 2026-05-19 11:50:29.434785 | PLAY [localhost] 2026-05-19 11:50:29.449270 | 2026-05-19 11:50:29.449393 | TASK [Gathering Facts] 2026-05-19 11:50:31.115014 | localhost | ok 2026-05-19 11:50:31.124230 | 2026-05-19 11:50:31.124432 | TASK [Setup log path fact] 2026-05-19 11:50:31.147097 | localhost | ok 2026-05-19 11:50:31.160213 | 2026-05-19 11:50:31.160366 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-05-19 11:50:31.195025 | localhost | ok 2026-05-19 11:50:31.205587 | 2026-05-19 11:50:31.205759 | TASK [emit-job-header : Print job information] 2026-05-19 11:50:31.246443 | # Job Information 2026-05-19 11:50:31.246618 | Ansible Version: 2.16.18 2026-05-19 11:50:31.246651 | Job: atmosphere-molecule-aio-openvswitch 2026-05-19 11:50:31.246674 | Pipeline: check 2026-05-19 11:50:31.246694 | Executor: 2d72f0692154 2026-05-19 11:50:31.246715 | Triggered by: https://github.com/vexxhost/atmosphere/pull/3926 2026-05-19 11:50:31.246738 | Event ID: ba2824d0-5378-11f1-8a88-ff3737694846 2026-05-19 11:50:31.249604 | 2026-05-19 11:50:31.249673 | LOOP [emit-job-header : Print node information] 2026-05-19 11:50:31.382140 | localhost | ok: 2026-05-19 11:50:31.382361 | localhost | # Node Information 2026-05-19 11:50:31.382401 | localhost | Inventory Hostname: instance 2026-05-19 11:50:31.382431 | localhost | Hostname: np0000174709 2026-05-19 11:50:31.382459 | localhost | Username: zuul 2026-05-19 11:50:31.382490 | localhost | Distro: Ubuntu 22.04 2026-05-19 11:50:31.382517 | localhost | Provider: yul1 2026-05-19 11:50:31.382547 | localhost | Region: ca-ymq-1 2026-05-19 11:50:31.382577 | localhost | Label: ubuntu-jammy-16 2026-05-19 11:50:31.382603 | localhost | Product Name: OpenStack Nova 2026-05-19 11:50:31.382628 | localhost | Interface IP: 199.19.213.75 2026-05-19 11:50:31.394876 | 2026-05-19 11:50:31.395021 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-05-19 11:50:31.855224 | localhost -> localhost | changed 2026-05-19 11:50:31.864110 | 2026-05-19 11:50:31.864208 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-05-19 11:50:33.369933 | localhost -> localhost | changed 2026-05-19 11:50:33.381330 | 2026-05-19 11:50:33.381415 | PLAY [all] 2026-05-19 11:50:33.389439 | 2026-05-19 11:50:33.389530 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-05-19 11:50:33.701793 | instance -> localhost | ok 2026-05-19 11:50:33.710574 | 2026-05-19 11:50:33.710665 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-05-19 11:50:33.747292 | instance | ok 2026-05-19 11:50:33.895146 | instance | included: /var/lib/zuul/builds/5deb0739b21e4323a2ac43ea72689b9e/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-05-19 11:50:33.900853 | 2026-05-19 11:50:33.900919 | TASK [add-build-sshkey : Create Temp SSH key] 2026-05-19 11:50:34.727220 | instance -> localhost | Generating public/private rsa key pair. 2026-05-19 11:50:34.783056 | instance -> localhost | Your identification has been saved in /var/lib/zuul/builds/5deb0739b21e4323a2ac43ea72689b9e/work/5deb0739b21e4323a2ac43ea72689b9e_id_rsa 2026-05-19 11:50:34.783162 | instance -> localhost | Your public key has been saved in /var/lib/zuul/builds/5deb0739b21e4323a2ac43ea72689b9e/work/5deb0739b21e4323a2ac43ea72689b9e_id_rsa.pub 2026-05-19 11:50:34.783220 | instance -> localhost | The key fingerprint is: 2026-05-19 11:50:34.783269 | instance -> localhost | SHA256:668ZFus96bsmshV6AghZlm4Uo84yPRbky6jLLgRAoHA zuul-build-sshkey 2026-05-19 11:50:34.783339 | instance -> localhost | The key's randomart image is: 2026-05-19 11:50:34.783405 | instance -> localhost | +---[RSA 3072]----+ 2026-05-19 11:50:34.783476 | instance -> localhost | |=.Eo | 2026-05-19 11:50:34.783525 | instance -> localhost | |+Oo. | 2026-05-19 11:50:34.783579 | instance -> localhost | |*oo | 2026-05-19 11:50:34.783626 | instance -> localhost | |+=o+ | 2026-05-19 11:50:34.783670 | instance -> localhost | |=+B . S | 2026-05-19 11:50:34.783713 | instance -> localhost | |o+ . . . = | 2026-05-19 11:50:34.783756 | instance -> localhost | |o o B . | 2026-05-19 11:50:34.783798 | instance -> localhost | |o. .B.++ | 2026-05-19 11:50:34.783847 | instance -> localhost | |+o .o=**+ | 2026-05-19 11:50:34.783891 | instance -> localhost | +----[SHA256]-----+ 2026-05-19 11:50:34.783996 | instance -> localhost | ok: Runtime: 0:00:00.366597 2026-05-19 11:50:34.794777 | 2026-05-19 11:50:34.794860 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-05-19 11:50:34.830751 | instance | ok 2026-05-19 11:50:34.843181 | instance | included: /var/lib/zuul/builds/5deb0739b21e4323a2ac43ea72689b9e/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-05-19 11:50:34.850432 | 2026-05-19 11:50:34.850493 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-05-19 11:50:34.875962 | instance | skipping: Conditional result was False 2026-05-19 11:50:34.887547 | 2026-05-19 11:50:34.887612 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-05-19 11:50:35.379541 | instance | changed 2026-05-19 11:50:35.390726 | 2026-05-19 11:50:35.390814 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-05-19 11:50:35.590131 | instance | ok 2026-05-19 11:50:35.780390 | 2026-05-19 11:50:35.780513 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-05-19 11:50:36.308750 | instance | changed 2026-05-19 11:50:36.434670 | 2026-05-19 11:50:36.434813 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-05-19 11:50:36.916530 | instance | changed 2026-05-19 11:50:36.957476 | 2026-05-19 11:50:36.957677 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-05-19 11:50:36.983046 | instance | skipping: Conditional result was False 2026-05-19 11:50:36.992406 | 2026-05-19 11:50:36.992588 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-05-19 11:50:37.618337 | instance -> localhost | changed 2026-05-19 11:50:37.637646 | 2026-05-19 11:50:37.637765 | TASK [add-build-sshkey : Add back temp key] 2026-05-19 11:50:37.986048 | instance -> localhost | Identity added: /var/lib/zuul/builds/5deb0739b21e4323a2ac43ea72689b9e/work/5deb0739b21e4323a2ac43ea72689b9e_id_rsa (zuul-build-sshkey) 2026-05-19 11:50:37.986288 | instance -> localhost | ok: Runtime: 0:00:00.011315 2026-05-19 11:50:37.992007 | 2026-05-19 11:50:37.992086 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-05-19 11:50:38.285267 | instance | ok 2026-05-19 11:50:38.290136 | 2026-05-19 11:50:38.290202 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-05-19 11:50:38.325786 | instance | skipping: Conditional result was False 2026-05-19 11:50:38.338191 | 2026-05-19 11:50:38.338281 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-05-19 11:50:38.648722 | instance | ok 2026-05-19 11:50:38.656893 | 2026-05-19 11:50:38.657021 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-05-19 11:50:40.561647 | instance | Output suppressed because no_log was given 2026-05-19 11:50:40.572593 | 2026-05-19 11:50:40.572665 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-05-19 11:50:40.769244 | instance | ok: "logs" 2026-05-19 11:50:40.877197 | instance | ok: All items complete 2026-05-19 11:50:40.877412 | 2026-05-19 11:50:40.921281 | instance | ok: "artifacts" 2026-05-19 11:50:41.072169 | instance | ok: "docs" 2026-05-19 11:50:41.083040 | 2026-05-19 11:50:41.083212 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-05-19 11:50:41.317049 | instance | changed: "logs" 2026-05-19 11:50:41.466127 | instance | changed: "artifacts" 2026-05-19 11:50:41.631666 | instance | changed: "docs" 2026-05-19 11:50:41.653021 | 2026-05-19 11:50:41.653169 | PLAY RECAP 2026-05-19 11:50:41.653238 | instance | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0 2026-05-19 11:50:41.653278 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-05-19 11:50:41.653309 | 2026-05-19 11:50:41.840429 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main] 2026-05-19 11:50:41.852093 | PRE-RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main] 2026-05-19 11:50:42.567536 | 2026-05-19 11:50:42.567971 | PLAY [all] 2026-05-19 11:50:42.579765 | 2026-05-19 11:50:42.579840 | TASK [setup-uv : Extract archive] 2026-05-19 11:50:45.440893 | instance | changed 2026-05-19 11:50:45.453260 | 2026-05-19 11:50:45.453977 | TASK [setup-uv : Print version] 2026-05-19 11:50:45.811033 | instance | uv 0.8.13 2026-05-19 11:50:46.012354 | instance | ok: Runtime: 0:00:00.010932 2026-05-19 11:50:46.019702 | 2026-05-19 11:50:46.019749 | PLAY RECAP 2026-05-19 11:50:46.019797 | instance | ok: 2 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-05-19 11:50:46.019821 | 2026-05-19 11:50:46.166822 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main] 2026-05-19 11:50:46.173891 | PRE-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@stable/2023.1] 2026-05-19 11:50:46.826656 | 2026-05-19 11:50:46.826826 | PLAY [all] 2026-05-19 11:50:46.839664 | 2026-05-19 11:50:46.839778 | TASK [Install "jq" for log collection] 2026-05-19 11:51:21.436645 | instance | changed 2026-05-19 11:51:21.439586 | 2026-05-19 11:51:21.439651 | PLAY RECAP 2026-05-19 11:51:21.439710 | instance | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-05-19 11:51:21.439819 | 2026-05-19 11:51:21.584061 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@stable/2023.1] 2026-05-19 11:51:22.127309 | RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main] 2026-05-19 11:51:22.721288 | 2026-05-19 11:51:22.721440 | PLAY [all] 2026-05-19 11:51:22.733194 | 2026-05-19 11:51:22.733329 | TASK [Copy inventory file for Zuul] 2026-05-19 11:51:23.573185 | instance | changed 2026-05-19 11:51:23.578802 | 2026-05-19 11:51:23.578888 | TASK [Switch "ansible_host" to private IP] 2026-05-19 11:51:23.909737 | instance | changed: 1 replacements made 2026-05-19 11:51:23.916335 | 2026-05-19 11:51:23.916431 | TASK [Run Molecule scenario] 2026-05-19 11:51:24.310144 | instance | Using CPython 3.10.12 interpreter at: /usr/bin/python3 2026-05-19 11:51:24.310282 | instance | Creating virtual environment at: .venv 2026-05-19 11:51:24.333132 | instance | Building atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere 2026-05-19 11:51:24.360923 | instance | Downloading kubernetes (1.9MiB) 2026-05-19 11:51:24.361265 | instance | Downloading pygments (1.2MiB) 2026-05-19 11:51:24.366855 | instance | Downloading openstacksdk (1.7MiB) 2026-05-19 11:51:24.367064 | instance | Downloading rjsonnet (1.2MiB) 2026-05-19 11:51:24.374097 | instance | Downloading cryptography (4.2MiB) 2026-05-19 11:51:24.385553 | instance | Downloading ansible-core (2.1MiB) 2026-05-19 11:51:24.405286 | instance | Downloading netaddr (2.2MiB) 2026-05-19 11:51:24.418545 | instance | Downloading setuptools (1.1MiB) 2026-05-19 11:51:24.663760 | instance | Downloading rjsonnet 2026-05-19 11:51:24.672063 | instance | Building pyperclip==1.9.0 2026-05-19 11:51:24.836467 | instance | Downloading netaddr 2026-05-19 11:51:24.848670 | instance | Downloading pygments 2026-05-19 11:51:24.859387 | instance | Downloading cryptography 2026-05-19 11:51:24.900235 | instance | Downloading setuptools 2026-05-19 11:51:24.962728 | instance | Downloading kubernetes 2026-05-19 11:51:24.999215 | instance | Downloading ansible-core 2026-05-19 11:51:25.038824 | instance | Downloading openstacksdk 2026-05-19 11:51:25.391520 | instance | Built pyperclip==1.9.0 2026-05-19 11:51:25.586642 | instance | Built atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere 2026-05-19 11:51:25.627246 | instance | Installed 79 packages in 38ms 2026-05-19 11:51:26.287644 | instance | WARNING Molecule scenarios should migrate to 'extensions/molecule' 2026-05-19 11:51:26.883404 | instance | INFO [aio > discovery] scenario test matrix: dependency, cleanup, destroy, syntax, create, prepare, converge, idempotence, side_effect, verify, cleanup, destroy 2026-05-19 11:51:26.883517 | instance | INFO [aio > prerun] Performing prerun with role_name_check=0... 2026-05-19 11:51:35.905094 | instance | WARNING Retrying execution failure 1 of: ansible-galaxy collection install -vvv ansible.posix:1.6.0 2026-05-19 11:51:35.905382 | instance | ERROR Command ansible-galaxy collection install -vvv ansible.posix:1.6.0, returned 1 code: 2026-05-19 11:51:35.905429 | instance | Starting galaxy collection install process 2026-05-19 11:51:35.905440 | instance | Process install dependency map 2026-05-19 11:51:35.905450 | instance | 2026-05-19 11:51:35.905459 | instance | ansible-galaxy 2026-05-19 11:51:35.905468 | instance | config file = None 2026-05-19 11:51:35.905477 | instance | configured module search path = 2026-05-19 11:51:35.905487 | instance | ansible python module location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/ansible 2026-05-19 11:51:35.905498 | instance | ansible collection location = /home/zuul/.ansible/collections:/usr/share/ansible/collections:/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/dist-packages:/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3/dist-packages:/home/zuul/src/github.com/vexxhost/atmosphere/.venv/local/lib/python3.10/dist-packages:/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages 2026-05-19 11:51:35.905527 | instance | executable location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/ansible-galaxy 2026-05-19 11:51:35.905536 | instance | python version = 3.10.12 (main, Mar 3 2026, 11:56:32) (/home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/python) 2026-05-19 11:51:35.905545 | instance | jinja version = 3.1.6 2026-05-19 11:51:35.905554 | instance | libyaml = True 2026-05-19 11:51:35.905563 | instance | No config file found; using defaults 2026-05-19 11:51:35.905572 | instance | : Collection ansible.netcommon does not support Ansible version 2026-05-19 11:51:35.905581 | instance | 2.17.12 2026-05-19 11:51:35.905590 | instance | Found installed collection ansible.netcommon:1.2.0 at '/home/zuul/.ansible/collections/ansible_collections/ansible/netcommon' 2026-05-19 11:51:35.905600 | instance | Opened /home/zuul/.ansible/galaxy_token 2026-05-19 11:51:35.905608 | instance | : Skipping Galaxy server https://galaxy.ansible.com/api/. Got an 2026-05-19 11:51:35.905618 | instance | unexpected error when getting available versions of collection ansible.posix: 2026-05-19 11:51:35.905627 | instance | Unknown error when attempting to call Galaxy at 2026-05-19 11:51:35.905636 | instance | 'https://galaxy.ansible.com/api/v3/collections/ansible/posix/': . 2026-05-19 11:51:35.905705 | instance | ERROR! Unknown error when attempting to call Galaxy at 'https://galaxy.ansible.com/api/v3/collections/ansible/posix/': . 2026-05-19 11:51:35.905715 | instance | 2026-05-19 11:51:35.905889 | instance | Traceback (most recent call last): 2026-05-19 11:51:35.906207 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/molecule", line 10, in 2026-05-19 11:51:35.907070 | instance | sys.exit(main()) 2026-05-19 11:51:35.907231 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 1442, in __call__ 2026-05-19 11:51:35.907583 | instance | return self.main(*args, **kwargs) 2026-05-19 11:51:35.907730 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 1363, in main 2026-05-19 11:51:35.908058 | instance | rv = self.invoke(ctx) 2026-05-19 11:51:35.908182 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 1830, in invoke 2026-05-19 11:51:35.908563 | instance | return _process_result(sub_ctx.command.invoke(sub_ctx)) 2026-05-19 11:51:35.908662 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 1226, in invoke 2026-05-19 11:51:35.908988 | instance | return ctx.invoke(self.callback, **ctx.params) 2026-05-19 11:51:35.909094 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 794, in invoke 2026-05-19 11:51:35.909412 | instance | return callback(*args, **kwargs) 2026-05-19 11:51:35.909564 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/molecule/click_cfg.py", line 583, in wrapper 2026-05-19 11:51:35.909832 | instance | return func(*args, **kwargs) 2026-05-19 11:51:35.909936 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/decorators.py", line 34, in new_func 2026-05-19 11:51:35.910096 | instance | return f(get_current_context(), *args, **kwargs) 2026-05-19 11:51:35.910237 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/molecule/click_cfg.py", line 418, in wrapper 2026-05-19 11:51:35.910457 | instance | return func(ctx) 2026-05-19 11:51:35.910563 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/molecule/command/test.py", line 81, in test 2026-05-19 11:51:35.910754 | instance | base.execute_cmdline_scenarios(scenario_name, args, command_args, ansible_args, exclude) 2026-05-19 11:51:35.910873 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/molecule/command/base.py", line 169, in execute_cmdline_scenarios 2026-05-19 11:51:35.911089 | instance | _run_scenarios(scenarios, command_args, default_config) 2026-05-19 11:51:35.911213 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/molecule/command/base.py", line 240, in _run_scenarios 2026-05-19 11:51:35.911391 | instance | scenario.config.runtime.prepare_environment( 2026-05-19 11:51:35.911520 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/ansible_compat/runtime.py", line 694, in prepare_environment 2026-05-19 11:51:35.911766 | instance | self.install_collection( 2026-05-19 11:51:35.911900 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/ansible_compat/runtime.py", line 552, in install_collection 2026-05-19 11:51:35.912114 | instance | raise InvalidPrerequisiteError(msg) 2026-05-19 11:51:35.913033 | instance | ansible_compat.errors.InvalidPrerequisiteError: Command ansible-galaxy collection install -vvv ansible.posix:1.6.0, returned 1 code: 2026-05-19 11:51:35.913044 | instance | Starting galaxy collection install process 2026-05-19 11:51:35.913053 | instance | Process install dependency map 2026-05-19 11:51:35.913074 | instance | 2026-05-19 11:51:35.913084 | instance | ansible-galaxy [core 2.17.12] 2026-05-19 11:51:35.913092 | instance | config file = None 2026-05-19 11:51:35.913101 | instance | configured module search path = ['/home/zuul/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules'] 2026-05-19 11:51:35.913111 | instance | ansible python module location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/ansible 2026-05-19 11:51:35.913121 | instance | ansible collection location = /home/zuul/.ansible/collections:/usr/share/ansible/collections:/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/dist-packages:/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3/dist-packages:/home/zuul/src/github.com/vexxhost/atmosphere/.venv/local/lib/python3.10/dist-packages:/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages 2026-05-19 11:51:35.913130 | instance | executable location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/ansible-galaxy 2026-05-19 11:51:35.913140 | instance | python version = 3.10.12 (main, Mar 3 2026, 11:56:32) [GCC 11.4.0] (/home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/python) 2026-05-19 11:51:35.913148 | instance | jinja version = 3.1.6 2026-05-19 11:51:35.913157 | instance | libyaml = True 2026-05-19 11:51:35.913166 | instance | No config file found; using defaults 2026-05-19 11:51:35.913175 | instance | [WARNING]: Collection ansible.netcommon does not support Ansible version 2026-05-19 11:51:35.913183 | instance | 2.17.12 2026-05-19 11:51:35.913192 | instance | Found installed collection ansible.netcommon:1.2.0 at '/home/zuul/.ansible/collections/ansible_collections/ansible/netcommon' 2026-05-19 11:51:35.913201 | instance | Opened /home/zuul/.ansible/galaxy_token 2026-05-19 11:51:35.913210 | instance | [WARNING]: Skipping Galaxy server https://galaxy.ansible.com/api/. Got an 2026-05-19 11:51:35.913219 | instance | unexpected error when getting available versions of collection ansible.posix: 2026-05-19 11:51:35.913228 | instance | Unknown error when attempting to call Galaxy at 2026-05-19 11:51:35.913236 | instance | 'https://galaxy.ansible.com/api/v3/collections/ansible/posix/': . 2026-05-19 11:51:35.913263 | instance | ERROR! Unknown error when attempting to call Galaxy at 'https://galaxy.ansible.com/api/v3/collections/ansible/posix/': . 2026-05-19 11:51:35.913340 | instance | 2026-05-19 11:51:36.345534 | instance | ERROR 2026-05-19 11:51:36.345780 | instance | { 2026-05-19 11:51:36.345821 | instance | "delta": "0:00:11.804138", 2026-05-19 11:51:36.345850 | instance | "end": "2026-05-19 11:51:36.044595", 2026-05-19 11:51:36.345876 | instance | "msg": "non-zero return code", 2026-05-19 11:51:36.345900 | instance | "rc": 1, 2026-05-19 11:51:36.345929 | instance | "start": "2026-05-19 11:51:24.240457" 2026-05-19 11:51:36.345955 | instance | } failure 2026-05-19 11:51:36.349598 | 2026-05-19 11:51:36.349664 | PLAY RECAP 2026-05-19 11:51:36.349720 | instance | ok: 2 changed: 2 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0 2026-05-19 11:51:36.349749 | 2026-05-19 11:51:36.535614 | RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main] 2026-05-19 11:51:36.546387 | POST-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@stable/2023.1] 2026-05-19 11:51:37.172667 | 2026-05-19 11:51:37.172814 | PLAY [all] 2026-05-19 11:51:37.187999 | 2026-05-19 11:51:37.188106 | TASK [gather-host-logs : creating directory for system status] 2026-05-19 11:51:37.538645 | instance | changed 2026-05-19 11:51:37.550446 | 2026-05-19 11:51:37.550557 | TASK [gather-host-logs : Get logs for each host] 2026-05-19 11:51:37.917364 | instance | + systemd-cgls --full --all --no-pager 2026-05-19 11:51:37.929614 | instance | + ip addr 2026-05-19 11:51:37.931142 | instance | + ip route 2026-05-19 11:51:37.932317 | instance | + lsblk 2026-05-19 11:51:37.934489 | instance | + mount 2026-05-19 11:51:37.935788 | instance | + docker images 2026-05-19 11:51:37.936147 | instance | /bin/bash: line 7: docker: command not found 2026-05-19 11:51:37.936332 | instance | + brctl show 2026-05-19 11:51:37.936653 | instance | /bin/bash: line 8: brctl: command not found 2026-05-19 11:51:37.936864 | instance | + ps aux --sort=-%mem 2026-05-19 11:51:37.948783 | instance | + dpkg -l 2026-05-19 11:51:37.955708 | instance | + CONTAINERS=($(docker ps -a --format '{{ .Names }}' --filter label=zuul)) 2026-05-19 11:51:37.956349 | instance | ++ docker ps -a --format '{{ .Names }}' --filter label=zuul 2026-05-19 11:51:37.956482 | instance | /bin/bash: line 11: docker: command not found 2026-05-19 11:51:37.956925 | instance | + '[' '!' -z '' ']' 2026-05-19 11:51:38.090167 | instance | ok: Runtime: 0:00:00.045635 2026-05-19 11:51:38.097663 | 2026-05-19 11:51:38.097731 | TASK [gather-host-logs : Downloads logs to executor] 2026-05-19 11:51:38.761949 | instance | changed: 2026-05-19 11:51:38.762189 | instance | created directory /var/lib/zuul/builds/5deb0739b21e4323a2ac43ea72689b9e/work/logs/instance 2026-05-19 11:51:38.762236 | instance | cd+++++++++ system/ 2026-05-19 11:51:38.762267 | instance | >f+++++++++ system/brctl-show.txt 2026-05-19 11:51:38.762296 | instance | >f+++++++++ system/docker-images.txt 2026-05-19 11:51:38.762323 | instance | >f+++++++++ system/ip-addr.txt 2026-05-19 11:51:38.762354 | instance | >f+++++++++ system/ip-route.txt 2026-05-19 11:51:38.762383 | instance | >f+++++++++ system/lsblk.txt 2026-05-19 11:51:38.762410 | instance | >f+++++++++ system/mount.txt 2026-05-19 11:51:38.762440 | instance | >f+++++++++ system/packages.txt 2026-05-19 11:51:38.762467 | instance | >f+++++++++ system/ps.txt 2026-05-19 11:51:38.762494 | instance | >f+++++++++ system/systemd-cgls.txt 2026-05-19 11:51:38.772379 | 2026-05-19 11:51:38.772449 | LOOP [helm-release-status : creating directory for helm release status] 2026-05-19 11:51:38.995520 | instance | changed: "values" 2026-05-19 11:51:39.165334 | instance | changed: "releases" 2026-05-19 11:51:39.177508 | 2026-05-19 11:51:39.177737 | TASK [helm-release-status : Gather get release status for helm charts] 2026-05-19 11:51:39.436368 | instance | /bin/bash: line 3: kubectl: command not found 2026-05-19 11:51:39.759383 | instance | ok: Runtime: 0:00:00.007435 2026-05-19 11:51:39.765522 | 2026-05-19 11:51:39.765592 | TASK [helm-release-status : Downloads logs to executor] 2026-05-19 11:51:40.257545 | instance | changed: 2026-05-19 11:51:40.257791 | instance | cd+++++++++ helm/ 2026-05-19 11:51:40.257859 | instance | cd+++++++++ helm/releases/ 2026-05-19 11:51:40.257925 | instance | cd+++++++++ helm/values/ 2026-05-19 11:51:40.268674 | 2026-05-19 11:51:40.268737 | TASK [describe-kubernetes-objects : creating directory for cluster scoped objects] 2026-05-19 11:51:40.475789 | instance | changed 2026-05-19 11:51:40.484008 | 2026-05-19 11:51:40.484083 | TASK [describe-kubernetes-objects : Gathering descriptions for cluster scoped objects] 2026-05-19 11:51:40.702766 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value 2026-05-19 11:51:40.703088 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value 2026-05-19 11:51:40.708437 | instance | environment: line 1: kubectl: command not found 2026-05-19 11:51:40.710187 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value 2026-05-19 11:51:40.710828 | instance | environment: line 1: kubectl: command not found 2026-05-19 11:51:40.712814 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value 2026-05-19 11:51:40.714910 | instance | environment: line 1: kubectl: command not found 2026-05-19 11:51:40.715870 | instance | environment: line 1: kubectl: command not found 2026-05-19 11:51:40.716612 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value 2026-05-19 11:51:40.716911 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value 2026-05-19 11:51:40.720096 | instance | environment: line 1: kubectl: command not found 2026-05-19 11:51:40.721163 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value 2026-05-19 11:51:41.022301 | instance | ok: Runtime: 0:00:00.029729 2026-05-19 11:51:41.030389 | 2026-05-19 11:51:41.030596 | TASK [describe-kubernetes-objects : creating directory for namespace scoped objects] 2026-05-19 11:51:41.226959 | instance | changed 2026-05-19 11:51:41.232750 | 2026-05-19 11:51:41.232891 | TASK [describe-kubernetes-objects : Gathering descriptions for namespace scoped objects] 2026-05-19 11:51:41.455614 | instance | environment: line 5: kubectl: command not found 2026-05-19 11:51:41.456630 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value 2026-05-19 11:51:41.456906 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value 2026-05-19 11:51:41.457425 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value 2026-05-19 11:51:41.772698 | instance | ok: Runtime: 0:00:00.010637 2026-05-19 11:51:41.780471 | 2026-05-19 11:51:41.780563 | TASK [describe-kubernetes-objects : Downloads logs to executor] 2026-05-19 11:51:42.276031 | instance | changed: 2026-05-19 11:51:42.276217 | instance | cd+++++++++ objects/ 2026-05-19 11:51:42.276245 | instance | cd+++++++++ objects/cluster/ 2026-05-19 11:51:42.276268 | instance | cd+++++++++ objects/namespaced/ 2026-05-19 11:51:42.285271 | 2026-05-19 11:51:42.285335 | TASK [gather-pod-logs : creating directory for pod logs] 2026-05-19 11:51:42.491669 | instance | changed 2026-05-19 11:51:42.496940 | 2026-05-19 11:51:42.497024 | TASK [gather-pod-logs : creating directory for failed pod logs] 2026-05-19 11:51:42.704819 | instance | changed 2026-05-19 11:51:42.709834 | 2026-05-19 11:51:42.709906 | TASK [gather-pod-logs : retrieve all kubernetes logs, current and previous (if they exist)] 2026-05-19 11:51:42.924614 | instance | environment: line 3: kubectl: command not found 2026-05-19 11:51:43.246087 | instance | ok: Runtime: 0:00:00.009838 2026-05-19 11:51:43.252673 | 2026-05-19 11:51:43.252744 | TASK [gather-pod-logs : Downloads pod logs to executor] 2026-05-19 11:51:43.765370 | instance | changed: 2026-05-19 11:51:43.765600 | instance | cd+++++++++ pod-logs/ 2026-05-19 11:51:43.765638 | instance | cd+++++++++ pod-logs/failed-pods/ 2026-05-19 11:51:43.776985 | 2026-05-19 11:51:43.777049 | TASK [gather-prom-metrics : creating directory for helm release descriptions] 2026-05-19 11:51:43.983927 | instance | changed 2026-05-19 11:51:43.988731 | 2026-05-19 11:51:43.988794 | TASK [gather-prom-metrics : Get metrics from exporter services in all namespaces] 2026-05-19 11:51:44.194848 | instance | /bin/bash: line 2: kubectl: command not found 2026-05-19 11:51:44.529271 | instance | ok: Runtime: 0:00:00.037306 2026-05-19 11:51:44.534751 | 2026-05-19 11:51:44.534821 | TASK [gather-prom-metrics : Get ceph metrics from ceph-mgr] 2026-05-19 11:51:44.733818 | instance | /bin/bash: line 2: kubectl: command not found 2026-05-19 11:51:44.769162 | instance | ceph-mgr endpoints: 2026-05-19 11:51:45.071670 | instance | ok: Runtime: 0:00:00.042450 2026-05-19 11:51:45.079340 | 2026-05-19 11:51:45.079544 | TASK [gather-prom-metrics : Get metrics from fluentd pods] 2026-05-19 11:51:45.338602 | instance | /bin/bash: line 4: kubectl: command not found 2026-05-19 11:51:45.617292 | instance | ok: Runtime: 0:00:00.033110 2026-05-19 11:51:45.624130 | 2026-05-19 11:51:45.624218 | TASK [gather-prom-metrics : Downloads logs to executor] 2026-05-19 11:51:46.116119 | instance | changed: cd+++++++++ prometheus/ 2026-05-19 11:51:46.125446 | 2026-05-19 11:51:46.125509 | TASK [gather-selenium-data : creating directory for helm release descriptions] 2026-05-19 11:51:46.325042 | instance | changed 2026-05-19 11:51:46.330172 | 2026-05-19 11:51:46.330252 | TASK [gather-selenium-data : Get selenium data] 2026-05-19 11:51:46.536802 | instance | + cp '/tmp/artifacts/*' /tmp/logs/selenium/. 2026-05-19 11:51:46.538623 | instance | cp: cannot stat '/tmp/artifacts/*': No such file or directory 2026-05-19 11:51:46.867225 | instance | ERROR 2026-05-19 11:51:46.867580 | instance | { 2026-05-19 11:51:46.867630 | instance | "delta": "0:00:00.007201", 2026-05-19 11:51:46.867660 | instance | "end": "2026-05-19 11:51:46.539199", 2026-05-19 11:51:46.867687 | instance | "msg": "non-zero return code", 2026-05-19 11:51:46.867712 | instance | "rc": 1, 2026-05-19 11:51:46.867737 | instance | "start": "2026-05-19 11:51:46.531998" 2026-05-19 11:51:46.867762 | instance | } 2026-05-19 11:51:46.867793 | instance | ERROR: Ignoring Errors 2026-05-19 11:51:46.874375 | 2026-05-19 11:51:46.874443 | TASK [gather-selenium-data : Downloads logs to executor] 2026-05-19 11:51:47.387038 | instance | changed: cd+++++++++ selenium/ 2026-05-19 11:51:47.393399 | 2026-05-19 11:51:47.393466 | PLAY RECAP 2026-05-19 11:51:47.393513 | instance | ok: 23 changed: 23 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 1 2026-05-19 11:51:47.393535 | 2026-05-19 11:51:47.571851 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@stable/2023.1] 2026-05-19 11:51:47.585211 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main] 2026-05-19 11:51:48.226664 | 2026-05-19 11:51:48.226818 | PLAY [all] 2026-05-19 11:51:48.238842 | 2026-05-19 11:51:48.238920 | TASK [fetch-output : Set log path for multiple nodes] 2026-05-19 11:51:48.284658 | instance | skipping: Conditional result was False 2026-05-19 11:51:48.295787 | 2026-05-19 11:51:48.295874 | TASK [fetch-output : Set log path for single node] 2026-05-19 11:51:48.339001 | instance | ok 2026-05-19 11:51:48.346365 | 2026-05-19 11:51:48.346442 | LOOP [fetch-output : Ensure local output dirs] 2026-05-19 11:51:48.755492 | instance -> localhost | ok: "/var/lib/zuul/builds/5deb0739b21e4323a2ac43ea72689b9e/work/logs" 2026-05-19 11:51:48.977341 | instance -> localhost | changed: "/var/lib/zuul/builds/5deb0739b21e4323a2ac43ea72689b9e/work/artifacts" 2026-05-19 11:51:49.187551 | instance -> localhost | changed: "/var/lib/zuul/builds/5deb0739b21e4323a2ac43ea72689b9e/work/docs" 2026-05-19 11:51:49.205704 | 2026-05-19 11:51:49.205849 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-05-19 11:51:49.852441 | instance | changed: .d..t...... ./ 2026-05-19 11:51:49.852666 | instance | changed: All items complete 2026-05-19 11:51:49.852695 | 2026-05-19 11:51:50.307475 | instance | changed: .d..t...... ./ 2026-05-19 11:51:50.759536 | instance | changed: .d..t...... ./ 2026-05-19 11:51:50.789476 | 2026-05-19 11:51:50.789617 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-05-19 11:51:51.222144 | instance -> localhost | ok: Item: artifacts Runtime: 0:00:00.008152 2026-05-19 11:51:51.446616 | instance -> localhost | ok: Item: docs Runtime: 0:00:00.008870 2026-05-19 11:51:51.463961 | 2026-05-19 11:51:51.464120 | PLAY [all] 2026-05-19 11:51:51.470419 | 2026-05-19 11:51:51.470485 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2026-05-19 11:51:51.900522 | instance | changed 2026-05-19 11:51:51.906681 | 2026-05-19 11:51:51.906735 | PLAY RECAP 2026-05-19 11:51:51.906780 | instance | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2026-05-19 11:51:51.906804 | 2026-05-19 11:51:52.052381 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main] 2026-05-19 11:51:52.066124 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main] 2026-05-19 11:51:52.696507 | 2026-05-19 11:51:52.696658 | PLAY [localhost] 2026-05-19 11:51:52.706690 | 2026-05-19 11:51:52.706762 | TASK [Generate Zuul manifest] 2026-05-19 11:51:52.729744 | localhost | ok 2026-05-19 11:51:52.746037 | 2026-05-19 11:51:52.746121 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-05-19 11:51:53.122880 | localhost | changed 2026-05-19 11:51:53.136427 | 2026-05-19 11:51:53.136501 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-05-19 11:51:53.169376 | localhost | ok 2026-05-19 11:51:53.178543 | 2026-05-19 11:51:53.178613 | TASK [Upload logs] 2026-05-19 11:51:53.202510 | localhost | ok 2026-05-19 11:51:53.315568 | 2026-05-19 11:51:53.315736 | TASK [Set zuul-log-path fact] 2026-05-19 11:51:53.339297 | localhost | ok 2026-05-19 11:51:53.351190 | 2026-05-19 11:51:53.351255 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-05-19 11:51:53.394406 | localhost | ok 2026-05-19 11:51:53.402167 | 2026-05-19 11:51:53.402228 | TASK [upload-logs : Create log directories] 2026-05-19 11:51:53.781792 | localhost | changed 2026-05-19 11:51:53.788200 | 2026-05-19 11:51:53.788269 | TASK [upload-logs : Ensure logs are readable before uploading] 2026-05-19 11:51:54.153195 | localhost -> localhost | ok: Runtime: 0:00:00.006625 2026-05-19 11:51:54.159185 | 2026-05-19 11:51:54.159336 | TASK [upload-logs : Upload logs to log server] 2026-05-19 11:51:54.584912 | localhost | Output suppressed because no_log was given 2026-05-19 11:51:54.588716 | 2026-05-19 11:51:54.588782 | LOOP [upload-logs : Compress console log and json output] 2026-05-19 11:51:54.639434 | localhost | skipping: Conditional result was False 2026-05-19 11:51:54.648512 | localhost | skipping: Conditional result was False 2026-05-19 11:51:54.663015 | 2026-05-19 11:51:54.663185 | LOOP [upload-logs : Upload compressed console log and json output] 2026-05-19 11:51:54.711018 | localhost | skipping: Conditional result was False 2026-05-19 11:51:54.711495 | 2026-05-19 11:51:54.715023 | localhost | skipping: Conditional result was False 2026-05-19 11:51:54.731348 | 2026-05-19 11:51:54.731523 | LOOP [upload-logs : Upload console log and json output]