2026-05-07 00:39:34.250295 | Job console starting
2026-05-07 00:39:34.270251 | Updating git repos
2026-05-07 00:39:34.434861 | Cloning repos into workspace
2026-05-07 00:39:34.519379 | Restoring repo states
2026-05-07 00:39:34.545782 | Merging changes
2026-05-07 00:39:35.799941 | Checking out repos
2026-05-07 00:39:36.079628 | Preparing playbooks
2026-05-07 00:39:39.618787 | Running Ansible setup
2026-05-07 00:39:43.022820 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-05-07 00:39:43.646787 | 
2026-05-07 00:39:43.646919 | PLAY [localhost]
2026-05-07 00:39:43.654510 | 
2026-05-07 00:39:43.654583 | TASK [Gathering Facts]
2026-05-07 00:39:44.529513 | localhost | ok
2026-05-07 00:39:44.538433 | 
2026-05-07 00:39:44.538543 | TASK [Setup log path fact]
2026-05-07 00:39:44.566549 | localhost | ok
2026-05-07 00:39:44.577609 | 
2026-05-07 00:39:44.577689 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-05-07 00:39:44.608951 | localhost | ok
2026-05-07 00:39:44.624830 | 
2026-05-07 00:39:44.625001 | TASK [emit-job-header : Print job information]
2026-05-07 00:39:44.669628 | # Job Information
2026-05-07 00:39:44.669889 | Ansible Version: 2.16.18
2026-05-07 00:39:44.669965 | Job: atmosphere-molecule-csi-local-path-provisioner
2026-05-07 00:39:44.670017 | Pipeline: check
2026-05-07 00:39:44.670063 | Executor: 2d72f0692154
2026-05-07 00:39:44.670110 | Triggered by: https://github.com/vexxhost/atmosphere/pull/3898
2026-05-07 00:39:44.670163 | Event ID: 217ebd40-49ad-11f1-8e84-fe2343e157d2
2026-05-07 00:39:44.674669 | 
2026-05-07 00:39:44.674738 | LOOP [emit-job-header : Print node information]
2026-05-07 00:39:44.781311 | localhost | ok:
2026-05-07 00:39:44.781531 | localhost | # Node Information
2026-05-07 00:39:44.781559 | localhost | Inventory Hostname: instance
2026-05-07 00:39:44.781580 | localhost | Hostname: np0000172327
2026-05-07 00:39:44.781600 | localhost | Username: zuul
2026-05-07 00:39:44.781621 | localhost | Distro: Ubuntu 22.04
2026-05-07 00:39:44.781640 | localhost | Provider: yul1
2026-05-07 00:39:44.781658 | localhost | Region: ca-ymq-1
2026-05-07 00:39:44.781677 | localhost | Label: ubuntu-jammy
2026-05-07 00:39:44.781695 | localhost | Product Name: OpenStack Nova
2026-05-07 00:39:44.781713 | localhost | Interface IP: 199.204.45.95
2026-05-07 00:39:44.797324 | 
2026-05-07 00:39:44.797494 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-05-07 00:39:45.189081 | localhost -> localhost | changed
2026-05-07 00:39:45.197722 | 
2026-05-07 00:39:45.197857 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-05-07 00:39:46.098498 | localhost -> localhost | changed
2026-05-07 00:39:46.107484 | 
2026-05-07 00:39:46.107604 | PLAY [all]
2026-05-07 00:39:46.119206 | 
2026-05-07 00:39:46.119348 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-05-07 00:39:46.347837 | instance -> localhost | ok
2026-05-07 00:39:46.360077 | 
2026-05-07 00:39:46.360195 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-05-07 00:39:46.393620 | instance | ok
2026-05-07 00:39:46.407937 | instance | included: /var/lib/zuul/builds/1521f6048a2841dba5a6ad8034cf479a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-05-07 00:39:46.414061 | 
2026-05-07 00:39:46.414123 | TASK [add-build-sshkey : Create Temp SSH key]
2026-05-07 00:39:47.690129 | instance -> localhost | Generating public/private rsa key pair.
2026-05-07 00:39:47.690318 | instance -> localhost | Your identification has been saved in /var/lib/zuul/builds/1521f6048a2841dba5a6ad8034cf479a/work/1521f6048a2841dba5a6ad8034cf479a_id_rsa
2026-05-07 00:39:47.690348 | instance -> localhost | Your public key has been saved in /var/lib/zuul/builds/1521f6048a2841dba5a6ad8034cf479a/work/1521f6048a2841dba5a6ad8034cf479a_id_rsa.pub
2026-05-07 00:39:47.690371 | instance -> localhost | The key fingerprint is:
2026-05-07 00:39:47.690393 | instance -> localhost | SHA256:XddQqPWGy6iD0rUhhXM8QMvnAV2P4Xkn0fdhwnBuabg zuul-build-sshkey
2026-05-07 00:39:47.690424 | instance -> localhost | The key's randomart image is:
2026-05-07 00:39:47.690446 | instance -> localhost | +---[RSA 3072]----+
2026-05-07 00:39:47.690473 | instance -> localhost | |       .o. o=.o+.|
2026-05-07 00:39:47.690495 | instance -> localhost | |       ..o..+B+*o|
2026-05-07 00:39:47.690515 | instance -> localhost | |        o+o.=BBo*|
2026-05-07 00:39:47.690535 | instance -> localhost | |        o+=o=o.o+|
2026-05-07 00:39:47.690555 | instance -> localhost | |        S+oE o o |
2026-05-07 00:39:47.690575 | instance -> localhost | |        . o . o  |
2026-05-07 00:39:47.690595 | instance -> localhost | |       . + +     |
2026-05-07 00:39:47.690623 | instance -> localhost | |      . o +      |
2026-05-07 00:39:47.690658 | instance -> localhost | |       .   .     |
2026-05-07 00:39:47.690682 | instance -> localhost | +----[SHA256]-----+
2026-05-07 00:39:47.690735 | instance -> localhost | ok: Runtime: 0:00:00.845868
2026-05-07 00:39:47.695838 | 
2026-05-07 00:39:47.695898 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-05-07 00:39:47.729570 | instance | ok
2026-05-07 00:39:47.738794 | instance | included: /var/lib/zuul/builds/1521f6048a2841dba5a6ad8034cf479a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-05-07 00:39:47.745936 | 
2026-05-07 00:39:47.745995 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-05-07 00:39:47.770213 | instance | skipping: Conditional result was False
2026-05-07 00:39:47.778395 | 
2026-05-07 00:39:47.778480 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-05-07 00:39:48.245761 | instance | changed
2026-05-07 00:39:48.252147 | 
2026-05-07 00:39:48.252211 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-05-07 00:39:48.436026 | instance | ok
2026-05-07 00:39:48.441807 | 
2026-05-07 00:39:48.441879 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-05-07 00:39:48.900498 | instance | changed
2026-05-07 00:39:48.916037 | 
2026-05-07 00:39:48.916166 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-05-07 00:39:49.386782 | instance | changed
2026-05-07 00:39:49.394638 | 
2026-05-07 00:39:49.394751 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-05-07 00:39:49.420306 | instance | skipping: Conditional result was False
2026-05-07 00:39:49.431620 | 
2026-05-07 00:39:49.431723 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-05-07 00:39:49.790660 | instance -> localhost | changed
2026-05-07 00:39:49.805831 | 
2026-05-07 00:39:49.805918 | TASK [add-build-sshkey : Add back temp key]
2026-05-07 00:39:50.109427 | instance -> localhost | Identity added: /var/lib/zuul/builds/1521f6048a2841dba5a6ad8034cf479a/work/1521f6048a2841dba5a6ad8034cf479a_id_rsa (zuul-build-sshkey)
2026-05-07 00:39:50.109670 | instance -> localhost | ok: Runtime: 0:00:00.015933
2026-05-07 00:39:50.116571 | 
2026-05-07 00:39:50.116652 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-05-07 00:39:50.440816 | instance | ok
2026-05-07 00:39:50.452479 | 
2026-05-07 00:39:50.452585 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-05-07 00:39:50.479202 | instance | skipping: Conditional result was False
2026-05-07 00:39:50.490198 | 
2026-05-07 00:39:50.490303 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-05-07 00:39:50.814811 | instance | ok
2026-05-07 00:39:50.824379 | 
2026-05-07 00:39:50.824445 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-05-07 00:39:52.437294 | instance | Output suppressed because no_log was given
2026-05-07 00:39:52.448660 | 
2026-05-07 00:39:52.448722 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-05-07 00:39:52.634951 | instance | ok: "logs"
2026-05-07 00:39:52.635247 | instance | ok: All items complete
2026-05-07 00:39:52.635286 | 
2026-05-07 00:39:52.795976 | instance | ok: "artifacts"
2026-05-07 00:39:52.952162 | instance | ok: "docs"
2026-05-07 00:39:52.971909 | 
2026-05-07 00:39:52.972141 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-05-07 00:39:53.155688 | instance | changed: "logs"
2026-05-07 00:39:53.313662 | instance | changed: "artifacts"
2026-05-07 00:39:53.466663 | instance | changed: "docs"
2026-05-07 00:39:53.485493 | 
2026-05-07 00:39:53.485638 | PLAY RECAP
2026-05-07 00:39:53.485690 | instance | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2026-05-07 00:39:53.485719 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-05-07 00:39:53.485741 | 
2026-05-07 00:39:53.659336 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-05-07 00:39:53.663464 | PRE-RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-05-07 00:39:54.289074 | 
2026-05-07 00:39:54.289251 | PLAY [all]
2026-05-07 00:39:54.302896 | 
2026-05-07 00:39:54.303099 | TASK [setup-uv : Extract archive]
2026-05-07 00:39:56.491174 | instance | changed
2026-05-07 00:39:56.498107 | 
2026-05-07 00:39:56.498189 | TASK [setup-uv : Print version]
2026-05-07 00:39:55.736118 | instance | uv 0.8.13
2026-05-07 00:39:57.035400 | instance | ok: Runtime: 0:00:00.013234
2026-05-07 00:39:57.042413 | 
2026-05-07 00:39:57.042465 | PLAY RECAP
2026-05-07 00:39:57.042515 | instance | ok: 2 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-05-07 00:39:57.042539 | 
2026-05-07 00:39:57.166612 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-05-07 00:39:57.170265 | PRE-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@stable/2023.1]
2026-05-07 00:39:57.778063 | 
2026-05-07 00:39:57.778188 | PLAY [all]
2026-05-07 00:39:57.789471 | 
2026-05-07 00:39:57.789556 | TASK [Install "jq" for log collection]
2026-05-07 00:40:08.991144 | instance | changed
2026-05-07 00:40:08.993758 | 
2026-05-07 00:40:08.993846 | PLAY RECAP
2026-05-07 00:40:08.993918 | instance | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-05-07 00:40:08.993990 | 
2026-05-07 00:40:09.131306 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@stable/2023.1]
2026-05-07 00:40:09.136085 | RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-05-07 00:40:09.747115 | 
2026-05-07 00:40:09.747261 | PLAY [all]
2026-05-07 00:40:09.758681 | 
2026-05-07 00:40:09.758773 | TASK [Copy inventory file for Zuul]
2026-05-07 00:40:10.604049 | instance | changed
2026-05-07 00:40:10.613107 | 
2026-05-07 00:40:10.613195 | TASK [Switch "ansible_host" to private IP]
2026-05-07 00:40:10.939364 | instance | changed: 1 replacements made
2026-05-07 00:40:10.946653 | 
2026-05-07 00:40:10.946749 | TASK [Run Molecule scenario]
2026-05-07 00:40:11.341620 | instance | Using CPython 3.10.12 interpreter at: /usr/bin/python3
2026-05-07 00:40:11.341850 | instance | Creating virtual environment at: .venv
2026-05-07 00:40:11.370437 | instance |    Building atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere
2026-05-07 00:40:11.398955 | instance | Downloading openstacksdk (1.7MiB)
2026-05-07 00:40:11.399864 | instance | Downloading cryptography (4.2MiB)
2026-05-07 00:40:11.400096 | instance | Downloading rjsonnet (1.2MiB)
2026-05-07 00:40:11.401639 | instance | Downloading ansible-core (2.1MiB)
2026-05-07 00:40:11.402302 | instance | Downloading setuptools (1.1MiB)
2026-05-07 00:40:11.404565 | instance | Downloading kubernetes (1.9MiB)
2026-05-07 00:40:11.416405 | instance | Downloading pygments (1.2MiB)
2026-05-07 00:40:11.417466 | instance | Downloading netaddr (2.2MiB)
2026-05-07 00:40:11.704742 | instance |    Building pyperclip==1.9.0
2026-05-07 00:40:11.710394 | instance |  Downloading rjsonnet
2026-05-07 00:40:11.850106 | instance |  Downloading netaddr
2026-05-07 00:40:11.862764 | instance |  Downloading pygments
2026-05-07 00:40:11.880049 | instance |  Downloading cryptography
2026-05-07 00:40:11.912071 | instance |  Downloading setuptools
2026-05-07 00:40:11.964914 | instance |  Downloading kubernetes
2026-05-07 00:40:11.999524 | instance |  Downloading ansible-core
2026-05-07 00:40:12.029743 | instance |  Downloading openstacksdk
2026-05-07 00:40:12.424898 | instance |       Built pyperclip==1.9.0
2026-05-07 00:40:12.582811 | instance |       Built atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere
2026-05-07 00:40:12.621888 | instance | Installed 79 packages in 37ms
2026-05-07 00:40:13.257017 | instance | WARNING  Molecule scenarios should migrate to 'extensions/molecule'
2026-05-07 00:40:13.852870 | instance | INFO     [csi > discovery] scenario test matrix: dependency, cleanup, destroy, syntax, create, prepare, converge, idempotence, side_effect, verify, cleanup, destroy
2026-05-07 00:40:13.852963 | instance | INFO     [csi > prerun] Performing prerun with role_name_check=0...
2026-05-07 00:40:38.391487 | instance | WARNING  Retrying execution failure 1 of: ansible-galaxy collection install -vvv atmosphere.common:>=0.6.0
2026-05-07 00:40:38.391637 | instance | ERROR    Command ansible-galaxy collection install -vvv atmosphere.common:>=0.6.0, returned 1 code:
2026-05-07 00:40:38.391644 | instance | Starting galaxy collection install process
2026-05-07 00:40:38.391649 | instance | Process install dependency map
2026-05-07 00:40:38.391654 | instance | Starting collection install process
2026-05-07 00:40:38.391669 | instance | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/atmosphere-common-0.6.0.tar.gz to /home/zuul/.ansible/tmp/ansible-local-1295h942zdty/tmpn0fnpw8m/atmosphere-common-0.6.0-4shdxdok
2026-05-07 00:40:38.391674 | instance |
2026-05-07 00:40:38.391678 | instance | ansible-galaxy
2026-05-07 00:40:38.391683 | instance |   config file = None
2026-05-07 00:40:38.391687 | instance |   configured module search path =
2026-05-07 00:40:38.391691 | instance |   ansible python module location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/ansible
2026-05-07 00:40:38.391697 | 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-07 00:40:38.391703 | instance |   executable location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/ansible-galaxy
2026-05-07 00:40:38.391707 | 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-07 00:40:38.391711 | instance |   jinja version = 3.1.6
2026-05-07 00:40:38.391716 | instance |   libyaml = True
2026-05-07 00:40:38.391720 | instance | No config file found; using defaults
2026-05-07 00:40:38.391724 | instance | Found installed collection ansible.posix:1.6.0 at '/home/zuul/.ansible/collections/ansible_collections/ansible/posix'
2026-05-07 00:40:38.391729 | instance | Found installed collection community.mysql:3.6.0 at '/home/zuul/.ansible/collections/ansible_collections/community/mysql'
2026-05-07 00:40:38.391733 | instance | Found installed collection community.general:7.3.0 at '/home/zuul/.ansible/collections/ansible_collections/community/general'
2026-05-07 00:40:38.391762 | instance | Found installed collection openstack.cloud:1.7.0 at '/home/zuul/.ansible/collections/ansible_collections/openstack/cloud'
2026-05-07 00:40:38.391766 | instance | Found installed collection kubernetes.core:2.4.0 at '/home/zuul/.ansible/collections/ansible_collections/kubernetes/core'
2026-05-07 00:40:38.391770 | instance | Found installed collection community.crypto:2.2.3 at '/home/zuul/.ansible/collections/ansible_collections/community/crypto'
2026-05-07 00:40:38.391774 | instance | Found installed collection ansible.utils:6.0.2 at '/home/zuul/.ansible/collections/ansible_collections/ansible/utils'
2026-05-07 00:40:38.391779 | instance | : Collection ansible.netcommon does not support Ansible version
2026-05-07 00:40:38.391783 | instance | 2.17.12
2026-05-07 00:40:38.391787 | instance | Found installed collection ansible.netcommon:1.2.0 at '/home/zuul/.ansible/collections/ansible_collections/ansible/netcommon'
2026-05-07 00:40:38.391791 | instance | Opened /home/zuul/.ansible/galaxy_token
2026-05-07 00:40:38.391796 | instance | ERROR! Failed to download collection tar from 'default' due to the following unforeseen error: HTTP Error 503: Service Unavailable. HTTP Error 503: Service Unavailable
2026-05-07 00:40:38.391801 | instance |
2026-05-07 00:40:38.392248 | instance | Traceback (most recent call last):
2026-05-07 00:40:38.392549 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/molecule", line 10, in <module>
2026-05-07 00:40:38.393030 | instance |     sys.exit(main())
2026-05-07 00:40:38.393307 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 1442, in __call__
2026-05-07 00:40:38.394137 | instance |     return self.main(*args, **kwargs)
2026-05-07 00:40:38.394375 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 1363, in main
2026-05-07 00:40:38.394834 | instance |     rv = self.invoke(ctx)
2026-05-07 00:40:38.395012 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 1830, in invoke
2026-05-07 00:40:38.395538 | instance |     return _process_result(sub_ctx.command.invoke(sub_ctx))
2026-05-07 00:40:38.395717 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 1226, in invoke
2026-05-07 00:40:38.396171 | instance |     return ctx.invoke(self.callback, **ctx.params)
2026-05-07 00:40:38.396334 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 794, in invoke
2026-05-07 00:40:38.396691 | instance |     return callback(*args, **kwargs)
2026-05-07 00:40:38.396859 | 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-07 00:40:38.397163 | instance |     return func(*args, **kwargs)
2026-05-07 00:40:38.397339 | 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-07 00:40:38.397550 | instance |     return f(get_current_context(), *args, **kwargs)
2026-05-07 00:40:38.397734 | 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-07 00:40:38.398048 | instance |     return func(ctx)
2026-05-07 00:40:38.398220 | 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-07 00:40:38.398480 | instance |     base.execute_cmdline_scenarios(scenario_name, args, command_args, ansible_args, exclude)
2026-05-07 00:40:38.398684 | 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-07 00:40:38.398970 | instance |     _run_scenarios(scenarios, command_args, default_config)
2026-05-07 00:40:38.399180 | 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-07 00:40:38.399467 | instance |     scenario.config.runtime.prepare_environment(
2026-05-07 00:40:38.399642 | 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-07 00:40:38.399964 | instance |     self.install_collection(
2026-05-07 00:40:38.400133 | 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-07 00:40:38.400478 | instance |     raise InvalidPrerequisiteError(msg)
2026-05-07 00:40:38.401752 | instance | ansible_compat.errors.InvalidPrerequisiteError: Command ansible-galaxy collection install -vvv atmosphere.common:>=0.6.0, returned 1 code:
2026-05-07 00:40:38.401758 | instance | Starting galaxy collection install process
2026-05-07 00:40:38.401762 | instance | Process install dependency map
2026-05-07 00:40:38.401766 | instance | Starting collection install process
2026-05-07 00:40:38.401770 | instance | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/atmosphere-common-0.6.0.tar.gz to /home/zuul/.ansible/tmp/ansible-local-1295h942zdty/tmpn0fnpw8m/atmosphere-common-0.6.0-4shdxdok
2026-05-07 00:40:38.401774 | instance |
2026-05-07 00:40:38.401778 | instance | ansible-galaxy [core 2.17.12]
2026-05-07 00:40:38.401782 | instance |   config file = None
2026-05-07 00:40:38.401786 | instance |   configured module search path = ['/home/zuul/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
2026-05-07 00:40:38.401790 | instance |   ansible python module location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/ansible
2026-05-07 00:40:38.401794 | 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-07 00:40:38.401799 | instance |   executable location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/ansible-galaxy
2026-05-07 00:40:38.401803 | 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-07 00:40:38.401807 | instance |   jinja version = 3.1.6
2026-05-07 00:40:38.401811 | instance |   libyaml = True
2026-05-07 00:40:38.401815 | instance | No config file found; using defaults
2026-05-07 00:40:38.401818 | instance | Found installed collection ansible.posix:1.6.0 at '/home/zuul/.ansible/collections/ansible_collections/ansible/posix'
2026-05-07 00:40:38.401822 | instance | Found installed collection community.mysql:3.6.0 at '/home/zuul/.ansible/collections/ansible_collections/community/mysql'
2026-05-07 00:40:38.401826 | instance | Found installed collection community.general:7.3.0 at '/home/zuul/.ansible/collections/ansible_collections/community/general'
2026-05-07 00:40:38.401830 | instance | Found installed collection openstack.cloud:1.7.0 at '/home/zuul/.ansible/collections/ansible_collections/openstack/cloud'
2026-05-07 00:40:38.401834 | instance | Found installed collection kubernetes.core:2.4.0 at '/home/zuul/.ansible/collections/ansible_collections/kubernetes/core'
2026-05-07 00:40:38.401841 | instance | Found installed collection community.crypto:2.2.3 at '/home/zuul/.ansible/collections/ansible_collections/community/crypto'
2026-05-07 00:40:38.401846 | instance | Found installed collection ansible.utils:6.0.2 at '/home/zuul/.ansible/collections/ansible_collections/ansible/utils'
2026-05-07 00:40:38.401850 | instance | [WARNING]: Collection ansible.netcommon does not support Ansible version
2026-05-07 00:40:38.401854 | instance | 2.17.12
2026-05-07 00:40:38.401858 | instance | Found installed collection ansible.netcommon:1.2.0 at '/home/zuul/.ansible/collections/ansible_collections/ansible/netcommon'
2026-05-07 00:40:38.401862 | instance | Opened /home/zuul/.ansible/galaxy_token
2026-05-07 00:40:38.401866 | instance | ERROR! Failed to download collection tar from 'default' due to the following unforeseen error: HTTP Error 503: Service Unavailable. HTTP Error 503: Service Unavailable
2026-05-07 00:40:38.401931 | instance |
2026-05-07 00:40:38.524567 | instance | ERROR
2026-05-07 00:40:38.524803 | instance | {
2026-05-07 00:40:38.524837 | instance |   "delta": "0:00:27.206275",
2026-05-07 00:40:38.524859 | instance |   "end": "2026-05-07 00:40:38.483532",
2026-05-07 00:40:38.524880 | instance |   "msg": "non-zero return code",
2026-05-07 00:40:38.524899 | instance |   "rc": 1,
2026-05-07 00:40:38.524922 | instance |   "start": "2026-05-07 00:40:11.277257"
2026-05-07 00:40:38.524940 | instance | }
failure
2026-05-07 00:40:38.528076 | 
2026-05-07 00:40:38.528143 | PLAY RECAP
2026-05-07 00:40:38.528204 | instance | ok: 2 changed: 2 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0
2026-05-07 00:40:38.528236 | 
2026-05-07 00:40:38.684000 | RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-05-07 00:40:38.687960 | POST-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@stable/2023.1]
2026-05-07 00:40:39.333758 | 
2026-05-07 00:40:39.333910 | PLAY [all]
2026-05-07 00:40:39.348718 | 
2026-05-07 00:40:39.348835 | TASK [gather-host-logs : creating directory for system status]
2026-05-07 00:40:39.704384 | instance | changed
2026-05-07 00:40:39.712029 | 
2026-05-07 00:40:39.712141 | TASK [gather-host-logs : Get logs for each host]
2026-05-07 00:40:40.057293 | instance | + systemd-cgls --full --all --no-pager
2026-05-07 00:40:40.069521 | instance | + ip addr
2026-05-07 00:40:40.070727 | instance | + ip route
2026-05-07 00:40:40.071784 | instance | + lsblk
2026-05-07 00:40:40.073773 | instance | + mount
2026-05-07 00:40:40.074927 | instance | + docker images
2026-05-07 00:40:40.075216 | instance | /bin/bash: line 7: docker: command not found
2026-05-07 00:40:40.075357 | instance | + brctl show
2026-05-07 00:40:40.075594 | instance | /bin/bash: line 8: brctl: command not found
2026-05-07 00:40:40.075710 | instance | + ps aux --sort=-%mem
2026-05-07 00:40:40.085343 | instance | + dpkg -l
2026-05-07 00:40:40.090940 | instance | + CONTAINERS=($(docker ps -a --format '{{ .Names }}' --filter label=zuul))
2026-05-07 00:40:40.091198 | instance | ++ docker ps -a --format '{{ .Names }}' --filter label=zuul
2026-05-07 00:40:40.091216 | instance | /bin/bash: line 11: docker: command not found
2026-05-07 00:40:40.091421 | instance | + '[' '!' -z '' ']'
2026-05-07 00:40:40.248040 | instance | ok: Runtime: 0:00:00.039254
2026-05-07 00:40:40.256847 | 
2026-05-07 00:40:40.256919 | TASK [gather-host-logs : Downloads logs to executor]
2026-05-07 00:40:40.944633 | instance | changed:
2026-05-07 00:40:40.944811 | instance | created directory /var/lib/zuul/builds/1521f6048a2841dba5a6ad8034cf479a/work/logs/instance
2026-05-07 00:40:40.944839 | instance | cd+++++++++ system/
2026-05-07 00:40:40.944860 | instance | >f+++++++++ system/brctl-show.txt
2026-05-07 00:40:40.944881 | instance | >f+++++++++ system/docker-images.txt
2026-05-07 00:40:40.944900 | instance | >f+++++++++ system/ip-addr.txt
2026-05-07 00:40:40.944922 | instance | >f+++++++++ system/ip-route.txt
2026-05-07 00:40:40.944943 | instance | >f+++++++++ system/lsblk.txt
2026-05-07 00:40:40.944978 | instance | >f+++++++++ system/mount.txt
2026-05-07 00:40:40.945190 | instance | >f+++++++++ system/packages.txt
2026-05-07 00:40:40.945210 | instance | >f+++++++++ system/ps.txt
2026-05-07 00:40:40.945228 | instance | >f+++++++++ system/systemd-cgls.txt
2026-05-07 00:40:40.955074 | 
2026-05-07 00:40:40.955139 | LOOP [helm-release-status : creating directory for helm release status]
2026-05-07 00:40:41.145871 | instance | changed: "values"
2026-05-07 00:40:41.311260 | instance | changed: "releases"
2026-05-07 00:40:41.326470 | 
2026-05-07 00:40:41.391280 | TASK [helm-release-status : Gather get release status for helm charts]
2026-05-07 00:40:41.618627 | instance | /bin/bash: line 3: kubectl: command not found
2026-05-07 00:40:41.935692 | instance | ok: Runtime: 0:00:00.004790
2026-05-07 00:40:41.943086 | 
2026-05-07 00:40:41.943183 | TASK [helm-release-status : Downloads logs to executor]
2026-05-07 00:40:42.443517 | instance | changed:
2026-05-07 00:40:42.443729 | instance | cd+++++++++ helm/
2026-05-07 00:40:42.443771 | instance | cd+++++++++ helm/releases/
2026-05-07 00:40:42.443805 | instance | cd+++++++++ helm/values/
2026-05-07 00:40:42.457110 | 
2026-05-07 00:40:42.457218 | TASK [describe-kubernetes-objects : creating directory for cluster scoped objects]
2026-05-07 00:40:42.652286 | instance | changed
2026-05-07 00:40:42.658901 | 
2026-05-07 00:40:42.658997 | TASK [describe-kubernetes-objects : Gathering descriptions for cluster scoped objects]
2026-05-07 00:40:42.873528 | instance | xargs: xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args valuewarning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-05-07 00:40:42.873633 | instance |
2026-05-07 00:40:42.879367 | instance | environment: line 1: kubectl: command not found
2026-05-07 00:40:42.880499 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-05-07 00:40:42.881836 | instance | environment: line 1: kubectl: command not found
2026-05-07 00:40:42.883333 | instance | environment: line 1: kubectl: command not found
2026-05-07 00:40:42.883672 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-05-07 00:40:42.884792 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-05-07 00:40:42.887205 | instance | environment: line 1: kubectl: command not found
2026-05-07 00:40:42.887883 | instance | environment: line 1: kubectl: command not found
2026-05-07 00:40:42.888793 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-05-07 00:40:42.889288 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-05-07 00:40:43.196745 | instance | ok: Runtime: 0:00:00.026116
2026-05-07 00:40:43.238481 | 
2026-05-07 00:40:43.238633 | TASK [describe-kubernetes-objects : creating directory for namespace scoped objects]
2026-05-07 00:40:43.444774 | instance | changed
2026-05-07 00:40:43.452442 | 
2026-05-07 00:40:43.452555 | TASK [describe-kubernetes-objects : Gathering descriptions for namespace scoped objects]
2026-05-07 00:40:43.660082 | instance | environment: line 5: kubectl: command not found
2026-05-07 00:40:43.660507 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-05-07 00:40:43.661227 | instance | xargs: xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args valuewarning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-05-07 00:40:43.661259 | instance |
2026-05-07 00:40:43.990947 | instance | ok: Runtime: 0:00:00.009947
2026-05-07 00:40:43.998094 | 
2026-05-07 00:40:43.998182 | TASK [describe-kubernetes-objects : Downloads logs to executor]
2026-05-07 00:40:44.487427 | instance | changed:
2026-05-07 00:40:44.487689 | instance | cd+++++++++ objects/
2026-05-07 00:40:44.487749 | instance | cd+++++++++ objects/cluster/
2026-05-07 00:40:44.487796 | instance | cd+++++++++ objects/namespaced/
2026-05-07 00:40:44.497699 | 
2026-05-07 00:40:44.497762 | TASK [gather-pod-logs : creating directory for pod logs]
2026-05-07 00:40:44.708327 | instance | changed
2026-05-07 00:40:44.713432 | 
2026-05-07 00:40:44.713537 | TASK [gather-pod-logs : creating directory for failed pod logs]
2026-05-07 00:40:44.910119 | instance | changed
2026-05-07 00:40:44.917066 | 
2026-05-07 00:40:44.917158 | TASK [gather-pod-logs : retrieve all kubernetes logs, current and previous (if they exist)]
2026-05-07 00:40:45.140063 | instance | environment: line 3: kubectl: command not found
2026-05-07 00:40:45.452521 | instance | ok: Runtime: 0:00:00.009638
2026-05-07 00:40:45.458769 | 
2026-05-07 00:40:45.458842 | TASK [gather-pod-logs : Downloads pod logs to executor]
2026-05-07 00:40:45.969286 | instance | changed:
2026-05-07 00:40:45.969519 | instance | cd+++++++++ pod-logs/
2026-05-07 00:40:45.969558 | instance | cd+++++++++ pod-logs/failed-pods/
2026-05-07 00:40:45.981770 | 
2026-05-07 00:40:45.981833 | TASK [gather-prom-metrics : creating directory for helm release descriptions]
2026-05-07 00:40:46.187163 | instance | changed
2026-05-07 00:40:46.196143 | 
2026-05-07 00:40:46.196225 | TASK [gather-prom-metrics : Get metrics from exporter services in all namespaces]
2026-05-07 00:40:46.410767 | instance | /bin/bash: line 2: kubectl: command not found
2026-05-07 00:40:46.731267 | instance | ok: Runtime: 0:00:00.040197
2026-05-07 00:40:46.737528 | 
2026-05-07 00:40:46.737596 | TASK [gather-prom-metrics : Get ceph metrics from ceph-mgr]
2026-05-07 00:40:46.947443 | instance | /bin/bash: line 2: kubectl: command not found
2026-05-07 00:40:46.975767 | instance | ceph-mgr endpoints:
2026-05-07 00:40:47.273255 | instance | ok: Runtime: 0:00:00.035457
2026-05-07 00:40:47.281080 | 
2026-05-07 00:40:47.281224 | TASK [gather-prom-metrics : Get metrics from fluentd pods]
2026-05-07 00:40:47.497585 | instance | /bin/bash: line 4: kubectl: command not found
2026-05-07 00:40:47.820735 | instance | ok: Runtime: 0:00:00.036848
2026-05-07 00:40:47.828233 | 
2026-05-07 00:40:47.828303 | TASK [gather-prom-metrics : Downloads logs to executor]
2026-05-07 00:40:48.316113 | instance | changed: cd+++++++++ prometheus/
2026-05-07 00:40:48.325414 | 
2026-05-07 00:40:48.325477 | TASK [gather-selenium-data : creating directory for helm release descriptions]
2026-05-07 00:40:48.562432 | instance | changed
2026-05-07 00:40:48.568167 | 
2026-05-07 00:40:48.568233 | TASK [gather-selenium-data : Get selenium data]
2026-05-07 00:40:48.839052 | instance | + cp '/tmp/artifacts/*' /tmp/logs/selenium/.
2026-05-07 00:40:48.840605 | instance | cp: cannot stat '/tmp/artifacts/*': No such file or directory
2026-05-07 00:40:49.147070 | instance | ERROR
2026-05-07 00:40:49.147326 | instance | {
2026-05-07 00:40:49.147358 | instance |   "delta": "0:00:00.005665",
2026-05-07 00:40:49.147382 | instance |   "end": "2026-05-07 00:40:48.840959",
2026-05-07 00:40:49.147402 | instance |   "msg": "non-zero return code",
2026-05-07 00:40:49.147421 | instance |   "rc": 1,
2026-05-07 00:40:49.147439 | instance |   "start": "2026-05-07 00:40:48.835294"
2026-05-07 00:40:49.147458 | instance | }
2026-05-07 00:40:49.147485 | instance | ERROR: Ignoring Errors
2026-05-07 00:40:49.152484 | 
2026-05-07 00:40:49.152549 | TASK [gather-selenium-data : Downloads logs to executor]
2026-05-07 00:40:49.672404 | instance | changed: cd+++++++++ selenium/
2026-05-07 00:40:49.680060 | 
2026-05-07 00:40:49.680112 | PLAY RECAP
2026-05-07 00:40:49.680165 | instance | ok: 23 changed: 23 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 1
2026-05-07 00:40:49.680186 | 
2026-05-07 00:40:49.807256 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@stable/2023.1]
2026-05-07 00:40:49.809462 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-05-07 00:40:50.453714 | 
2026-05-07 00:40:50.453836 | PLAY [all]
2026-05-07 00:40:50.464903 | 
2026-05-07 00:40:50.465006 | TASK [fetch-output : Set log path for multiple nodes]
2026-05-07 00:40:50.509947 | instance | skipping: Conditional result was False
2026-05-07 00:40:50.520629 | 
2026-05-07 00:40:50.520715 | TASK [fetch-output : Set log path for single node]
2026-05-07 00:40:50.563435 | instance | ok
2026-05-07 00:40:50.568603 | 
2026-05-07 00:40:50.568685 | LOOP [fetch-output : Ensure local output dirs]
2026-05-07 00:40:51.024527 | instance -> localhost | ok: "/var/lib/zuul/builds/1521f6048a2841dba5a6ad8034cf479a/work/logs"
2026-05-07 00:40:51.253682 | instance -> localhost | changed: "/var/lib/zuul/builds/1521f6048a2841dba5a6ad8034cf479a/work/artifacts"
2026-05-07 00:40:51.460796 | instance -> localhost | changed: "/var/lib/zuul/builds/1521f6048a2841dba5a6ad8034cf479a/work/docs"
2026-05-07 00:40:51.477244 | 
2026-05-07 00:40:51.477358 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-05-07 00:40:52.147558 | instance | changed: .d..t...... ./
2026-05-07 00:40:52.147769 | instance | changed: All items complete
2026-05-07 00:40:52.147797 | 
2026-05-07 00:40:52.636283 | instance | changed: .d..t...... ./
2026-05-07 00:40:53.127542 | instance | changed: .d..t...... ./
2026-05-07 00:40:53.151581 | 
2026-05-07 00:40:53.151743 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-05-07 00:40:53.583465 | instance -> localhost | ok: Item: artifacts Runtime: 0:00:00.007774
2026-05-07 00:40:53.809008 | instance -> localhost | ok: Item: docs Runtime: 0:00:00.008617
2026-05-07 00:40:53.826411 | 
2026-05-07 00:40:53.826561 | PLAY [all]
2026-05-07 00:40:53.833157 | 
2026-05-07 00:40:53.833223 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-05-07 00:40:54.270922 | instance | changed
2026-05-07 00:40:54.277170 | 
2026-05-07 00:40:54.277230 | PLAY RECAP
2026-05-07 00:40:54.277276 | instance | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-05-07 00:40:54.277301 | 
2026-05-07 00:40:54.477545 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-05-07 00:40:54.481977 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main]
2026-05-07 00:40:55.084429 | 
2026-05-07 00:40:55.191700 | PLAY [localhost]
2026-05-07 00:40:55.208755 | 
2026-05-07 00:40:55.208859 | TASK [Generate Zuul manifest]
2026-05-07 00:40:55.231999 | localhost | ok
2026-05-07 00:40:55.249216 | 
2026-05-07 00:40:55.249310 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-05-07 00:40:55.890412 | localhost | changed
2026-05-07 00:40:55.905252 | 
2026-05-07 00:40:55.905411 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-05-07 00:40:55.967627 | localhost | ok
2026-05-07 00:40:55.974386 | 
2026-05-07 00:40:55.974481 | TASK [Upload logs]
2026-05-07 00:40:55.995460 | localhost | ok
2026-05-07 00:40:56.055095 | 
2026-05-07 00:40:56.055233 | TASK [Set zuul-log-path fact]
2026-05-07 00:40:56.076772 | localhost | ok
2026-05-07 00:40:56.090671 | 
2026-05-07 00:40:56.090756 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-05-07 00:40:56.123509 | localhost | ok
2026-05-07 00:40:56.132831 | 
2026-05-07 00:40:56.132920 | TASK [upload-logs : Create log directories]
2026-05-07 00:40:56.569372 | localhost | changed
2026-05-07 00:40:56.575415 | 
2026-05-07 00:40:56.575486 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-05-07 00:40:57.123232 | localhost -> localhost | ok: Runtime: 0:00:00.005736
2026-05-07 00:40:57.128897 | 
2026-05-07 00:40:57.128992 | TASK [upload-logs : Upload logs to log server]
2026-05-07 00:40:58.050535 | localhost | Output suppressed because no_log was given
2026-05-07 00:40:58.055578 | 
2026-05-07 00:40:58.055669 | LOOP [upload-logs : Compress console log and json output]
2026-05-07 00:40:58.148476 | localhost | skipping: Conditional result was False
2026-05-07 00:40:58.156412 | localhost | skipping: Conditional result was False
2026-05-07 00:40:58.172589 | 
2026-05-07 00:40:58.172920 | LOOP [upload-logs : Upload compressed console log and json output]
2026-05-07 00:40:58.260673 | localhost | skipping: Conditional result was False
2026-05-07 00:40:58.261067 | 
2026-05-07 00:40:58.265848 | localhost | skipping: Conditional result was False
2026-05-07 00:40:58.329349 | 
2026-05-07 00:40:58.329528 | LOOP [upload-logs : Upload console log and json output]