2026-02-19 02:45:52.267351 | Job console starting 2026-02-19 02:45:52.277908 | Updating git repos 2026-02-19 02:45:52.351275 | Cloning repos into workspace 2026-02-19 02:45:52.425869 | Restoring repo states 2026-02-19 02:45:52.443525 | Merging changes 2026-02-19 02:45:53.482227 | Checking out repos 2026-02-19 02:45:53.591170 | Preparing playbooks 2026-02-19 02:45:56.385940 | Running Ansible setup 2026-02-19 02:45:59.644665 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main] 2026-02-19 02:46:00.216064 | 2026-02-19 02:46:00.216191 | PLAY [localhost] 2026-02-19 02:46:00.224123 | 2026-02-19 02:46:00.224196 | TASK [Gathering Facts] 2026-02-19 02:46:01.135005 | localhost | ok 2026-02-19 02:46:01.141998 | 2026-02-19 02:46:01.142077 | TASK [Setup log path fact] 2026-02-19 02:46:01.162917 | localhost | ok 2026-02-19 02:46:01.174664 | 2026-02-19 02:46:01.174731 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-19 02:46:01.208486 | localhost | ok 2026-02-19 02:46:01.217841 | 2026-02-19 02:46:01.217912 | TASK [emit-job-header : Print job information] 2026-02-19 02:46:01.260112 | # Job Information 2026-02-19 02:46:01.260332 | Ansible Version: 2.16.16 2026-02-19 02:46:01.260403 | Job: atmosphere-molecule-csi-rbd 2026-02-19 02:46:01.260452 | Pipeline: check 2026-02-19 02:46:01.260496 | Executor: 0a8996d2b663 2026-02-19 02:46:01.260538 | Triggered by: https://github.com/vexxhost/atmosphere/pull/3501 2026-02-19 02:46:01.260587 | Event ID: 03e06600-0d3d-11f1-9d53-bcc166ec8e25 2026-02-19 02:46:01.264564 | 2026-02-19 02:46:01.264653 | LOOP [emit-job-header : Print node information] 2026-02-19 02:46:01.376560 | localhost | ok: 2026-02-19 02:46:01.377257 | localhost | # Node Information 2026-02-19 02:46:01.377344 | localhost | Inventory Hostname: instance 2026-02-19 02:46:01.377395 | localhost | Hostname: np0000156506 2026-02-19 02:46:01.377439 | localhost | Username: zuul 2026-02-19 02:46:01.377542 | localhost | Distro: Ubuntu 22.04 2026-02-19 02:46:01.377587 | localhost | Provider: yul1 2026-02-19 02:46:01.377610 | localhost | Region: ca-ymq-1 2026-02-19 02:46:01.377721 | localhost | Label: ubuntu-jammy 2026-02-19 02:46:01.377758 | localhost | Product Name: OpenStack Nova 2026-02-19 02:46:01.377779 | localhost | Interface IP: 199.204.45.70 2026-02-19 02:46:01.392727 | 2026-02-19 02:46:01.392853 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-02-19 02:46:01.844052 | localhost -> localhost | changed 2026-02-19 02:46:01.852796 | 2026-02-19 02:46:01.852888 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-02-19 02:46:02.771606 | localhost -> localhost | changed 2026-02-19 02:46:02.785548 | 2026-02-19 02:46:02.785774 | PLAY [all] 2026-02-19 02:46:02.799471 | 2026-02-19 02:46:02.799542 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-02-19 02:46:03.048547 | instance -> localhost | ok 2026-02-19 02:46:03.062039 | 2026-02-19 02:46:03.062148 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-02-19 02:46:03.096424 | instance | ok 2026-02-19 02:46:03.112532 | instance | included: /var/lib/zuul/builds/990ac9cc41bd46eabd1ce7bcc84f3ccb/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-02-19 02:46:03.118372 | 2026-02-19 02:46:03.118431 | TASK [add-build-sshkey : Create Temp SSH key] 2026-02-19 02:46:04.279378 | instance -> localhost | Generating public/private rsa key pair. 2026-02-19 02:46:04.279585 | instance -> localhost | Your identification has been saved in /var/lib/zuul/builds/990ac9cc41bd46eabd1ce7bcc84f3ccb/work/990ac9cc41bd46eabd1ce7bcc84f3ccb_id_rsa 2026-02-19 02:46:04.279616 | instance -> localhost | Your public key has been saved in /var/lib/zuul/builds/990ac9cc41bd46eabd1ce7bcc84f3ccb/work/990ac9cc41bd46eabd1ce7bcc84f3ccb_id_rsa.pub 2026-02-19 02:46:04.279639 | instance -> localhost | The key fingerprint is: 2026-02-19 02:46:04.279661 | instance -> localhost | SHA256:XrtTrab2CXc/eXnKgenu091elbQ8P7WwI0yQSxCX6Cs zuul-build-sshkey 2026-02-19 02:46:04.279701 | instance -> localhost | The key's randomart image is: 2026-02-19 02:46:04.279723 | instance -> localhost | +---[RSA 3072]----+ 2026-02-19 02:46:04.279749 | instance -> localhost | | oo.. | 2026-02-19 02:46:04.279771 | instance -> localhost | | .o.. | 2026-02-19 02:46:04.279791 | instance -> localhost | | . + . | 2026-02-19 02:46:04.279812 | instance -> localhost | | .. o o o| 2026-02-19 02:46:04.279832 | instance -> localhost | | S... o =o| 2026-02-19 02:46:04.279852 | instance -> localhost | | E o .o..o+ *| 2026-02-19 02:46:04.279872 | instance -> localhost | | . . o++=o+*| 2026-02-19 02:46:04.279893 | instance -> localhost | | o==+o*B| 2026-02-19 02:46:04.279915 | instance -> localhost | | .oB*.oo*| 2026-02-19 02:46:04.279936 | instance -> localhost | +----[SHA256]-----+ 2026-02-19 02:46:04.279983 | instance -> localhost | ok: Runtime: 0:00:00.745175 2026-02-19 02:46:04.286146 | 2026-02-19 02:46:04.286210 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-02-19 02:46:04.320079 | instance | ok 2026-02-19 02:46:04.331141 | instance | included: /var/lib/zuul/builds/990ac9cc41bd46eabd1ce7bcc84f3ccb/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-02-19 02:46:04.338535 | 2026-02-19 02:46:04.338596 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-02-19 02:46:04.363422 | instance | skipping: Conditional result was False 2026-02-19 02:46:04.373303 | 2026-02-19 02:46:04.373390 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-02-19 02:46:04.826288 | instance | changed 2026-02-19 02:46:04.831268 | 2026-02-19 02:46:04.831333 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-02-19 02:46:05.014339 | instance | ok 2026-02-19 02:46:05.019445 | 2026-02-19 02:46:05.019508 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-02-19 02:46:05.498686 | instance | changed 2026-02-19 02:46:05.505821 | 2026-02-19 02:46:05.505911 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-02-19 02:46:05.956925 | instance | changed 2026-02-19 02:46:05.964113 | 2026-02-19 02:46:05.964192 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-02-19 02:46:05.990799 | instance | skipping: Conditional result was False 2026-02-19 02:46:06.003161 | 2026-02-19 02:46:06.003242 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-02-19 02:46:06.397900 | instance -> localhost | changed 2026-02-19 02:46:06.413350 | 2026-02-19 02:46:06.413445 | TASK [add-build-sshkey : Add back temp key] 2026-02-19 02:46:06.700530 | instance -> localhost | Identity added: /var/lib/zuul/builds/990ac9cc41bd46eabd1ce7bcc84f3ccb/work/990ac9cc41bd46eabd1ce7bcc84f3ccb_id_rsa (zuul-build-sshkey) 2026-02-19 02:46:06.700778 | instance -> localhost | ok: Runtime: 0:00:00.014196 2026-02-19 02:46:06.709052 | 2026-02-19 02:46:06.709139 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-02-19 02:46:07.026181 | instance | ok 2026-02-19 02:46:07.032793 | 2026-02-19 02:46:07.032870 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-02-19 02:46:07.058768 | instance | skipping: Conditional result was False 2026-02-19 02:46:07.075142 | 2026-02-19 02:46:07.075213 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-02-19 02:46:07.414952 | instance | ok 2026-02-19 02:46:07.423347 | 2026-02-19 02:46:07.423443 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-02-19 02:46:09.019266 | instance | Output suppressed because no_log was given 2026-02-19 02:46:09.031324 | 2026-02-19 02:46:09.031389 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-02-19 02:46:09.218786 | instance | ok: "logs" 2026-02-19 02:46:09.219113 | instance | ok: All items complete 2026-02-19 02:46:09.219155 | 2026-02-19 02:46:09.378131 | instance | ok: "artifacts" 2026-02-19 02:46:09.540108 | instance | ok: "docs" 2026-02-19 02:46:09.558818 | 2026-02-19 02:46:09.559292 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-02-19 02:46:09.750718 | instance | changed: "logs" 2026-02-19 02:46:09.904463 | instance | changed: "artifacts" 2026-02-19 02:46:10.059554 | instance | changed: "docs" 2026-02-19 02:46:10.073902 | 2026-02-19 02:46:10.074027 | PLAY RECAP 2026-02-19 02:46:10.074090 | instance | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0 2026-02-19 02:46:10.074131 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-02-19 02:46:10.074163 | 2026-02-19 02:46:10.212464 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main] 2026-02-19 02:46:10.216617 | PRE-RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main] 2026-02-19 02:46:10.800472 | 2026-02-19 02:46:10.800607 | PLAY [all] 2026-02-19 02:46:10.811980 | 2026-02-19 02:46:10.812061 | TASK [setup-uv : Extract archive] 2026-02-19 02:46:13.045781 | instance | changed 2026-02-19 02:46:13.053834 | 2026-02-19 02:46:13.053942 | TASK [setup-uv : Print version] 2026-02-19 02:46:13.004494 | instance | uv 0.8.13 2026-02-19 02:46:13.592168 | instance | ok: Runtime: 0:00:00.013550 2026-02-19 02:46:13.599715 | 2026-02-19 02:46:13.599768 | PLAY RECAP 2026-02-19 02:46:13.599816 | instance | ok: 2 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-02-19 02:46:13.599840 | 2026-02-19 02:46:13.731907 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main] 2026-02-19 02:46:13.735951 | PRE-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@main] 2026-02-19 02:46:14.362372 | 2026-02-19 02:46:14.362517 | PLAY [all] 2026-02-19 02:46:14.373809 | 2026-02-19 02:46:14.373890 | TASK [Install "jq" for log collection] 2026-02-19 02:46:24.823785 | instance | changed 2026-02-19 02:46:24.825888 | 2026-02-19 02:46:24.825958 | PLAY RECAP 2026-02-19 02:46:24.826015 | instance | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-02-19 02:46:24.826066 | 2026-02-19 02:46:24.950500 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@main] 2026-02-19 02:46:24.954581 | RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main] 2026-02-19 02:46:25.612879 | 2026-02-19 02:46:25.613045 | PLAY [all] 2026-02-19 02:46:25.625000 | 2026-02-19 02:46:25.625074 | TASK [Copy inventory file for Zuul] 2026-02-19 02:46:26.497684 | instance | changed 2026-02-19 02:46:26.504700 | 2026-02-19 02:46:26.504782 | TASK [Switch "ansible_host" to private IP] 2026-02-19 02:46:26.782213 | instance | changed: 1 replacements made 2026-02-19 02:46:26.789619 | 2026-02-19 02:46:26.789713 | TASK [Run Molecule scenario] 2026-02-19 02:46:27.235875 | instance | Using CPython 3.10.12 interpreter at: /usr/bin/python3 2026-02-19 02:46:27.236113 | instance | Creating virtual environment at: .venv 2026-02-19 02:46:27.256393 | instance | Building atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere 2026-02-19 02:46:27.289526 | instance | Downloading pygments (1.2MiB) 2026-02-19 02:46:27.289654 | instance | Downloading kubernetes (1.9MiB) 2026-02-19 02:46:27.290488 | instance | Downloading ansible-core (2.1MiB) 2026-02-19 02:46:27.290669 | instance | Downloading netaddr (2.2MiB) 2026-02-19 02:46:27.291393 | instance | Downloading openstacksdk (1.7MiB) 2026-02-19 02:46:27.293988 | instance | Downloading rjsonnet (1.2MiB) 2026-02-19 02:46:27.294220 | instance | Downloading setuptools (1.1MiB) 2026-02-19 02:46:27.294703 | instance | Downloading cryptography (4.2MiB) 2026-02-19 02:46:27.561677 | instance | Building pyperclip==1.9.0 2026-02-19 02:46:27.577130 | instance | Downloading rjsonnet 2026-02-19 02:46:27.713587 | instance | Downloading netaddr 2026-02-19 02:46:27.727802 | instance | Downloading pygments 2026-02-19 02:46:27.738930 | instance | Downloading cryptography 2026-02-19 02:46:27.771379 | instance | Downloading setuptools 2026-02-19 02:46:27.824116 | instance | Downloading kubernetes 2026-02-19 02:46:27.857150 | instance | Downloading ansible-core 2026-02-19 02:46:27.887884 | instance | Downloading openstacksdk 2026-02-19 02:46:28.256351 | instance | Built pyperclip==1.9.0 2026-02-19 02:46:28.523612 | instance | Built atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere 2026-02-19 02:46:28.565802 | instance | Installed 79 packages in 40ms 2026-02-19 02:46:29.207475 | instance | WARNING Molecule scenarios should migrate to 'extensions/molecule' 2026-02-19 02:46:29.849503 | instance | INFO [csi > discovery] scenario test matrix: dependency, cleanup, destroy, syntax, create, prepare, converge, idempotence, side_effect, verify, cleanup, destroy 2026-02-19 02:46:29.849596 | instance | INFO [csi > prerun] Performing prerun with role_name_check=0... 2026-02-19 02:46:41.597000 | instance | WARNING Retrying execution failure 1 of: ansible-galaxy collection install -vvv community.general:7.3.0 2026-02-19 02:46:41.597147 | instance | ERROR Command ansible-galaxy collection install -vvv community.general:7.3.0, returned 1 code: 2026-02-19 02:46:41.597166 | instance | Starting galaxy collection install process 2026-02-19 02:46:41.597180 | instance | Process install dependency map 2026-02-19 02:46:41.597194 | instance | Starting collection install process 2026-02-19 02:46:41.597209 | instance | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/community-general-7.3.0.tar.gz to /home/zuul/.ansible/tmp/ansible-local-13009jc44m_u/tmp8ii3mp6y/community-general-7.3.0-ly5b_qre 2026-02-19 02:46:41.597223 | instance | 2026-02-19 02:46:41.597237 | instance | ansible-galaxy 2026-02-19 02:46:41.597250 | instance | config file = None 2026-02-19 02:46:41.597263 | instance | configured module search path = 2026-02-19 02:46:41.597276 | instance | ansible python module location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/ansible 2026-02-19 02:46:41.597290 | 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-02-19 02:46:41.597324 | instance | executable location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/ansible-galaxy 2026-02-19 02:46:41.597338 | instance | python version = 3.10.12 (main, Jan 26 2026, 14:55:28) (/home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/python) 2026-02-19 02:46:41.597351 | instance | jinja version = 3.1.6 2026-02-19 02:46:41.597364 | instance | libyaml = True 2026-02-19 02:46:41.597376 | instance | No config file found; using defaults 2026-02-19 02:46:41.597390 | instance | Found installed collection ansible.posix:1.6.0 at '/home/zuul/.ansible/collections/ansible_collections/ansible/posix' 2026-02-19 02:46:41.597402 | instance | Found installed collection community.crypto:2.2.3 at '/home/zuul/.ansible/collections/ansible_collections/community/crypto' 2026-02-19 02:46:41.597415 | instance | : Collection ansible.netcommon does not support Ansible version 2026-02-19 02:46:41.597446 | instance | 2.17.12 2026-02-19 02:46:41.597461 | instance | Found installed collection ansible.netcommon:1.2.0 at '/home/zuul/.ansible/collections/ansible_collections/ansible/netcommon' 2026-02-19 02:46:41.597475 | instance | Found installed collection ansible.utils:6.0.1 at '/home/zuul/.ansible/collections/ansible_collections/ansible/utils' 2026-02-19 02:46:41.597489 | instance | Opened /home/zuul/.ansible/galaxy_token 2026-02-19 02:46:41.597503 | instance | ERROR! Failed to download collection tar from 'default' due to the following unforeseen error: HTTP Error 502: Bad Gateway. HTTP Error 502: Bad Gateway 2026-02-19 02:46:41.597556 | instance | 2026-02-19 02:46:41.598027 | instance | Traceback (most recent call last): 2026-02-19 02:46:41.598364 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/molecule", line 10, in 2026-02-19 02:46:41.598826 | instance | sys.exit(main()) 2026-02-19 02:46:41.599135 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 1442, in __call__ 2026-02-19 02:46:41.600906 | instance | return self.main(*args, **kwargs) 2026-02-19 02:46:41.601231 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 1363, in main 2026-02-19 02:46:41.602045 | instance | rv = self.invoke(ctx) 2026-02-19 02:46:41.602340 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 1830, in invoke 2026-02-19 02:46:41.603181 | instance | return _process_result(sub_ctx.command.invoke(sub_ctx)) 2026-02-19 02:46:41.603482 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 1226, in invoke 2026-02-19 02:46:41.604256 | instance | return ctx.invoke(self.callback, **ctx.params) 2026-02-19 02:46:41.604528 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 794, in invoke 2026-02-19 02:46:41.605090 | instance | return callback(*args, **kwargs) 2026-02-19 02:46:41.605389 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/molecule/click_cfg.py", line 583, in wrapper 2026-02-19 02:46:41.605956 | instance | return func(*args, **kwargs) 2026-02-19 02:46:41.606295 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/decorators.py", line 34, in new_func 2026-02-19 02:46:41.606682 | instance | return f(get_current_context(), *args, **kwargs) 2026-02-19 02:46:41.606980 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/molecule/click_cfg.py", line 418, in wrapper 2026-02-19 02:46:41.607446 | instance | return func(ctx) 2026-02-19 02:46:41.607774 | instance | File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/molecule/command/test.py", line 81, in test 2026-02-19 02:46:41.608205 | instance | base.execute_cmdline_scenarios(scenario_name, args, command_args, ansible_args, exclude) 2026-02-19 02:46:41.608507 | 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-02-19 02:46:41.608948 | instance | _run_scenarios(scenarios, command_args, default_config) 2026-02-19 02:46:41.609277 | 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-02-19 02:46:41.609767 | instance | scenario.config.runtime.prepare_environment( 2026-02-19 02:46:41.610080 | 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-02-19 02:46:41.610598 | instance | self.install_collection( 2026-02-19 02:46:41.610717 | 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-02-19 02:46:41.610952 | instance | raise InvalidPrerequisiteError(msg) 2026-02-19 02:46:41.611898 | instance | ansible_compat.errors.InvalidPrerequisiteError: Command ansible-galaxy collection install -vvv community.general:7.3.0, returned 1 code: 2026-02-19 02:46:41.611925 | instance | Starting galaxy collection install process 2026-02-19 02:46:41.611934 | instance | Process install dependency map 2026-02-19 02:46:41.611943 | instance | Starting collection install process 2026-02-19 02:46:41.611952 | instance | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/community-general-7.3.0.tar.gz to /home/zuul/.ansible/tmp/ansible-local-13009jc44m_u/tmp8ii3mp6y/community-general-7.3.0-ly5b_qre 2026-02-19 02:46:41.611963 | instance | 2026-02-19 02:46:41.611976 | instance | ansible-galaxy [core 2.17.12] 2026-02-19 02:46:41.612009 | instance | config file = None 2026-02-19 02:46:41.612025 | instance | configured module search path = ['/home/zuul/src/github.com/vexxhost/atmosphere/plugins/modules', '/home/zuul/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules'] 2026-02-19 02:46:41.612039 | instance | ansible python module location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/ansible 2026-02-19 02:46:41.612053 | 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-02-19 02:46:41.612067 | instance | executable location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/ansible-galaxy 2026-02-19 02:46:41.612080 | instance | python version = 3.10.12 (main, Jan 26 2026, 14:55:28) [GCC 11.4.0] (/home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/python) 2026-02-19 02:46:41.612092 | instance | jinja version = 3.1.6 2026-02-19 02:46:41.612101 | instance | libyaml = True 2026-02-19 02:46:41.612110 | instance | No config file found; using defaults 2026-02-19 02:46:41.612119 | instance | Found installed collection ansible.posix:1.6.0 at '/home/zuul/.ansible/collections/ansible_collections/ansible/posix' 2026-02-19 02:46:41.612128 | instance | Found installed collection community.crypto:2.2.3 at '/home/zuul/.ansible/collections/ansible_collections/community/crypto' 2026-02-19 02:46:41.612137 | instance | [WARNING]: Collection ansible.netcommon does not support Ansible version 2026-02-19 02:46:41.612145 | instance | 2.17.12 2026-02-19 02:46:41.612154 | instance | Found installed collection ansible.netcommon:1.2.0 at '/home/zuul/.ansible/collections/ansible_collections/ansible/netcommon' 2026-02-19 02:46:41.612163 | instance | Found installed collection ansible.utils:6.0.1 at '/home/zuul/.ansible/collections/ansible_collections/ansible/utils' 2026-02-19 02:46:41.612171 | instance | Opened /home/zuul/.ansible/galaxy_token 2026-02-19 02:46:41.612180 | instance | ERROR! Failed to download collection tar from 'default' due to the following unforeseen error: HTTP Error 502: Bad Gateway. HTTP Error 502: Bad Gateway 2026-02-19 02:46:41.612195 | instance | 2026-02-19 02:46:41.852860 | instance | ERROR 2026-02-19 02:46:41.853117 | instance | { 2026-02-19 02:46:41.853149 | instance | "delta": "0:00:14.538400", 2026-02-19 02:46:41.853172 | instance | "end": "2026-02-19 02:46:41.704767", 2026-02-19 02:46:41.853192 | instance | "msg": "non-zero return code", 2026-02-19 02:46:41.853211 | instance | "rc": 1, 2026-02-19 02:46:41.853232 | instance | "start": "2026-02-19 02:46:27.166367" 2026-02-19 02:46:41.853251 | instance | } failure 2026-02-19 02:46:41.855518 | 2026-02-19 02:46:41.855566 | PLAY RECAP 2026-02-19 02:46:41.855613 | instance | ok: 2 changed: 2 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0 2026-02-19 02:46:41.855636 | 2026-02-19 02:46:41.962997 | RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main] 2026-02-19 02:46:41.967908 | POST-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@main] 2026-02-19 02:46:42.567210 | 2026-02-19 02:46:42.567345 | PLAY [all] 2026-02-19 02:46:42.582506 | 2026-02-19 02:46:42.582598 | TASK [gather-host-logs : creating directory for system status] 2026-02-19 02:46:42.946099 | instance | changed 2026-02-19 02:46:43.494961 | 2026-02-19 02:46:43.495190 | TASK [gather-host-logs : Get logs for each host] 2026-02-19 02:46:43.869038 | instance | + systemd-cgls --full --all --no-pager 2026-02-19 02:46:43.881494 | instance | + ip addr 2026-02-19 02:46:43.884565 | instance | + ip route 2026-02-19 02:46:43.886082 | instance | + lsblk 2026-02-19 02:46:43.890714 | instance | + mount 2026-02-19 02:46:43.894050 | instance | + docker images 2026-02-19 02:46:43.894866 | instance | /bin/bash: line 7: docker: command not found 2026-02-19 02:46:43.895230 | instance | + brctl show 2026-02-19 02:46:43.896426 | instance | /bin/bash: line 8: brctl: command not found 2026-02-19 02:46:43.896807 | instance | + ps aux --sort=-%mem 2026-02-19 02:46:43.911512 | instance | + dpkg -l 2026-02-19 02:46:43.918919 | instance | + CONTAINERS=($(docker ps -a --format '{{ .Names }}' --filter label=zuul)) 2026-02-19 02:46:43.919357 | instance | ++ docker ps -a --format '{{ .Names }}' --filter label=zuul 2026-02-19 02:46:43.919413 | instance | /bin/bash: line 11: docker: command not found 2026-02-19 02:46:43.919779 | instance | + '[' '!' -z '' ']' 2026-02-19 02:46:44.031467 | instance | ok: Runtime: 0:00:00.057212 2026-02-19 02:46:44.039909 | 2026-02-19 02:46:44.040007 | TASK [gather-host-logs : Downloads logs to executor] 2026-02-19 02:46:44.745286 | instance | changed: 2026-02-19 02:46:44.745507 | instance | created directory /var/lib/zuul/builds/990ac9cc41bd46eabd1ce7bcc84f3ccb/work/logs/instance 2026-02-19 02:46:44.745548 | instance | cd+++++++++ system/ 2026-02-19 02:46:44.745581 | instance | >f+++++++++ system/brctl-show.txt 2026-02-19 02:46:44.745609 | instance | >f+++++++++ system/docker-images.txt 2026-02-19 02:46:44.745636 | instance | >f+++++++++ system/ip-addr.txt 2026-02-19 02:46:44.745667 | instance | >f+++++++++ system/ip-route.txt 2026-02-19 02:46:44.745698 | instance | >f+++++++++ system/lsblk.txt 2026-02-19 02:46:44.745726 | instance | >f+++++++++ system/mount.txt 2026-02-19 02:46:44.745755 | instance | >f+++++++++ system/packages.txt 2026-02-19 02:46:44.745782 | instance | >f+++++++++ system/ps.txt 2026-02-19 02:46:44.745811 | instance | >f+++++++++ system/systemd-cgls.txt 2026-02-19 02:46:44.756432 | 2026-02-19 02:46:44.756509 | LOOP [helm-release-status : creating directory for helm release status] 2026-02-19 02:46:44.999742 | instance | changed: "values" 2026-02-19 02:46:45.177873 | instance | changed: "releases" 2026-02-19 02:46:45.198121 | 2026-02-19 02:46:45.198501 | TASK [helm-release-status : Gather get release status for helm charts] 2026-02-19 02:46:45.423878 | instance | /bin/bash: line 3: kubectl: command not found 2026-02-19 02:46:45.749626 | instance | ok: Runtime: 0:00:00.006040 2026-02-19 02:46:45.755540 | 2026-02-19 02:46:45.755609 | TASK [helm-release-status : Downloads logs to executor] 2026-02-19 02:46:46.298464 | instance | changed: 2026-02-19 02:46:46.298621 | instance | cd+++++++++ helm/ 2026-02-19 02:46:46.298649 | instance | cd+++++++++ helm/releases/ 2026-02-19 02:46:46.298671 | instance | cd+++++++++ helm/values/ 2026-02-19 02:46:46.307469 | 2026-02-19 02:46:46.307567 | TASK [describe-kubernetes-objects : creating directory for cluster scoped objects] 2026-02-19 02:46:46.515079 | instance | changed 2026-02-19 02:46:46.524449 | 2026-02-19 02:46:46.524562 | TASK [describe-kubernetes-objects : Gathering descriptions for cluster scoped objects] 2026-02-19 02:46:46.737102 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value 2026-02-19 02:46:46.737759 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value 2026-02-19 02:46:46.742552 | instance | environment: line 1: kubectl: command not found 2026-02-19 02:46:46.743322 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value 2026-02-19 02:46:46.744374 | instance | environment: line 1: kubectl: command not found 2026-02-19 02:46:46.745373 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value 2026-02-19 02:46:46.747064 | instance | environment: line 1: kubectl: command not found 2026-02-19 02:46:46.748103 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value 2026-02-19 02:46:46.749322 | instance | environment: line 1: kubectl: command not found 2026-02-19 02:46:46.750465 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value 2026-02-19 02:46:46.751525 | instance | environment: line 1: kubectl: command not found 2026-02-19 02:46:46.752402 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value 2026-02-19 02:46:47.107761 | instance | ok: Runtime: 0:00:00.025802 2026-02-19 02:46:47.115791 | 2026-02-19 02:46:47.115929 | TASK [describe-kubernetes-objects : creating directory for namespace scoped objects] 2026-02-19 02:46:47.319711 | instance | changed 2026-02-19 02:46:47.327975 | 2026-02-19 02:46:47.328075 | TASK [describe-kubernetes-objects : Gathering descriptions for namespace scoped objects] 2026-02-19 02:46:47.569301 | instance | environment: line 5: kubectl: command not found 2026-02-19 02:46:47.569520 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value 2026-02-19 02:46:47.570350 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value 2026-02-19 02:46:47.570689 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value 2026-02-19 02:46:47.900678 | instance | ok: Runtime: 0:00:00.009156 2026-02-19 02:46:47.908123 | 2026-02-19 02:46:47.908218 | TASK [describe-kubernetes-objects : Downloads logs to executor] 2026-02-19 02:46:48.399084 | instance | changed: 2026-02-19 02:46:48.399350 | instance | cd+++++++++ objects/ 2026-02-19 02:46:48.399410 | instance | cd+++++++++ objects/cluster/ 2026-02-19 02:46:48.399457 | instance | cd+++++++++ objects/namespaced/ 2026-02-19 02:46:48.411418 | 2026-02-19 02:46:48.411487 | TASK [gather-pod-logs : creating directory for pod logs] 2026-02-19 02:46:48.618331 | instance | changed 2026-02-19 02:46:48.623511 | 2026-02-19 02:46:48.623579 | TASK [gather-pod-logs : creating directory for failed pod logs] 2026-02-19 02:46:48.833602 | instance | changed 2026-02-19 02:46:48.838542 | 2026-02-19 02:46:48.838615 | TASK [gather-pod-logs : retrieve all kubernetes logs, current and previous (if they exist)] 2026-02-19 02:46:49.054345 | instance | environment: line 3: kubectl: command not found 2026-02-19 02:46:49.374747 | instance | ok: Runtime: 0:00:00.009560 2026-02-19 02:46:49.381766 | 2026-02-19 02:46:49.381854 | TASK [gather-pod-logs : Downloads pod logs to executor] 2026-02-19 02:46:50.012513 | instance | changed: 2026-02-19 02:46:50.012697 | instance | cd+++++++++ pod-logs/ 2026-02-19 02:46:50.012725 | instance | cd+++++++++ pod-logs/failed-pods/ 2026-02-19 02:46:50.031984 | 2026-02-19 02:46:50.032055 | TASK [gather-prom-metrics : creating directory for helm release descriptions] 2026-02-19 02:46:50.233923 | instance | changed 2026-02-19 02:46:50.240429 | 2026-02-19 02:46:50.240520 | TASK [gather-prom-metrics : Get metrics from exporter services in all namespaces] 2026-02-19 02:46:50.444522 | instance | /bin/bash: line 2: kubectl: command not found 2026-02-19 02:46:50.777484 | instance | ok: Runtime: 0:00:00.036834 2026-02-19 02:46:50.784078 | 2026-02-19 02:46:50.784169 | TASK [gather-prom-metrics : Get ceph metrics from ceph-mgr] 2026-02-19 02:46:50.991333 | instance | /bin/bash: line 2: kubectl: command not found 2026-02-19 02:46:51.022088 | instance | ceph-mgr endpoints: 2026-02-19 02:46:51.321999 | instance | ok: Runtime: 0:00:00.036791 2026-02-19 02:46:51.331128 | 2026-02-19 02:46:51.331665 | TASK [gather-prom-metrics : Get metrics from fluentd pods] 2026-02-19 02:46:51.550344 | instance | /bin/bash: line 4: kubectl: command not found 2026-02-19 02:46:51.872412 | instance | ok: Runtime: 0:00:00.036399 2026-02-19 02:46:51.878874 | 2026-02-19 02:46:51.878943 | TASK [gather-prom-metrics : Downloads logs to executor] 2026-02-19 02:46:52.408869 | instance | changed: cd+++++++++ prometheus/ 2026-02-19 02:46:52.418840 | 2026-02-19 02:46:52.418901 | TASK [gather-selenium-data : creating directory for helm release descriptions] 2026-02-19 02:46:52.626947 | instance | changed 2026-02-19 02:46:52.634395 | 2026-02-19 02:46:52.634503 | TASK [gather-selenium-data : Get selenium data] 2026-02-19 02:46:52.841730 | instance | + cp '/tmp/artifacts/*' /tmp/logs/selenium/. 2026-02-19 02:46:52.843256 | instance | cp: cannot stat '/tmp/artifacts/*': No such file or directory 2026-02-19 02:46:53.175638 | instance | ERROR 2026-02-19 02:46:53.175929 | instance | { 2026-02-19 02:46:53.175972 | instance | "delta": "0:00:00.007400", 2026-02-19 02:46:53.176002 | instance | "end": "2026-02-19 02:46:52.843683", 2026-02-19 02:46:53.176029 | instance | "msg": "non-zero return code", 2026-02-19 02:46:53.176054 | instance | "rc": 1, 2026-02-19 02:46:53.176079 | instance | "start": "2026-02-19 02:46:52.836283" 2026-02-19 02:46:53.176103 | instance | } 2026-02-19 02:46:53.176135 | instance | ERROR: Ignoring Errors 2026-02-19 02:46:53.183095 | 2026-02-19 02:46:53.183257 | TASK [gather-selenium-data : Downloads logs to executor] 2026-02-19 02:46:53.690692 | instance | changed: cd+++++++++ selenium/ 2026-02-19 02:46:53.697322 | 2026-02-19 02:46:53.697377 | PLAY RECAP 2026-02-19 02:46:53.697425 | instance | ok: 23 changed: 23 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 1 2026-02-19 02:46:53.697447 | 2026-02-19 02:46:53.841809 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@main] 2026-02-19 02:46:53.846208 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main] 2026-02-19 02:46:54.415189 | 2026-02-19 02:46:54.415934 | PLAY [all] 2026-02-19 02:46:54.427917 | 2026-02-19 02:46:54.427996 | TASK [fetch-output : Set log path for multiple nodes] 2026-02-19 02:46:54.473500 | instance | skipping: Conditional result was False 2026-02-19 02:46:54.479648 | 2026-02-19 02:46:54.479731 | TASK [fetch-output : Set log path for single node] 2026-02-19 02:46:54.519594 | instance | ok 2026-02-19 02:46:54.524418 | 2026-02-19 02:46:54.524485 | LOOP [fetch-output : Ensure local output dirs] 2026-02-19 02:46:54.947604 | instance -> localhost | ok: "/var/lib/zuul/builds/990ac9cc41bd46eabd1ce7bcc84f3ccb/work/logs" 2026-02-19 02:46:55.207999 | instance -> localhost | changed: "/var/lib/zuul/builds/990ac9cc41bd46eabd1ce7bcc84f3ccb/work/artifacts" 2026-02-19 02:46:55.415434 | instance -> localhost | changed: "/var/lib/zuul/builds/990ac9cc41bd46eabd1ce7bcc84f3ccb/work/docs" 2026-02-19 02:46:55.438079 | 2026-02-19 02:46:55.438246 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-02-19 02:46:56.117097 | instance | changed: .d..t...... ./ 2026-02-19 02:46:56.117492 | instance | changed: All items complete 2026-02-19 02:46:56.117532 | 2026-02-19 02:46:56.584744 | instance | changed: .d..t...... ./ 2026-02-19 02:46:57.056116 | instance | changed: .d..t...... ./ 2026-02-19 02:46:57.082203 | 2026-02-19 02:46:57.082379 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-02-19 02:46:57.571681 | instance -> localhost | ok: Item: artifacts Runtime: 0:00:00.007830 2026-02-19 02:46:57.815692 | instance -> localhost | ok: Item: docs Runtime: 0:00:00.009119 2026-02-19 02:46:57.836470 | 2026-02-19 02:46:57.836633 | PLAY [all] 2026-02-19 02:46:57.842672 | 2026-02-19 02:46:57.842738 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2026-02-19 02:46:58.263833 | instance | changed 2026-02-19 02:46:58.271676 | 2026-02-19 02:46:58.271747 | PLAY RECAP 2026-02-19 02:46:58.271838 | instance | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2026-02-19 02:46:58.271877 | 2026-02-19 02:46:58.411491 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main] 2026-02-19 02:46:58.415728 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main] 2026-02-19 02:46:59.060061 | 2026-02-19 02:46:59.060194 | PLAY [localhost] 2026-02-19 02:46:59.070133 | 2026-02-19 02:46:59.070206 | TASK [Generate Zuul manifest] 2026-02-19 02:46:59.094604 | localhost | ok 2026-02-19 02:46:59.112656 | 2026-02-19 02:46:59.112736 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-02-19 02:46:59.444157 | localhost | changed 2026-02-19 02:46:59.455536 | 2026-02-19 02:46:59.455615 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-02-19 02:46:59.485290 | localhost | ok 2026-02-19 02:46:59.495917 | 2026-02-19 02:46:59.496035 | TASK [Upload logs] 2026-02-19 02:46:59.530156 | localhost | ok 2026-02-19 02:46:59.596854 | 2026-02-19 02:46:59.597045 | TASK [Set zuul-log-path fact] 2026-02-19 02:46:59.621611 | localhost | ok 2026-02-19 02:46:59.638735 | 2026-02-19 02:46:59.638989 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-02-19 02:46:59.675040 | localhost | ok 2026-02-19 02:46:59.684421 | 2026-02-19 02:46:59.684518 | TASK [upload-logs : Create log directories] 2026-02-19 02:47:00.116895 | localhost | changed 2026-02-19 02:47:00.128069 | 2026-02-19 02:47:00.128274 | TASK [upload-logs : Ensure logs are readable before uploading] 2026-02-19 02:47:00.575852 | localhost -> localhost | ok: Runtime: 0:00:00.005732 2026-02-19 02:47:00.582817 | 2026-02-19 02:47:00.582912 | TASK [upload-logs : Upload logs to log server] 2026-02-19 02:47:01.056239 | localhost | Output suppressed because no_log was given 2026-02-19 02:47:01.060303 | 2026-02-19 02:47:01.060368 | LOOP [upload-logs : Compress console log and json output] 2026-02-19 02:47:01.108212 | localhost | skipping: Conditional result was False 2026-02-19 02:47:01.114943 | localhost | skipping: Conditional result was False 2026-02-19 02:47:01.128904 | 2026-02-19 02:47:01.129031 | LOOP [upload-logs : Upload compressed console log and json output] 2026-02-19 02:47:01.168107 | localhost | skipping: Conditional result was False 2026-02-19 02:47:01.168503 | 2026-02-19 02:47:01.171795 | localhost | skipping: Conditional result was False 2026-02-19 02:47:01.182865 | 2026-02-19 02:47:01.183049 | LOOP [upload-logs : Upload console log and json output]