2026-01-26 08:41:33.948210 | Job console starting
2026-01-26 08:41:33.957414 | Updating git repos
2026-01-26 08:41:34.019146 | Cloning repos into workspace
2026-01-26 08:41:34.154545 | Restoring repo states
2026-01-26 08:41:34.179108 | Merging changes
2026-01-26 08:41:35.193537 | Checking out repos
2026-01-26 08:41:35.321572 | Preparing playbooks
2026-01-26 08:41:37.846335 | Running Ansible setup
2026-01-26 08:41:41.138536 | PRE-RUN START: [trusted : vexxhost.dev/zuul-config/playbooks/base/pre.yaml@main]
2026-01-26 08:41:41.737820 | 
2026-01-26 08:41:41.737967 | PLAY [localhost]
2026-01-26 08:41:41.746800 | 
2026-01-26 08:41:41.746874 | TASK [Gathering Facts]
2026-01-26 08:41:42.656655 | localhost | ok
2026-01-26 08:41:42.668195 | 
2026-01-26 08:41:42.668298 | TASK [Setup log path fact]
2026-01-26 08:41:42.689900 | localhost | ok
2026-01-26 08:41:42.703555 | 
2026-01-26 08:41:42.703621 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-26 08:41:42.732980 | localhost | ok
2026-01-26 08:41:42.743992 | 
2026-01-26 08:41:42.744055 | TASK [emit-job-header : Print job information]
2026-01-26 08:41:42.784421 | # Job Information
2026-01-26 08:41:42.784605 | Ansible Version: 2.16.15
2026-01-26 08:41:42.784649 | Job: atmosphere-molecule-csi-local-path-provisioner
2026-01-26 08:41:42.784678 | Pipeline: check
2026-01-26 08:41:42.784705 | Executor: 3a2793d2bd32
2026-01-26 08:41:42.784732 | Triggered by: https://github.com/vexxhost/atmosphere/pull/3468
2026-01-26 08:41:42.784764 | Event ID: b3a1cce0-fa92-11f0-8f20-7bd548aca8ba
2026-01-26 08:41:42.788543 | 
2026-01-26 08:41:42.788634 | LOOP [emit-job-header : Print node information]
2026-01-26 08:41:42.894455 | localhost | ok:
2026-01-26 08:41:42.895382 | localhost | # Node Information
2026-01-26 08:41:42.895424 | localhost | Inventory Hostname: instance
2026-01-26 08:41:42.895455 | localhost | Hostname: np0000154466
2026-01-26 08:41:42.895483 | localhost | Username: zuul
2026-01-26 08:41:42.895514 | localhost | Distro: Ubuntu 22.04
2026-01-26 08:41:42.895542 | localhost | Provider: yul1
2026-01-26 08:41:42.895570 | localhost | Region: ca-ymq-1
2026-01-26 08:41:42.895596 | localhost | Label: ubuntu-jammy
2026-01-26 08:41:42.895623 | localhost | Product Name: OpenStack Nova
2026-01-26 08:41:42.895650 | localhost | Interface IP: 162.253.55.227
2026-01-26 08:41:42.909355 | 
2026-01-26 08:41:42.909542 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-26 08:41:43.329995 | localhost -> localhost | changed
2026-01-26 08:41:43.336777 | 
2026-01-26 08:41:43.336871 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-26 08:41:44.224217 | localhost -> localhost | changed
2026-01-26 08:41:44.234707 | 
2026-01-26 08:41:44.234855 | PLAY [all]
2026-01-26 08:41:44.244264 | 
2026-01-26 08:41:44.244353 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-26 08:41:44.502622 | instance -> localhost | ok
2026-01-26 08:41:44.511989 | 
2026-01-26 08:41:44.512052 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-26 08:41:44.541128 | instance | ok
2026-01-26 08:41:44.554739 | instance | included: /var/lib/zuul/builds/1fd889d7f63b40c993abe88fe7ac355e/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-26 08:41:44.560329 | 
2026-01-26 08:41:44.560388 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-26 08:41:45.377765 | instance -> localhost | Generating public/private rsa key pair.
2026-01-26 08:41:45.377994 | instance -> localhost | Your identification has been saved in /var/lib/zuul/builds/1fd889d7f63b40c993abe88fe7ac355e/work/1fd889d7f63b40c993abe88fe7ac355e_id_rsa
2026-01-26 08:41:45.378035 | instance -> localhost | Your public key has been saved in /var/lib/zuul/builds/1fd889d7f63b40c993abe88fe7ac355e/work/1fd889d7f63b40c993abe88fe7ac355e_id_rsa.pub
2026-01-26 08:41:45.378066 | instance -> localhost | The key fingerprint is:
2026-01-26 08:41:45.378095 | instance -> localhost | SHA256:YrVUuqf5AOflgc4rEg5L86zd6u+KXMRbtdtwg3A97FA zuul-build-sshkey
2026-01-26 08:41:45.378142 | instance -> localhost | The key's randomart image is:
2026-01-26 08:41:45.378174 | instance -> localhost | +---[RSA 3072]----+
2026-01-26 08:41:45.378209 | instance -> localhost | |          E      |
2026-01-26 08:41:45.378240 | instance -> localhost | |         *       |
2026-01-26 08:41:45.378269 | instance -> localhost | |      . B +      |
2026-01-26 08:41:45.378297 | instance -> localhost | |   .   * O .     |
2026-01-26 08:41:45.378324 | instance -> localhost | |    o = S B      |
2026-01-26 08:41:45.378352 | instance -> localhost | |  +..+ B @ o     |
2026-01-26 08:41:45.378379 | instance -> localhost | | . Bo.  O o      |
2026-01-26 08:41:45.378406 | instance -> localhost | | ..+=..  +       |
2026-01-26 08:41:45.378436 | instance -> localhost | |  +o=*+.. .      |
2026-01-26 08:41:45.378464 | instance -> localhost | +----[SHA256]-----+
2026-01-26 08:41:45.378526 | instance -> localhost | ok: Runtime: 0:00:00.395299
2026-01-26 08:41:45.385939 | 
2026-01-26 08:41:45.386004 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-26 08:41:45.420511 | instance | ok
2026-01-26 08:41:45.430657 | instance | included: /var/lib/zuul/builds/1fd889d7f63b40c993abe88fe7ac355e/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-26 08:41:45.438103 | 
2026-01-26 08:41:45.438167 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-26 08:41:45.463047 | instance | skipping: Conditional result was False
2026-01-26 08:41:45.471324 | 
2026-01-26 08:41:45.471409 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-26 08:41:45.931126 | instance | changed
2026-01-26 08:41:45.936143 | 
2026-01-26 08:41:45.936208 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-26 08:41:46.112980 | instance | ok
2026-01-26 08:41:46.119510 | 
2026-01-26 08:41:46.119576 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-26 08:41:46.549969 | instance | changed
2026-01-26 08:41:46.555033 | 
2026-01-26 08:41:46.555100 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-26 08:41:46.989752 | instance | changed
2026-01-26 08:41:46.997257 | 
2026-01-26 08:41:46.997373 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-26 08:41:47.022324 | instance | skipping: Conditional result was False
2026-01-26 08:41:47.033270 | 
2026-01-26 08:41:47.033412 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-26 08:41:47.417328 | instance -> localhost | changed
2026-01-26 08:41:47.432863 | 
2026-01-26 08:41:47.433070 | TASK [add-build-sshkey : Add back temp key]
2026-01-26 08:41:47.728531 | instance -> localhost | Identity added: /var/lib/zuul/builds/1fd889d7f63b40c993abe88fe7ac355e/work/1fd889d7f63b40c993abe88fe7ac355e_id_rsa (zuul-build-sshkey)
2026-01-26 08:41:47.728792 | instance -> localhost | ok: Runtime: 0:00:00.014505
2026-01-26 08:41:47.736329 | 
2026-01-26 08:41:47.736408 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-26 08:41:48.055767 | instance | ok
2026-01-26 08:41:48.062120 | 
2026-01-26 08:41:48.062188 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-26 08:41:48.088081 | instance | skipping: Conditional result was False
2026-01-26 08:41:48.105492 | 
2026-01-26 08:41:48.105582 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-26 08:41:48.432697 | instance | ok
2026-01-26 08:41:48.440723 | 
2026-01-26 08:41:48.440825 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-26 08:41:50.034636 | instance | Output suppressed because no_log was given
2026-01-26 08:41:50.050739 | 
2026-01-26 08:41:50.050936 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-26 08:41:50.234357 | instance | ok: "logs"
2026-01-26 08:41:50.234642 | instance | ok: All items complete
2026-01-26 08:41:50.234669 | 
2026-01-26 08:41:50.380095 | instance | ok: "artifacts"
2026-01-26 08:41:50.533247 | instance | ok: "docs"
2026-01-26 08:41:50.546385 | 
2026-01-26 08:41:50.546546 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-26 08:41:50.726078 | instance | changed: "logs"
2026-01-26 08:41:50.877946 | instance | changed: "artifacts"
2026-01-26 08:41:51.035437 | instance | changed: "docs"
2026-01-26 08:41:51.055415 | 
2026-01-26 08:41:51.055565 | PLAY RECAP
2026-01-26 08:41:51.055638 | instance | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2026-01-26 08:41:51.055696 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-26 08:41:51.055745 | 
2026-01-26 08:41:51.178514 | PRE-RUN END RESULT_NORMAL: [trusted : vexxhost.dev/zuul-config/playbooks/base/pre.yaml@main]
2026-01-26 08:41:51.182508 | PRE-RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-01-26 08:41:51.758765 | 
2026-01-26 08:41:51.758903 | PLAY [all]
2026-01-26 08:41:51.770409 | 
2026-01-26 08:41:51.770494 | TASK [setup-uv : Extract archive]
2026-01-26 08:41:53.940729 | instance | changed
2026-01-26 08:41:53.949543 | 
2026-01-26 08:41:53.949666 | TASK [setup-uv : Print version]
2026-01-26 08:41:53.556193 | instance | uv 0.8.13
2026-01-26 08:41:54.484733 | instance | ok: Runtime: 0:00:00.009111
2026-01-26 08:41:54.495266 | 
2026-01-26 08:41:54.495353 | PLAY RECAP
2026-01-26 08:41:54.495405 | instance | ok: 2 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-26 08:41:54.495430 | 
2026-01-26 08:41:54.631001 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-01-26 08:41:54.634873 | PRE-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@main]
2026-01-26 08:41:55.253142 | 
2026-01-26 08:41:55.253277 | PLAY [all]
2026-01-26 08:41:55.264199 | 
2026-01-26 08:41:55.264274 | TASK [Install "jq" for log collection]
2026-01-26 08:42:04.942033 | instance | changed
2026-01-26 08:42:04.944498 | 
2026-01-26 08:42:04.944577 | PLAY RECAP
2026-01-26 08:42:04.944648 | instance | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-26 08:42:04.944720 | 
2026-01-26 08:42:05.096000 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@main]
2026-01-26 08:42:05.098901 | RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-01-26 08:42:05.683191 | 
2026-01-26 08:42:05.683336 | PLAY [all]
2026-01-26 08:42:05.694566 | 
2026-01-26 08:42:05.694656 | TASK [Copy inventory file for Zuul]
2026-01-26 08:42:06.501379 | instance | changed
2026-01-26 08:42:06.507842 | 
2026-01-26 08:42:06.507927 | TASK [Switch "ansible_host" to private IP]
2026-01-26 08:42:06.766740 | instance | changed: 1 replacements made
2026-01-26 08:42:06.773734 | 
2026-01-26 08:42:06.773799 | TASK [Run Molecule scenario]
2026-01-26 08:42:07.166565 | instance | Using CPython 3.10.12 interpreter at: /usr/bin/python3
2026-01-26 08:42:07.166734 | instance | Creating virtual environment at: .venv
2026-01-26 08:42:07.194089 | instance |    Building atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere
2026-01-26 08:42:07.227832 | instance | Downloading netaddr (2.2MiB)
2026-01-26 08:42:07.254336 | instance | Downloading pygments (1.2MiB)
2026-01-26 08:42:07.262047 | instance | Downloading rjsonnet (1.2MiB)
2026-01-26 08:42:07.274171 | instance | Downloading setuptools (1.1MiB)
2026-01-26 08:42:07.281862 | instance | Downloading openstacksdk (1.7MiB)
2026-01-26 08:42:07.284051 | instance | Downloading ansible-core (2.1MiB)
2026-01-26 08:42:07.285493 | instance | Downloading kubernetes (1.9MiB)
2026-01-26 08:42:07.286395 | instance | Downloading cryptography (4.2MiB)
2026-01-26 08:42:07.525646 | instance |    Building pyperclip==1.9.0
2026-01-26 08:42:07.546114 | instance |  Downloading rjsonnet
2026-01-26 08:42:07.691354 | instance |  Downloading netaddr
2026-01-26 08:42:07.697759 | instance |  Downloading pygments
2026-01-26 08:42:07.718336 | instance |  Downloading cryptography
2026-01-26 08:42:07.748937 | instance |  Downloading setuptools
2026-01-26 08:42:07.843550 | instance |  Downloading kubernetes
2026-01-26 08:42:07.862743 | instance |  Downloading ansible-core
2026-01-26 08:42:07.868068 | instance |  Downloading openstacksdk
2026-01-26 08:42:08.230694 | instance |       Built pyperclip==1.9.0
2026-01-26 08:42:08.491603 | instance |       Built atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere
2026-01-26 08:42:08.552691 | instance | Installed 79 packages in 60ms
2026-01-26 08:42:09.155548 | instance | WARNING  Molecule scenarios should migrate to 'extensions/molecule'
2026-01-26 08:42:09.736961 | instance | INFO     [csi > discovery] scenario test matrix: dependency, cleanup, destroy, syntax, create, prepare, converge, idempotence, side_effect, verify, cleanup, destroy
2026-01-26 08:42:09.737103 | instance | INFO     [csi > prerun] Performing prerun with role_name_check=0...
2026-01-26 08:42:11.900694 | instance | WARNING  Retrying execution failure 1 of: ansible-galaxy collection install -vvv ansible.netcommon:1.2.0
2026-01-26 08:42:11.900749 | instance | ERROR    Command ansible-galaxy collection install -vvv ansible.netcommon:1.2.0, returned 1 code:
2026-01-26 08:42:11.900758 | instance | Starting galaxy collection install process
2026-01-26 08:42:11.900764 | instance | Process install dependency map
2026-01-26 08:42:11.900770 | instance |
2026-01-26 08:42:11.900776 | instance | ansible-galaxy
2026-01-26 08:42:11.900782 | instance |   config file = None
2026-01-26 08:42:11.900787 | instance |   configured module search path =
2026-01-26 08:42:11.900793 | instance |   ansible python module location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/ansible
2026-01-26 08:42:11.900800 | 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-01-26 08:42:11.900807 | instance |   executable location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/ansible-galaxy
2026-01-26 08:42:11.900813 | instance |   python version = 3.10.12 (main, Jan  8 2026, 06:52:19)  (/home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/python)
2026-01-26 08:42:11.900818 | instance |   jinja version = 3.1.6
2026-01-26 08:42:11.900824 | instance |   libyaml = True
2026-01-26 08:42:11.900829 | instance | No config file found; using defaults
2026-01-26 08:42:11.900835 | instance | Created /home/zuul/.ansible/galaxy_token
2026-01-26 08:42:11.900841 | instance | ERROR! Error when getting collection version metadata for ansible.netcommon:1.2.0 from default (https://galaxy.ansible.com/api/) (HTTP Code: 500, Message: Internal Server Error Code: Unknown)
2026-01-26 08:42:11.900853 | instance |
2026-01-26 08:42:11.900859 | instance | Traceback (most recent call last):
2026-01-26 08:42:11.900864 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/molecule", line 10, in <module>
2026-01-26 08:42:11.900876 | instance |     sys.exit(main())
2026-01-26 08:42:11.901132 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 1442, in __call__
2026-01-26 08:42:11.901817 | instance |     return self.main(*args, **kwargs)
2026-01-26 08:42:11.902085 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 1363, in main
2026-01-26 08:42:11.902737 | instance |     rv = self.invoke(ctx)
2026-01-26 08:42:11.903018 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 1830, in invoke
2026-01-26 08:42:11.903762 | instance |     return _process_result(sub_ctx.command.invoke(sub_ctx))
2026-01-26 08:42:11.904031 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 1226, in invoke
2026-01-26 08:42:11.904654 | instance |     return ctx.invoke(self.callback, **ctx.params)
2026-01-26 08:42:11.904934 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 794, in invoke
2026-01-26 08:42:11.905398 | instance |     return callback(*args, **kwargs)
2026-01-26 08:42:11.905565 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/molecule/click_cfg.py", line 583, in wrapper
2026-01-26 08:42:11.905861 | instance |     return func(*args, **kwargs)
2026-01-26 08:42:11.906044 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/decorators.py", line 34, in new_func
2026-01-26 08:42:11.906255 | instance |     return f(get_current_context(), *args, **kwargs)
2026-01-26 08:42:11.906424 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/molecule/click_cfg.py", line 418, in wrapper
2026-01-26 08:42:11.906683 | instance |     return func(ctx)
2026-01-26 08:42:11.906854 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/molecule/command/test.py", line 81, in test
2026-01-26 08:42:11.907102 | instance |     base.execute_cmdline_scenarios(scenario_name, args, command_args, ansible_args, exclude)
2026-01-26 08:42:11.907264 | 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-01-26 08:42:11.907507 | instance |     _run_scenarios(scenarios, command_args, default_config)
2026-01-26 08:42:11.907683 | 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-01-26 08:42:11.907935 | instance |     scenario.config.runtime.prepare_environment(
2026-01-26 08:42:11.908107 | 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-01-26 08:42:11.908457 | instance |     self.install_collection(
2026-01-26 08:42:11.908641 | 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-01-26 08:42:11.908939 | instance |     raise InvalidPrerequisiteError(msg)
2026-01-26 08:42:11.909744 | instance | ansible_compat.errors.InvalidPrerequisiteError: Command ansible-galaxy collection install -vvv ansible.netcommon:1.2.0, returned 1 code:
2026-01-26 08:42:11.909752 | instance | Starting galaxy collection install process
2026-01-26 08:42:11.909758 | instance | Process install dependency map
2026-01-26 08:42:11.909763 | instance |
2026-01-26 08:42:11.909769 | instance | ansible-galaxy [core 2.17.12]
2026-01-26 08:42:11.909774 | instance |   config file = None
2026-01-26 08:42:11.909780 | 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-01-26 08:42:11.909785 | instance |   ansible python module location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/ansible
2026-01-26 08:42:11.909792 | 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-01-26 08:42:11.909806 | instance |   executable location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/ansible-galaxy
2026-01-26 08:42:11.909812 | instance |   python version = 3.10.12 (main, Jan  8 2026, 06:52:19) [GCC 11.4.0] (/home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/python)
2026-01-26 08:42:11.909817 | instance |   jinja version = 3.1.6
2026-01-26 08:42:11.909823 | instance |   libyaml = True
2026-01-26 08:42:11.909828 | instance | No config file found; using defaults
2026-01-26 08:42:11.909833 | instance | Created /home/zuul/.ansible/galaxy_token
2026-01-26 08:42:11.909839 | instance | ERROR! Error when getting collection version metadata for ansible.netcommon:1.2.0 from default (https://galaxy.ansible.com/api/) (HTTP Code: 500, Message: Internal Server Error Code: Unknown)
2026-01-26 08:42:11.909905 | instance |
2026-01-26 08:42:12.318165 | instance | ERROR
2026-01-26 08:42:12.318511 | instance | {
2026-01-26 08:42:12.318576 | instance |   "delta": "0:00:04.864753",
2026-01-26 08:42:12.318623 | instance |   "end": "2026-01-26 08:42:11.979593",
2026-01-26 08:42:12.318665 | instance |   "msg": "non-zero return code",
2026-01-26 08:42:12.318705 | instance |   "rc": 1,
2026-01-26 08:42:12.318752 | instance |   "start": "2026-01-26 08:42:07.114840"
2026-01-26 08:42:12.318792 | instance | }
failure
2026-01-26 08:42:12.321777 | 
2026-01-26 08:42:12.321821 | PLAY RECAP
2026-01-26 08:42:12.321868 | instance | ok: 2 changed: 2 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0
2026-01-26 08:42:12.321890 | 
2026-01-26 08:42:12.431944 | RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-01-26 08:42:12.436048 | POST-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@main]
2026-01-26 08:42:13.046260 | 
2026-01-26 08:42:13.046421 | PLAY [all]
2026-01-26 08:42:13.066157 | 
2026-01-26 08:42:13.066433 | TASK [gather-host-logs : creating directory for system status]
2026-01-26 08:42:13.395551 | instance | changed
2026-01-26 08:42:13.402597 | 
2026-01-26 08:42:13.402691 | TASK [gather-host-logs : Get logs for each host]
2026-01-26 08:42:13.739943 | instance | + systemd-cgls --full --all --no-pager
2026-01-26 08:42:13.747390 | instance | + ip addr
2026-01-26 08:42:13.748959 | instance | + ip route
2026-01-26 08:42:13.750466 | instance | + lsblk
2026-01-26 08:42:13.752470 | instance | + mount
2026-01-26 08:42:13.753654 | instance | + docker images
2026-01-26 08:42:13.753937 | instance | /bin/bash: line 7: docker: command not found
2026-01-26 08:42:13.754122 | instance | + brctl show
2026-01-26 08:42:13.754389 | instance | /bin/bash: line 8: brctl: command not found
2026-01-26 08:42:13.754578 | instance | + ps aux --sort=-%mem
2026-01-26 08:42:13.761031 | instance | + dpkg -l
2026-01-26 08:42:13.766142 | instance | + CONTAINERS=($(docker ps -a --format '{{ .Names }}' --filter label=zuul))
2026-01-26 08:42:13.766449 | instance | ++ docker ps -a --format '{{ .Names }}' --filter label=zuul
2026-01-26 08:42:13.766504 | instance | /bin/bash: line 11: docker: command not found
2026-01-26 08:42:13.766756 | instance | + '[' '!' -z '' ']'
2026-01-26 08:42:13.941037 | instance | ok: Runtime: 0:00:00.031305
2026-01-26 08:42:13.947271 | 
2026-01-26 08:42:13.947350 | TASK [gather-host-logs : Downloads logs to executor]
2026-01-26 08:42:14.589339 | instance | changed:
2026-01-26 08:42:14.589560 | instance | created directory /var/lib/zuul/builds/1fd889d7f63b40c993abe88fe7ac355e/work/logs/instance
2026-01-26 08:42:14.589602 | instance | cd+++++++++ system/
2026-01-26 08:42:14.589638 | instance | >f+++++++++ system/brctl-show.txt
2026-01-26 08:42:14.589678 | instance | >f+++++++++ system/docker-images.txt
2026-01-26 08:42:14.589717 | instance | >f+++++++++ system/ip-addr.txt
2026-01-26 08:42:14.589760 | instance | >f+++++++++ system/ip-route.txt
2026-01-26 08:42:14.589792 | instance | >f+++++++++ system/lsblk.txt
2026-01-26 08:42:14.589819 | instance | >f+++++++++ system/mount.txt
2026-01-26 08:42:14.589855 | instance | >f+++++++++ system/packages.txt
2026-01-26 08:42:14.589894 | instance | >f+++++++++ system/ps.txt
2026-01-26 08:42:14.589947 | instance | >f+++++++++ system/systemd-cgls.txt
2026-01-26 08:42:14.603189 | 
2026-01-26 08:42:14.603382 | LOOP [helm-release-status : creating directory for helm release status]
2026-01-26 08:42:14.794366 | instance | changed: "values"
2026-01-26 08:42:14.951796 | instance | changed: "releases"
2026-01-26 08:42:14.967553 | 
2026-01-26 08:42:14.967726 | TASK [helm-release-status : Gather get release status for helm charts]
2026-01-26 08:42:15.173790 | instance | /bin/bash: line 3: kubectl: command not found
2026-01-26 08:42:15.515403 | instance | ok: Runtime: 0:00:00.006225
2026-01-26 08:42:15.521364 | 
2026-01-26 08:42:15.521460 | TASK [helm-release-status : Downloads logs to executor]
2026-01-26 08:42:15.993786 | instance | changed:
2026-01-26 08:42:15.993998 | instance | cd+++++++++ helm/
2026-01-26 08:42:15.994038 | instance | cd+++++++++ helm/releases/
2026-01-26 08:42:15.994067 | instance | cd+++++++++ helm/values/
2026-01-26 08:42:16.003792 | 
2026-01-26 08:42:16.003874 | TASK [describe-kubernetes-objects : creating directory for cluster scoped objects]
2026-01-26 08:42:16.188362 | instance | changed
2026-01-26 08:42:16.193621 | 
2026-01-26 08:42:16.193702 | TASK [describe-kubernetes-objects : Gathering descriptions for cluster scoped objects]
2026-01-26 08:42:16.393711 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-01-26 08:42:16.394118 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-01-26 08:42:16.398728 | instance | environment: line 1: kubectl: command not found
2026-01-26 08:42:16.399734 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-01-26 08:42:16.400227 | instance | environment: line 1: kubectl: command not found
2026-01-26 08:42:16.400729 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-01-26 08:42:16.401517 | instance | environment: line 1: kubectl: command not found
2026-01-26 08:42:16.402253 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-01-26 08:42:16.405369 | instance | environment: line 1: kubectl: command not found
2026-01-26 08:42:16.406109 | instance | environment: line 1: kubectl: command not found
2026-01-26 08:42:16.406732 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-01-26 08:42:16.407171 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-01-26 08:42:16.728949 | instance | ok: Runtime: 0:00:00.020708
2026-01-26 08:42:16.737223 | 
2026-01-26 08:42:16.737386 | TASK [describe-kubernetes-objects : creating directory for namespace scoped objects]
2026-01-26 08:42:16.913821 | instance | changed
2026-01-26 08:42:16.921343 | 
2026-01-26 08:42:16.921483 | TASK [describe-kubernetes-objects : Gathering descriptions for namespace scoped objects]
2026-01-26 08:42:17.186825 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-01-26 08:42:17.187058 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-01-26 08:42:17.187315 | instance | environment: line 5: kubectl: command not found
2026-01-26 08:42:17.187585 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-01-26 08:42:17.519486 | instance | ok: Runtime: 0:00:00.006772
2026-01-26 08:42:17.526975 | 
2026-01-26 08:42:17.527041 | TASK [describe-kubernetes-objects : Downloads logs to executor]
2026-01-26 08:42:17.996718 | instance | changed:
2026-01-26 08:42:17.996936 | instance | cd+++++++++ objects/
2026-01-26 08:42:17.997025 | instance | cd+++++++++ objects/cluster/
2026-01-26 08:42:17.997064 | instance | cd+++++++++ objects/namespaced/
2026-01-26 08:42:18.006425 | 
2026-01-26 08:42:18.006493 | TASK [gather-pod-logs : creating directory for pod logs]
2026-01-26 08:42:18.193304 | instance | changed
2026-01-26 08:42:18.199012 | 
2026-01-26 08:42:18.199081 | TASK [gather-pod-logs : creating directory for failed pod logs]
2026-01-26 08:42:18.372583 | instance | changed
2026-01-26 08:42:18.382330 | 
2026-01-26 08:42:18.382431 | TASK [gather-pod-logs : retrieve all kubernetes logs, current and previous (if they exist)]
2026-01-26 08:42:18.587940 | instance | environment: line 3: kubectl: command not found
2026-01-26 08:42:18.924480 | instance | ok: Runtime: 0:00:00.004829
2026-01-26 08:42:18.930270 | 
2026-01-26 08:42:18.930339 | TASK [gather-pod-logs : Downloads pod logs to executor]
2026-01-26 08:42:19.412447 | instance | changed:
2026-01-26 08:42:19.412617 | instance | cd+++++++++ pod-logs/
2026-01-26 08:42:19.412645 | instance | cd+++++++++ pod-logs/failed-pods/
2026-01-26 08:42:19.421531 | 
2026-01-26 08:42:19.421598 | TASK [gather-prom-metrics : creating directory for helm release descriptions]
2026-01-26 08:42:19.616450 | instance | changed
2026-01-26 08:42:19.622366 | 
2026-01-26 08:42:19.622436 | TASK [gather-prom-metrics : Get metrics from exporter services in all namespaces]
2026-01-26 08:42:19.825051 | instance | /bin/bash: line 2: kubectl: command not found
2026-01-26 08:42:20.155616 | instance | ok: Runtime: 0:00:00.031935
2026-01-26 08:42:20.160767 | 
2026-01-26 08:42:20.160837 | TASK [gather-prom-metrics : Get ceph metrics from ceph-mgr]
2026-01-26 08:42:20.367295 | instance | /bin/bash: line 2: kubectl: command not found
2026-01-26 08:42:20.393066 | instance | ceph-mgr endpoints:
2026-01-26 08:42:20.696564 | instance | ok: Runtime: 0:00:00.031524
2026-01-26 08:42:20.703308 | 
2026-01-26 08:42:20.703475 | TASK [gather-prom-metrics : Get metrics from fluentd pods]
2026-01-26 08:42:20.915264 | instance | /bin/bash: line 4: kubectl: command not found
2026-01-26 08:42:21.236412 | instance | ok: Runtime: 0:00:00.033926
2026-01-26 08:42:21.241851 | 
2026-01-26 08:42:21.241917 | TASK [gather-prom-metrics : Downloads logs to executor]
2026-01-26 08:42:21.711963 | instance | changed: cd+++++++++ prometheus/
2026-01-26 08:42:21.721899 | 
2026-01-26 08:42:21.721969 | TASK [gather-selenium-data : creating directory for helm release descriptions]
2026-01-26 08:42:21.908600 | instance | changed
2026-01-26 08:42:21.916589 | 
2026-01-26 08:42:21.916669 | TASK [gather-selenium-data : Get selenium data]
2026-01-26 08:42:22.121131 | instance | + cp '/tmp/artifacts/*' /tmp/logs/selenium/.
2026-01-26 08:42:22.122589 | instance | cp: cannot stat '/tmp/artifacts/*': No such file or directory
2026-01-26 08:42:22.451421 | instance | ERROR
2026-01-26 08:42:22.451600 | instance | {
2026-01-26 08:42:22.451644 | instance |   "delta": "0:00:00.005793",
2026-01-26 08:42:22.451674 | instance |   "end": "2026-01-26 08:42:22.122882",
2026-01-26 08:42:22.451701 | instance |   "msg": "non-zero return code",
2026-01-26 08:42:22.451726 | instance |   "rc": 1,
2026-01-26 08:42:22.451751 | instance |   "start": "2026-01-26 08:42:22.117089"
2026-01-26 08:42:22.451775 | instance | }
2026-01-26 08:42:22.451808 | instance | ERROR: Ignoring Errors
2026-01-26 08:42:22.458146 | 
2026-01-26 08:42:22.458216 | TASK [gather-selenium-data : Downloads logs to executor]
2026-01-26 08:42:22.946501 | instance | changed: cd+++++++++ selenium/
2026-01-26 08:42:22.953405 | 
2026-01-26 08:42:22.953554 | PLAY RECAP
2026-01-26 08:42:22.953647 | instance | ok: 23 changed: 23 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 1
2026-01-26 08:42:22.953695 | 
2026-01-26 08:42:23.086197 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@main]
2026-01-26 08:42:23.088215 | POST-RUN START: [trusted : vexxhost.dev/zuul-config/playbooks/base/post.yaml@main]
2026-01-26 08:42:23.691942 | 
2026-01-26 08:42:23.692114 | PLAY [all]
2026-01-26 08:42:23.704571 | 
2026-01-26 08:42:23.704682 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-26 08:42:23.752735 | instance | skipping: Conditional result was False
2026-01-26 08:42:23.764051 | 
2026-01-26 08:42:23.764174 | TASK [fetch-output : Set log path for single node]
2026-01-26 08:42:23.808726 | instance | ok
2026-01-26 08:42:23.813514 | 
2026-01-26 08:42:23.813589 | LOOP [fetch-output : Ensure local output dirs]
2026-01-26 08:42:24.226307 | instance -> localhost | ok: "/var/lib/zuul/builds/1fd889d7f63b40c993abe88fe7ac355e/work/logs"
2026-01-26 08:42:24.435916 | instance -> localhost | changed: "/var/lib/zuul/builds/1fd889d7f63b40c993abe88fe7ac355e/work/artifacts"
2026-01-26 08:42:24.648881 | instance -> localhost | changed: "/var/lib/zuul/builds/1fd889d7f63b40c993abe88fe7ac355e/work/docs"
2026-01-26 08:42:24.668584 | 
2026-01-26 08:42:24.668678 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-26 08:42:25.297326 | instance | changed: .d..t...... ./
2026-01-26 08:42:25.297630 | instance | changed: All items complete
2026-01-26 08:42:25.297673 | 
2026-01-26 08:42:25.757446 | instance | changed: .d..t...... ./
2026-01-26 08:42:26.204381 | instance | changed: .d..t...... ./
2026-01-26 08:42:26.223398 | 
2026-01-26 08:42:26.223536 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-26 08:42:26.648471 | instance -> localhost | ok: Item: artifacts Runtime: 0:00:00.008024
2026-01-26 08:42:26.906714 | instance -> localhost | ok: Item: docs Runtime: 0:00:00.009272
2026-01-26 08:42:26.927463 | 
2026-01-26 08:42:26.927601 | PLAY [all]
2026-01-26 08:42:26.933768 | 
2026-01-26 08:42:26.933835 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-01-26 08:42:27.353532 | instance | changed
2026-01-26 08:42:27.360625 | 
2026-01-26 08:42:27.360681 | PLAY RECAP
2026-01-26 08:42:27.360730 | instance | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-01-26 08:42:27.360753 | 
2026-01-26 08:42:27.487251 | POST-RUN END RESULT_NORMAL: [trusted : vexxhost.dev/zuul-config/playbooks/base/post.yaml@main]
2026-01-26 08:42:27.490110 | POST-RUN START: [trusted : vexxhost.dev/zuul-config/playbooks/base/post-logs.yaml@main]
2026-01-26 08:42:28.080113 | 
2026-01-26 08:42:28.080946 | PLAY [localhost]
2026-01-26 08:42:28.090862 | 
2026-01-26 08:42:28.090933 | TASK [Generate Zuul manifest]
2026-01-26 08:42:28.111980 | localhost | ok
2026-01-26 08:42:28.128901 | 
2026-01-26 08:42:28.129006 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-26 08:42:28.455233 | localhost | changed
2026-01-26 08:42:28.467496 | 
2026-01-26 08:42:28.467580 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-26 08:42:28.498028 | localhost | ok
2026-01-26 08:42:28.506054 | 
2026-01-26 08:42:28.506118 | TASK [Upload logs]
2026-01-26 08:42:28.523737 | localhost | ok
2026-01-26 08:42:28.584102 | 
2026-01-26 08:42:28.584242 | TASK [Set zuul-log-path fact]
2026-01-26 08:42:28.607846 | localhost | ok
2026-01-26 08:42:28.619732 | 
2026-01-26 08:42:28.619812 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-26 08:42:28.650838 | localhost | ok
2026-01-26 08:42:28.658350 | 
2026-01-26 08:42:28.658417 | TASK [upload-logs : Create log directories]
2026-01-26 08:42:29.085803 | localhost | changed
2026-01-26 08:42:29.091999 | 
2026-01-26 08:42:29.092094 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-01-26 08:42:29.534967 | localhost -> localhost | ok: Runtime: 0:00:00.004816
2026-01-26 08:42:29.541574 | 
2026-01-26 08:42:29.541645 | TASK [upload-logs : Upload logs to log server]
2026-01-26 08:42:30.052260 | localhost | Output suppressed because no_log was given
2026-01-26 08:42:30.057768 | 
2026-01-26 08:42:30.057861 | LOOP [upload-logs : Compress console log and json output]
2026-01-26 08:42:30.105679 | localhost | skipping: Conditional result was False
2026-01-26 08:42:30.111379 | localhost | skipping: Conditional result was False
2026-01-26 08:42:30.126440 | 
2026-01-26 08:42:30.126620 | LOOP [upload-logs : Upload compressed console log and json output]
2026-01-26 08:42:30.173867 | localhost | skipping: Conditional result was False
2026-01-26 08:42:30.174333 | 
2026-01-26 08:42:30.177411 | localhost | skipping: Conditional result was False
2026-01-26 08:42:30.195984 | 
2026-01-26 08:42:30.196057 | LOOP [upload-logs : Upload console log and json output]