2026-02-19 05:50:57.841003 | Job console starting
2026-02-19 05:50:57.849200 | Updating git repos
2026-02-19 05:50:57.910298 | Cloning repos into workspace
2026-02-19 05:50:57.961880 | Restoring repo states
2026-02-19 05:50:57.978554 | Merging changes
2026-02-19 05:50:58.956750 | Checking out repos
2026-02-19 05:50:59.346381 | Preparing playbooks
2026-02-19 05:51:01.346403 | Running Ansible setup
2026-02-19 05:51:04.613209 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-02-19 05:51:05.235134 | 
2026-02-19 05:51:05.235936 | PLAY [localhost]
2026-02-19 05:51:05.244295 | 
2026-02-19 05:51:05.244364 | TASK [Gathering Facts]
2026-02-19 05:51:06.160207 | localhost | ok
2026-02-19 05:51:06.167938 | 
2026-02-19 05:51:06.168021 | TASK [Setup log path fact]
2026-02-19 05:51:06.186066 | localhost | ok
2026-02-19 05:51:06.197587 | 
2026-02-19 05:51:06.197672 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-19 05:51:06.225596 | localhost | ok
2026-02-19 05:51:06.233375 | 
2026-02-19 05:51:06.233442 | TASK [emit-job-header : Print job information]
2026-02-19 05:51:06.275773 | # Job Information
2026-02-19 05:51:06.275925 | Ansible Version: 2.16.16
2026-02-19 05:51:06.275969 | Job: atmosphere-molecule-csi-local-path-provisioner
2026-02-19 05:51:06.276001 | Pipeline: check
2026-02-19 05:51:06.276029 | Executor: 0a8996d2b663
2026-02-19 05:51:06.276057 | Triggered by: https://github.com/vexxhost/atmosphere/pull/3669
2026-02-19 05:51:06.276087 | Event ID: d65f62c0-0d56-11f1-9c5c-d61ef9d28e11
2026-02-19 05:51:06.279699 | 
2026-02-19 05:51:06.279779 | LOOP [emit-job-header : Print node information]
2026-02-19 05:51:06.368569 | localhost | ok:
2026-02-19 05:51:06.368795 | localhost | # Node Information
2026-02-19 05:51:06.368836 | localhost | Inventory Hostname: instance
2026-02-19 05:51:06.368869 | localhost | Hostname: np0000156537
2026-02-19 05:51:06.368899 | localhost | Username: zuul
2026-02-19 05:51:06.368932 | localhost | Distro: Ubuntu 22.04
2026-02-19 05:51:06.368963 | localhost | Provider: yul1
2026-02-19 05:51:06.368999 | localhost | Region: ca-ymq-1
2026-02-19 05:51:06.369047 | localhost | Label: ubuntu-jammy
2026-02-19 05:51:06.369077 | localhost | Product Name: OpenStack Nova
2026-02-19 05:51:06.369105 | localhost | Interface IP: 199.204.45.95
2026-02-19 05:51:06.388464 | 
2026-02-19 05:51:06.388579 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-02-19 05:51:06.749298 | localhost -> localhost | changed
2026-02-19 05:51:06.755894 | 
2026-02-19 05:51:06.755984 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-02-19 05:51:07.553675 | localhost -> localhost | changed
2026-02-19 05:51:07.559392 | 
2026-02-19 05:51:07.559446 | PLAY [all]
2026-02-19 05:51:07.569284 | 
2026-02-19 05:51:07.569376 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-19 05:51:07.806419 | instance -> localhost | ok
2026-02-19 05:51:07.816644 | 
2026-02-19 05:51:07.816715 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-19 05:51:07.849090 | instance | ok
2026-02-19 05:51:07.865106 | instance | included: /var/lib/zuul/builds/900a63b0eb15403e8ae1897ef986bff6/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-19 05:51:07.871960 | 
2026-02-19 05:51:07.872069 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-19 05:51:09.188670 | instance -> localhost | Generating public/private rsa key pair.
2026-02-19 05:51:09.188845 | instance -> localhost | Your identification has been saved in /var/lib/zuul/builds/900a63b0eb15403e8ae1897ef986bff6/work/900a63b0eb15403e8ae1897ef986bff6_id_rsa
2026-02-19 05:51:09.188874 | instance -> localhost | Your public key has been saved in /var/lib/zuul/builds/900a63b0eb15403e8ae1897ef986bff6/work/900a63b0eb15403e8ae1897ef986bff6_id_rsa.pub
2026-02-19 05:51:09.188896 | instance -> localhost | The key fingerprint is:
2026-02-19 05:51:09.188918 | instance -> localhost | SHA256:UrTcD7TuBk+Yrm3tNjTj2Y2ov37bwm/WjeacKcUHkyk zuul-build-sshkey
2026-02-19 05:51:09.188951 | instance -> localhost | The key's randomart image is:
2026-02-19 05:51:09.188976 | instance -> localhost | +---[RSA 3072]----+
2026-02-19 05:51:09.189019 | instance -> localhost | |        . .      |
2026-02-19 05:51:09.189042 | instance -> localhost | |       o + .     |
2026-02-19 05:51:09.189063 | instance -> localhost | |        + +    o |
2026-02-19 05:51:09.189084 | instance -> localhost | |       . + oE =  |
2026-02-19 05:51:09.189104 | instance -> localhost | |      . S o .o o |
2026-02-19 05:51:09.189124 | instance -> localhost | |       o =+   o .|
2026-02-19 05:51:09.189144 | instance -> localhost | |        .++B + +.|
2026-02-19 05:51:09.189163 | instance -> localhost | |       o..B Bo*oo|
2026-02-19 05:51:09.189185 | instance -> localhost | |      ..o*=+.XB  |
2026-02-19 05:51:09.189205 | instance -> localhost | +----[SHA256]-----+
2026-02-19 05:51:09.189251 | instance -> localhost | ok: Runtime: 0:00:00.918954
2026-02-19 05:51:09.194132 | 
2026-02-19 05:51:09.194190 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-19 05:51:09.214733 | instance | ok
2026-02-19 05:51:09.225204 | instance | included: /var/lib/zuul/builds/900a63b0eb15403e8ae1897ef986bff6/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-19 05:51:09.232111 | 
2026-02-19 05:51:09.232167 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-19 05:51:09.256103 | instance | skipping: Conditional result was False
2026-02-19 05:51:09.265718 | 
2026-02-19 05:51:09.265778 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-19 05:51:09.682984 | instance | changed
2026-02-19 05:51:09.689222 | 
2026-02-19 05:51:09.689294 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-19 05:51:09.864570 | instance | ok
2026-02-19 05:51:09.872409 | 
2026-02-19 05:51:09.872546 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-19 05:51:10.348250 | instance | changed
2026-02-19 05:51:10.353805 | 
2026-02-19 05:51:10.353866 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-19 05:51:10.804337 | instance | changed
2026-02-19 05:51:10.810320 | 
2026-02-19 05:51:10.810879 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-19 05:51:10.836723 | instance | skipping: Conditional result was False
2026-02-19 05:51:10.849256 | 
2026-02-19 05:51:10.849323 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-19 05:51:11.190091 | instance -> localhost | changed
2026-02-19 05:51:11.204572 | 
2026-02-19 05:51:11.204658 | TASK [add-build-sshkey : Add back temp key]
2026-02-19 05:51:11.478935 | instance -> localhost | Identity added: /var/lib/zuul/builds/900a63b0eb15403e8ae1897ef986bff6/work/900a63b0eb15403e8ae1897ef986bff6_id_rsa (zuul-build-sshkey)
2026-02-19 05:51:11.479164 | instance -> localhost | ok: Runtime: 0:00:00.015058
2026-02-19 05:51:11.485928 | 
2026-02-19 05:51:11.485993 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-19 05:51:11.786117 | instance | ok
2026-02-19 05:51:11.792687 | 
2026-02-19 05:51:11.792792 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-19 05:51:11.817920 | instance | skipping: Conditional result was False
2026-02-19 05:51:11.834321 | 
2026-02-19 05:51:11.834385 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-02-19 05:51:12.151440 | instance | ok
2026-02-19 05:51:12.159975 | 
2026-02-19 05:51:12.160037 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-02-19 05:51:13.716202 | instance | Output suppressed because no_log was given
2026-02-19 05:51:13.727905 | 
2026-02-19 05:51:13.727971 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-02-19 05:51:13.907033 | instance | ok: "logs"
2026-02-19 05:51:13.907333 | instance | ok: All items complete
2026-02-19 05:51:13.907366 | 
2026-02-19 05:51:14.057874 | instance | ok: "artifacts"
2026-02-19 05:51:14.209741 | instance | ok: "docs"
2026-02-19 05:51:14.221216 | 
2026-02-19 05:51:14.221367 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-02-19 05:51:14.405471 | instance | changed: "logs"
2026-02-19 05:51:14.556516 | instance | changed: "artifacts"
2026-02-19 05:51:14.708849 | instance | changed: "docs"
2026-02-19 05:51:14.738946 | 
2026-02-19 05:51:14.739061 | PLAY RECAP
2026-02-19 05:51:14.739110 | instance | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2026-02-19 05:51:14.739139 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-19 05:51:14.739159 | 
2026-02-19 05:51:14.856998 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-02-19 05:51:14.860939 | PRE-RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-02-19 05:51:15.458720 | 
2026-02-19 05:51:15.459413 | PLAY [all]
2026-02-19 05:51:15.471450 | 
2026-02-19 05:51:15.471537 | TASK [setup-uv : Extract archive]
2026-02-19 05:51:17.568145 | instance | changed
2026-02-19 05:51:17.574920 | 
2026-02-19 05:51:17.575015 | TASK [setup-uv : Print version]
2026-02-19 05:51:17.276160 | instance | uv 0.8.13
2026-02-19 05:51:18.110301 | instance | ok: Runtime: 0:00:00.012434
2026-02-19 05:51:18.118932 | 
2026-02-19 05:51:18.118988 | PLAY RECAP
2026-02-19 05:51:18.119039 | instance | ok: 2 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-19 05:51:18.119066 | 
2026-02-19 05:51:18.281057 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-02-19 05:51:18.287252 | PRE-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@stable/2025.1]
2026-02-19 05:51:18.864902 | 
2026-02-19 05:51:18.903430 | PLAY [all]
2026-02-19 05:51:18.919764 | 
2026-02-19 05:51:18.919889 | TASK [Install "jq" for log collection]
2026-02-19 05:51:27.067108 | instance | changed
2026-02-19 05:51:27.068905 | 
2026-02-19 05:51:27.068983 | PLAY RECAP
2026-02-19 05:51:27.069039 | instance | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-19 05:51:27.069090 | 
2026-02-19 05:51:27.254172 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@stable/2025.1]
2026-02-19 05:51:27.259479 | RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-02-19 05:51:27.880528 | 
2026-02-19 05:51:27.880695 | PLAY [all]
2026-02-19 05:51:27.892581 | 
2026-02-19 05:51:27.892661 | TASK [Copy inventory file for Zuul]
2026-02-19 05:51:28.708361 | instance | changed
2026-02-19 05:51:28.714768 | 
2026-02-19 05:51:28.714841 | TASK [Switch "ansible_host" to private IP]
2026-02-19 05:51:28.982832 | instance | changed: 1 replacements made
2026-02-19 05:51:28.988644 | 
2026-02-19 05:51:28.988781 | TASK [Run Molecule scenario]
2026-02-19 05:51:29.412522 | instance | Using CPython 3.10.12 interpreter at: /usr/bin/python3
2026-02-19 05:51:29.412696 | instance | Creating virtual environment at: .venv
2026-02-19 05:51:29.434742 | instance |    Building atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere
2026-02-19 05:51:29.459227 | instance | Downloading rjsonnet (1.2MiB)
2026-02-19 05:51:29.461440 | instance | Downloading ansible-core (2.1MiB)
2026-02-19 05:51:29.461858 | instance | Downloading pygments (1.2MiB)
2026-02-19 05:51:29.462985 | instance | Downloading cryptography (4.2MiB)
2026-02-19 05:51:29.464174 | instance | Downloading setuptools (1.1MiB)
2026-02-19 05:51:29.464491 | instance | Downloading kubernetes (1.9MiB)
2026-02-19 05:51:29.495662 | instance | Downloading netaddr (2.2MiB)
2026-02-19 05:51:29.534865 | instance | Downloading openstacksdk (1.7MiB)
2026-02-19 05:51:29.762953 | instance |    Building pyperclip==1.9.0
2026-02-19 05:51:29.775989 | instance |  Downloading rjsonnet
2026-02-19 05:51:29.930102 | instance |  Downloading netaddr
2026-02-19 05:51:29.948603 | instance |  Downloading pygments
2026-02-19 05:51:29.980877 | instance |  Downloading cryptography
2026-02-19 05:51:29.998861 | instance |  Downloading setuptools
2026-02-19 05:51:30.050547 | instance |  Downloading kubernetes
2026-02-19 05:51:30.085499 | instance |  Downloading ansible-core
2026-02-19 05:51:30.120462 | instance |  Downloading openstacksdk
2026-02-19 05:51:30.509544 | instance |       Built pyperclip==1.9.0
2026-02-19 05:51:30.705251 | instance |       Built atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere
2026-02-19 05:51:30.747548 | instance | Installed 79 packages in 40ms
2026-02-19 05:51:31.415942 | instance | WARNING  Molecule scenarios should migrate to 'extensions/molecule'
2026-02-19 05:51:32.018220 | instance | INFO     [csi > discovery] scenario test matrix: dependency, cleanup, destroy, syntax, create, prepare, converge, idempotence, side_effect, verify, cleanup, destroy
2026-02-19 05:51:32.018306 | instance | INFO     [csi > prerun] Performing prerun with role_name_check=0...
2026-02-19 05:51:39.685752 | instance | WARNING  Retrying execution failure 1 of: ansible-galaxy collection install -vvv ansible.utils:>=2.9.0
2026-02-19 05:51:39.685862 | instance | ERROR    Command ansible-galaxy collection install -vvv ansible.utils:>=2.9.0, returned 1 code:
2026-02-19 05:51:39.685870 | instance | Starting galaxy collection install process
2026-02-19 05:51:39.685874 | instance | Process install dependency map
2026-02-19 05:51:39.685879 | instance | Starting collection install process
2026-02-19 05:51:39.685887 | instance | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/ansible-utils-6.0.1.tar.gz to /home/zuul/.ansible/tmp/ansible-local-12976fm7yn55/tmp0fbv0oar/ansible-utils-6.0.1-4boz528m
2026-02-19 05:51:39.685900 | instance |
2026-02-19 05:51:39.685905 | instance | ansible-galaxy
2026-02-19 05:51:39.685909 | instance |   config file = None
2026-02-19 05:51:39.685913 | instance |   configured module search path =
2026-02-19 05:51:39.685917 | instance |   ansible python module location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/ansible
2026-02-19 05:51:39.685922 | 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 05:51:39.685927 | instance |   executable location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/ansible-galaxy
2026-02-19 05:51:39.685931 | 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 05:51:39.685935 | instance |   jinja version = 3.1.6
2026-02-19 05:51:39.685939 | instance |   libyaml = True
2026-02-19 05:51:39.685943 | instance | No config file found; using defaults
2026-02-19 05:51:39.685947 | instance | : Collection ansible.netcommon does not support Ansible version
2026-02-19 05:51:39.685952 | instance | 2.17.12
2026-02-19 05:51:39.685956 | instance | Found installed collection ansible.netcommon:1.2.0 at '/home/zuul/.ansible/collections/ansible_collections/ansible/netcommon'
2026-02-19 05:51:39.685960 | instance | Found installed collection ansible.posix:1.6.0 at '/home/zuul/.ansible/collections/ansible_collections/ansible/posix'
2026-02-19 05:51:39.685975 | instance | Opened /home/zuul/.ansible/galaxy_token
2026-02-19 05:51:39.685979 | 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 05:51:39.685984 | instance |
2026-02-19 05:51:39.686809 | instance | Traceback (most recent call last):
2026-02-19 05:51:39.687142 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/molecule", line 10, in <module>
2026-02-19 05:51:39.687654 | instance |     sys.exit(main())
2026-02-19 05:51:39.688024 | 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 05:51:39.688804 | instance |     return self.main(*args, **kwargs)
2026-02-19 05:51:39.689172 | 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 05:51:39.689842 | instance |     rv = self.invoke(ctx)
2026-02-19 05:51:39.690112 | 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 05:51:39.690868 | instance |     return _process_result(sub_ctx.command.invoke(sub_ctx))
2026-02-19 05:51:39.691202 | 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 05:51:39.691884 | instance |     return ctx.invoke(self.callback, **ctx.params)
2026-02-19 05:51:39.692155 | 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 05:51:39.692676 | instance |     return callback(*args, **kwargs)
2026-02-19 05:51:39.692948 | 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 05:51:39.693469 | instance |     return func(*args, **kwargs)
2026-02-19 05:51:39.693763 | 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 05:51:39.694125 | instance |     return f(get_current_context(), *args, **kwargs)
2026-02-19 05:51:39.694398 | 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 05:51:39.694826 | instance |     return func(ctx)
2026-02-19 05:51:39.695093 | 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 05:51:39.695478 | instance |     base.execute_cmdline_scenarios(scenario_name, args, command_args, ansible_args, exclude)
2026-02-19 05:51:39.695770 | 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 05:51:39.696223 | instance |     _run_scenarios(scenarios, command_args, default_config)
2026-02-19 05:51:39.696475 | 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 05:51:39.696671 | instance |     scenario.config.runtime.prepare_environment(
2026-02-19 05:51:39.696795 | 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 05:51:39.697054 | instance |     self.install_collection(
2026-02-19 05:51:39.697184 | 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 05:51:39.697403 | instance |     raise InvalidPrerequisiteError(msg)
2026-02-19 05:51:39.698301 | instance | ansible_compat.errors.InvalidPrerequisiteError: Command ansible-galaxy collection install -vvv ansible.utils:>=2.9.0, returned 1 code:
2026-02-19 05:51:39.698311 | instance | Starting galaxy collection install process
2026-02-19 05:51:39.698320 | instance | Process install dependency map
2026-02-19 05:51:39.698329 | instance | Starting collection install process
2026-02-19 05:51:39.698348 | instance | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/ansible-utils-6.0.1.tar.gz to /home/zuul/.ansible/tmp/ansible-local-12976fm7yn55/tmp0fbv0oar/ansible-utils-6.0.1-4boz528m
2026-02-19 05:51:39.698357 | instance |
2026-02-19 05:51:39.698366 | instance | ansible-galaxy [core 2.17.12]
2026-02-19 05:51:39.698375 | instance |   config file = None
2026-02-19 05:51:39.698384 | 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 05:51:39.698394 | instance |   ansible python module location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/ansible
2026-02-19 05:51:39.698404 | 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 05:51:39.698414 | instance |   executable location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/ansible-galaxy
2026-02-19 05:51:39.698423 | 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 05:51:39.698432 | instance |   jinja version = 3.1.6
2026-02-19 05:51:39.698441 | instance |   libyaml = True
2026-02-19 05:51:39.698449 | instance | No config file found; using defaults
2026-02-19 05:51:39.698458 | instance | [WARNING]: Collection ansible.netcommon does not support Ansible version
2026-02-19 05:51:39.698467 | instance | 2.17.12
2026-02-19 05:51:39.698476 | instance | Found installed collection ansible.netcommon:1.2.0 at '/home/zuul/.ansible/collections/ansible_collections/ansible/netcommon'
2026-02-19 05:51:39.698485 | instance | Found installed collection ansible.posix:1.6.0 at '/home/zuul/.ansible/collections/ansible_collections/ansible/posix'
2026-02-19 05:51:39.698494 | instance | Opened /home/zuul/.ansible/galaxy_token
2026-02-19 05:51:39.698503 | 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 05:51:39.698515 | instance |
2026-02-19 05:51:40.067388 | instance | ERROR
2026-02-19 05:51:40.067740 | instance | {
2026-02-19 05:51:40.067803 | instance |   "delta": "0:00:10.492444",
2026-02-19 05:51:40.067848 | instance |   "end": "2026-02-19 05:51:39.841569",
2026-02-19 05:51:40.067889 | instance |   "msg": "non-zero return code",
2026-02-19 05:51:40.067929 | instance |   "rc": 1,
2026-02-19 05:51:40.067975 | instance |   "start": "2026-02-19 05:51:29.349125"
2026-02-19 05:51:40.068015 | instance | }
failure
2026-02-19 05:51:40.070577 | 
2026-02-19 05:51:40.070617 | PLAY RECAP
2026-02-19 05:51:40.070665 | instance | ok: 2 changed: 2 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0
2026-02-19 05:51:40.070687 | 
2026-02-19 05:51:40.212760 | RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-02-19 05:51:40.216912 | POST-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@stable/2025.1]
2026-02-19 05:51:40.802364 | 
2026-02-19 05:51:40.802507 | PLAY [all]
2026-02-19 05:51:40.816228 | 
2026-02-19 05:51:40.816307 | TASK [gather-host-logs : creating directory for system status]
2026-02-19 05:51:41.156690 | instance | changed
2026-02-19 05:51:41.163277 | 
2026-02-19 05:51:41.163350 | TASK [gather-host-logs : Get logs for each host]
2026-02-19 05:51:41.542503 | instance | + systemd-cgls --full --all --no-pager
2026-02-19 05:51:41.560738 | instance | + ip addr
2026-02-19 05:51:41.562537 | instance | + ip route
2026-02-19 05:51:41.564094 | instance | + lsblk
2026-02-19 05:51:41.566403 | instance | + mount
2026-02-19 05:51:41.567724 | instance | + docker images
2026-02-19 05:51:41.568128 | instance | /bin/bash: line 7: docker: command not found
2026-02-19 05:51:41.568327 | instance | + brctl show
2026-02-19 05:51:41.568676 | instance | /bin/bash: line 8: brctl: command not found
2026-02-19 05:51:41.568867 | instance | + ps aux --sort=-%mem
2026-02-19 05:51:41.580864 | instance | + dpkg -l
2026-02-19 05:51:41.586480 | instance | + CONTAINERS=($(docker ps -a --format '{{ .Names }}' --filter label=zuul))
2026-02-19 05:51:41.598997 | instance | ++ docker ps -a --format '{{ .Names }}' --filter label=zuul
2026-02-19 05:51:41.599020 | instance | /bin/bash: line 11: docker: command not found
2026-02-19 05:51:41.599030 | instance | + '[' '!' -z '' ']'
2026-02-19 05:51:41.696082 | instance | ok: Runtime: 0:00:00.062323
2026-02-19 05:51:41.703899 | 
2026-02-19 05:51:41.704029 | TASK [gather-host-logs : Downloads logs to executor]
2026-02-19 05:51:42.313113 | instance | changed:
2026-02-19 05:51:42.313295 | instance | created directory /var/lib/zuul/builds/900a63b0eb15403e8ae1897ef986bff6/work/logs/instance
2026-02-19 05:51:42.313333 | instance | cd+++++++++ system/
2026-02-19 05:51:42.313363 | instance | >f+++++++++ system/brctl-show.txt
2026-02-19 05:51:42.313391 | instance | >f+++++++++ system/docker-images.txt
2026-02-19 05:51:42.313417 | instance | >f+++++++++ system/ip-addr.txt
2026-02-19 05:51:42.313446 | instance | >f+++++++++ system/ip-route.txt
2026-02-19 05:51:42.313474 | instance | >f+++++++++ system/lsblk.txt
2026-02-19 05:51:42.313501 | instance | >f+++++++++ system/mount.txt
2026-02-19 05:51:42.313530 | instance | >f+++++++++ system/packages.txt
2026-02-19 05:51:42.313556 | instance | >f+++++++++ system/ps.txt
2026-02-19 05:51:42.313582 | instance | >f+++++++++ system/systemd-cgls.txt
2026-02-19 05:51:42.324166 | 
2026-02-19 05:51:42.324228 | LOOP [helm-release-status : creating directory for helm release status]
2026-02-19 05:51:42.520703 | instance | changed: "values"
2026-02-19 05:51:42.681835 | instance | changed: "releases"
2026-02-19 05:51:42.694287 | 
2026-02-19 05:51:42.694359 | TASK [helm-release-status : Gather get release status for helm charts]
2026-02-19 05:51:42.892991 | instance | /bin/bash: line 3: kubectl: command not found
2026-02-19 05:51:43.231498 | instance | ok: Runtime: 0:00:00.006604
2026-02-19 05:51:43.238234 | 
2026-02-19 05:51:43.238307 | TASK [helm-release-status : Downloads logs to executor]
2026-02-19 05:51:43.729232 | instance | changed:
2026-02-19 05:51:43.729428 | instance | cd+++++++++ helm/
2026-02-19 05:51:43.729465 | instance | cd+++++++++ helm/releases/
2026-02-19 05:51:43.729496 | instance | cd+++++++++ helm/values/
2026-02-19 05:51:43.739673 | 
2026-02-19 05:51:43.739740 | TASK [describe-kubernetes-objects : creating directory for cluster scoped objects]
2026-02-19 05:51:43.943367 | instance | changed
2026-02-19 05:51:43.949867 | 
2026-02-19 05:51:43.949933 | TASK [describe-kubernetes-objects : Gathering descriptions for cluster scoped objects]
2026-02-19 05:51:44.149787 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-02-19 05:51:44.149861 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-02-19 05:51:44.154373 | instance | environment: line 1: kubectl: command not found
2026-02-19 05:51:44.155899 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-02-19 05:51:44.156451 | instance | environment: line 1: kubectl: command not found
2026-02-19 05:51:44.157264 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-02-19 05:51:44.159108 | instance | environment: line 1: kubectl: command not found
2026-02-19 05:51:44.160120 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-02-19 05:51:44.160897 | instance | environment: line 1: kubectl: command not found
2026-02-19 05:51:44.161549 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-02-19 05:51:44.162541 | instance | environment: line 1: kubectl: command not found
2026-02-19 05:51:44.163503 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-02-19 05:51:44.485375 | instance | ok: Runtime: 0:00:00.022522
2026-02-19 05:51:44.491926 | 
2026-02-19 05:51:44.491989 | TASK [describe-kubernetes-objects : creating directory for namespace scoped objects]
2026-02-19 05:51:44.689749 | instance | changed
2026-02-19 05:51:44.694733 | 
2026-02-19 05:51:44.694891 | TASK [describe-kubernetes-objects : Gathering descriptions for namespace scoped objects]
2026-02-19 05:51:44.923315 | instance | environment: line 5: kubectl: command not found
2026-02-19 05:51:44.924230 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-02-19 05:51:44.924399 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-02-19 05:51:44.925245 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-02-19 05:51:45.265577 | instance | ok: Runtime: 0:00:00.008168
2026-02-19 05:51:45.272946 | 
2026-02-19 05:51:45.273048 | TASK [describe-kubernetes-objects : Downloads logs to executor]
2026-02-19 05:51:45.755792 | instance | changed:
2026-02-19 05:51:45.756023 | instance | cd+++++++++ objects/
2026-02-19 05:51:45.756061 | instance | cd+++++++++ objects/cluster/
2026-02-19 05:51:45.756089 | instance | cd+++++++++ objects/namespaced/
2026-02-19 05:51:45.767021 | 
2026-02-19 05:51:45.767084 | TASK [gather-pod-logs : creating directory for pod logs]
2026-02-19 05:51:45.953167 | instance | changed
2026-02-19 05:51:45.959489 | 
2026-02-19 05:51:45.959553 | TASK [gather-pod-logs : creating directory for failed pod logs]
2026-02-19 05:51:46.145701 | instance | changed
2026-02-19 05:51:46.150590 | 
2026-02-19 05:51:46.150659 | TASK [gather-pod-logs : retrieve all kubernetes logs, current and previous (if they exist)]
2026-02-19 05:51:46.360084 | instance | environment: line 3: kubectl: command not found
2026-02-19 05:51:46.685274 | instance | ok: Runtime: 0:00:00.008680
2026-02-19 05:51:46.690492 | 
2026-02-19 05:51:46.690558 | TASK [gather-pod-logs : Downloads pod logs to executor]
2026-02-19 05:51:47.172617 | instance | changed:
2026-02-19 05:51:47.172838 | instance | cd+++++++++ pod-logs/
2026-02-19 05:51:47.172877 | instance | cd+++++++++ pod-logs/failed-pods/
2026-02-19 05:51:47.185849 | 
2026-02-19 05:51:47.185927 | TASK [gather-prom-metrics : creating directory for helm release descriptions]
2026-02-19 05:51:47.382072 | instance | changed
2026-02-19 05:51:47.386903 | 
2026-02-19 05:51:47.386966 | TASK [gather-prom-metrics : Get metrics from exporter services in all namespaces]
2026-02-19 05:51:47.581110 | instance | /bin/bash: line 2: kubectl: command not found
2026-02-19 05:51:47.920338 | instance | ok: Runtime: 0:00:00.033856
2026-02-19 05:51:47.927622 | 
2026-02-19 05:51:47.927686 | TASK [gather-prom-metrics : Get ceph metrics from ceph-mgr]
2026-02-19 05:51:48.127679 | instance | /bin/bash: line 2: kubectl: command not found
2026-02-19 05:51:48.156648 | instance | ceph-mgr endpoints:
2026-02-19 05:51:48.465516 | instance | ok: Runtime: 0:00:00.035074
2026-02-19 05:51:48.472423 | 
2026-02-19 05:51:48.472509 | TASK [gather-prom-metrics : Get metrics from fluentd pods]
2026-02-19 05:51:48.673966 | instance | /bin/bash: line 4: kubectl: command not found
2026-02-19 05:51:49.008885 | instance | ok: Runtime: 0:00:00.036997
2026-02-19 05:51:49.015596 | 
2026-02-19 05:51:49.024524 | TASK [gather-prom-metrics : Downloads logs to executor]
2026-02-19 05:51:49.517463 | instance | changed: cd+++++++++ prometheus/
2026-02-19 05:51:49.527954 | 
2026-02-19 05:51:49.528018 | TASK [gather-selenium-data : creating directory for helm release descriptions]
2026-02-19 05:51:49.723674 | instance | changed
2026-02-19 05:51:49.729570 | 
2026-02-19 05:51:49.729632 | TASK [gather-selenium-data : Get selenium data]
2026-02-19 05:51:49.929315 | instance | + cp '/tmp/artifacts/*' /tmp/logs/selenium/.
2026-02-19 05:51:49.930746 | instance | cp: cannot stat '/tmp/artifacts/*': No such file or directory
2026-02-19 05:51:50.262983 | instance | ERROR
2026-02-19 05:51:50.263183 | instance | {
2026-02-19 05:51:50.263214 | instance |   "delta": "0:00:00.006584",
2026-02-19 05:51:50.263235 | instance |   "end": "2026-02-19 05:51:49.931143",
2026-02-19 05:51:50.263254 | instance |   "msg": "non-zero return code",
2026-02-19 05:51:50.263272 | instance |   "rc": 1,
2026-02-19 05:51:50.263291 | instance |   "start": "2026-02-19 05:51:49.924559"
2026-02-19 05:51:50.263309 | instance | }
2026-02-19 05:51:50.263332 | instance | ERROR: Ignoring Errors
2026-02-19 05:51:50.272101 | 
2026-02-19 05:51:50.272167 | TASK [gather-selenium-data : Downloads logs to executor]
2026-02-19 05:51:50.756169 | instance | changed: cd+++++++++ selenium/
2026-02-19 05:51:50.763473 | 
2026-02-19 05:51:50.763519 | PLAY RECAP
2026-02-19 05:51:50.763564 | instance | ok: 23 changed: 23 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 1
2026-02-19 05:51:50.763586 | 
2026-02-19 05:51:50.877291 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@stable/2025.1]
2026-02-19 05:51:50.881894 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-02-19 05:51:51.515696 | 
2026-02-19 05:51:51.515842 | PLAY [all]
2026-02-19 05:51:51.527303 | 
2026-02-19 05:51:51.527375 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-19 05:51:51.571901 | instance | skipping: Conditional result was False
2026-02-19 05:51:51.579140 | 
2026-02-19 05:51:51.579244 | TASK [fetch-output : Set log path for single node]
2026-02-19 05:51:51.622191 | instance | ok
2026-02-19 05:51:51.626622 | 
2026-02-19 05:51:51.626684 | LOOP [fetch-output : Ensure local output dirs]
2026-02-19 05:51:51.987591 | instance -> localhost | ok: "/var/lib/zuul/builds/900a63b0eb15403e8ae1897ef986bff6/work/logs"
2026-02-19 05:51:52.187990 | instance -> localhost | changed: "/var/lib/zuul/builds/900a63b0eb15403e8ae1897ef986bff6/work/artifacts"
2026-02-19 05:51:52.388545 | instance -> localhost | changed: "/var/lib/zuul/builds/900a63b0eb15403e8ae1897ef986bff6/work/docs"
2026-02-19 05:51:52.403308 | 
2026-02-19 05:51:52.403444 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-19 05:51:53.004428 | instance | changed: .d..t...... ./
2026-02-19 05:51:53.004647 | instance | changed: All items complete
2026-02-19 05:51:53.004674 | 
2026-02-19 05:51:53.440723 | instance | changed: .d..t...... ./
2026-02-19 05:51:53.880992 | instance | changed: .d..t...... ./
2026-02-19 05:51:53.904911 | 
2026-02-19 05:51:53.905069 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-02-19 05:51:54.304088 | instance -> localhost | ok: Item: artifacts Runtime: 0:00:00.008253
2026-02-19 05:51:54.513620 | instance -> localhost | ok: Item: docs Runtime: 0:00:00.007256
2026-02-19 05:51:54.527361 | 
2026-02-19 05:51:54.527479 | PLAY [all]
2026-02-19 05:51:54.533321 | 
2026-02-19 05:51:54.533383 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-02-19 05:51:54.937999 | instance | changed
2026-02-19 05:51:54.943601 | 
2026-02-19 05:51:54.943649 | PLAY RECAP
2026-02-19 05:51:54.943693 | instance | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-02-19 05:51:54.943715 | 
2026-02-19 05:51:55.053802 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-02-19 05:51:55.058094 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main]
2026-02-19 05:51:55.625891 | 
2026-02-19 05:51:55.626041 | PLAY [localhost]
2026-02-19 05:51:55.636357 | 
2026-02-19 05:51:55.636439 | TASK [Generate Zuul manifest]
2026-02-19 05:51:55.658214 | localhost | ok
2026-02-19 05:51:55.673508 | 
2026-02-19 05:51:55.673589 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-02-19 05:51:55.992140 | localhost | changed
2026-02-19 05:51:56.003430 | 
2026-02-19 05:51:56.003529 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-02-19 05:51:56.034399 | localhost | ok
2026-02-19 05:51:56.043091 | 
2026-02-19 05:51:56.043163 | TASK [Upload logs]
2026-02-19 05:51:56.078603 | localhost | ok
2026-02-19 05:51:56.138035 | 
2026-02-19 05:51:56.138166 | TASK [Set zuul-log-path fact]
2026-02-19 05:51:56.161968 | localhost | ok
2026-02-19 05:51:56.178347 | 
2026-02-19 05:51:56.178889 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-19 05:51:56.210413 | localhost | ok
2026-02-19 05:51:56.218867 | 
2026-02-19 05:51:56.218929 | TASK [upload-logs : Create log directories]
2026-02-19 05:51:56.605332 | localhost | changed
2026-02-19 05:51:56.612286 | 
2026-02-19 05:51:56.612391 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-02-19 05:51:57.007544 | localhost -> localhost | ok: Runtime: 0:00:00.005799
2026-02-19 05:51:57.013380 | 
2026-02-19 05:51:57.013444 | TASK [upload-logs : Upload logs to log server]
2026-02-19 05:51:57.493796 | localhost | Output suppressed because no_log was given
2026-02-19 05:51:57.499379 | 
2026-02-19 05:51:57.499453 | LOOP [upload-logs : Compress console log and json output]
2026-02-19 05:51:57.557304 | localhost | skipping: Conditional result was False
2026-02-19 05:51:57.564662 | localhost | skipping: Conditional result was False
2026-02-19 05:51:57.572940 | 
2026-02-19 05:51:57.573106 | LOOP [upload-logs : Upload compressed console log and json output]
2026-02-19 05:51:57.612878 | localhost | skipping: Conditional result was False
2026-02-19 05:51:57.613413 | 
2026-02-19 05:51:57.616720 | localhost | skipping: Conditional result was False
2026-02-19 05:51:57.626023 | 
2026-02-19 05:51:57.626164 | LOOP [upload-logs : Upload console log and json output]