2026-01-26 07:09:46.544028 | Job console starting
2026-01-26 07:09:46.561690 | Updating git repos
2026-01-26 07:09:46.613119 | Cloning repos into workspace
2026-01-26 07:09:46.679905 | Restoring repo states
2026-01-26 07:09:46.700453 | Merging changes
2026-01-26 07:09:47.387688 | Checking out repos
2026-01-26 07:09:47.624578 | Preparing playbooks
2026-01-26 07:09:49.613474 | Running Ansible setup
2026-01-26 07:09:52.850899 | PRE-RUN START: [trusted : vexxhost.dev/zuul-config/playbooks/base/pre.yaml@main]
2026-01-26 07:09:53.416046 | 
2026-01-26 07:09:53.416593 | PLAY [localhost]
2026-01-26 07:09:53.423920 | 
2026-01-26 07:09:53.423986 | TASK [Gathering Facts]
2026-01-26 07:09:54.265710 | localhost | ok
2026-01-26 07:09:54.278029 | 
2026-01-26 07:09:54.278128 | TASK [Setup log path fact]
2026-01-26 07:09:54.301011 | localhost | ok
2026-01-26 07:09:54.312856 | 
2026-01-26 07:09:54.312918 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-26 07:09:54.342829 | localhost | ok
2026-01-26 07:09:54.352662 | 
2026-01-26 07:09:54.352749 | TASK [emit-job-header : Print job information]
2026-01-26 07:09:54.394682 | # Job Information
2026-01-26 07:09:54.395041 | Ansible Version: 2.16.15
2026-01-26 07:09:54.395117 | Job: atmosphere-molecule-csi-local-path-provisioner
2026-01-26 07:09:54.395166 | Pipeline: check
2026-01-26 07:09:54.395209 | Executor: 3a2793d2bd32
2026-01-26 07:09:54.395251 | Triggered by: https://github.com/vexxhost/atmosphere/pull/3467
2026-01-26 07:09:54.395298 | Event ID: e38b58c0-fa85-11f0-9bac-26b7a21d70b0
2026-01-26 07:09:54.398625 | 
2026-01-26 07:09:54.398688 | LOOP [emit-job-header : Print node information]
2026-01-26 07:09:54.494714 | localhost | ok:
2026-01-26 07:09:54.495175 | localhost | # Node Information
2026-01-26 07:09:54.495297 | localhost | Inventory Hostname: instance
2026-01-26 07:09:54.495393 | localhost | Hostname: np0000154462
2026-01-26 07:09:54.495553 | localhost | Username: zuul
2026-01-26 07:09:54.495744 | localhost | Distro: Ubuntu 22.04
2026-01-26 07:09:54.495807 | localhost | Provider: yul1
2026-01-26 07:09:54.495851 | localhost | Region: ca-ymq-1
2026-01-26 07:09:54.495893 | localhost | Label: ubuntu-jammy
2026-01-26 07:09:54.495933 | localhost | Product Name: OpenStack Nova
2026-01-26 07:09:54.495978 | localhost | Interface IP: 162.253.55.206
2026-01-26 07:09:54.517249 | 
2026-01-26 07:09:54.517362 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-26 07:09:54.897214 | localhost -> localhost | changed
2026-01-26 07:09:54.904869 | 
2026-01-26 07:09:54.904987 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-26 07:09:55.711764 | localhost -> localhost | changed
2026-01-26 07:09:55.718331 | 
2026-01-26 07:09:55.718388 | PLAY [all]
2026-01-26 07:09:55.726341 | 
2026-01-26 07:09:55.726404 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-26 07:09:55.963733 | instance -> localhost | ok
2026-01-26 07:09:55.975579 | 
2026-01-26 07:09:55.975644 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-26 07:09:56.008225 | instance | ok
2026-01-26 07:09:56.022865 | instance | included: /var/lib/zuul/builds/423107f678a6490eac05f1a6ae5669e8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-26 07:09:56.028303 | 
2026-01-26 07:09:56.028362 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-26 07:09:57.463318 | instance -> localhost | Generating public/private rsa key pair.
2026-01-26 07:09:57.463601 | instance -> localhost | Your identification has been saved in /var/lib/zuul/builds/423107f678a6490eac05f1a6ae5669e8/work/423107f678a6490eac05f1a6ae5669e8_id_rsa
2026-01-26 07:09:57.463664 | instance -> localhost | Your public key has been saved in /var/lib/zuul/builds/423107f678a6490eac05f1a6ae5669e8/work/423107f678a6490eac05f1a6ae5669e8_id_rsa.pub
2026-01-26 07:09:57.463717 | instance -> localhost | The key fingerprint is:
2026-01-26 07:09:57.463765 | instance -> localhost | SHA256:8vanVu63ajO6z+8FXiWhPEq9ypilduUI8gebO2E5W70 zuul-build-sshkey
2026-01-26 07:09:57.463831 | instance -> localhost | The key's randomart image is:
2026-01-26 07:09:57.463878 | instance -> localhost | +---[RSA 3072]----+
2026-01-26 07:09:57.463932 | instance -> localhost | |              .  |
2026-01-26 07:09:57.463981 | instance -> localhost | |           o . . |
2026-01-26 07:09:57.464027 | instance -> localhost | |          . = . .|
2026-01-26 07:09:57.464073 | instance -> localhost | |         . . o ..|
2026-01-26 07:09:57.464119 | instance -> localhost | |      o S.o.o . .|
2026-01-26 07:09:57.464165 | instance -> localhost | |       ==@.=o. o |
2026-01-26 07:09:57.464211 | instance -> localhost | |       .@=*o... .|
2026-01-26 07:09:57.464257 | instance -> localhost | |       oo=..E .. |
2026-01-26 07:09:57.464308 | instance -> localhost | |        .o=O=B+. |
2026-01-26 07:09:57.464352 | instance -> localhost | +----[SHA256]-----+
2026-01-26 07:09:57.464443 | instance -> localhost | ok: Runtime: 0:00:01.040794
2026-01-26 07:09:57.472289 | 
2026-01-26 07:09:57.472367 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-26 07:09:57.502852 | instance | ok
2026-01-26 07:09:57.510821 | instance | included: /var/lib/zuul/builds/423107f678a6490eac05f1a6ae5669e8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-26 07:09:57.517877 | 
2026-01-26 07:09:57.517950 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-26 07:09:57.540732 | instance | skipping: Conditional result was False
2026-01-26 07:09:57.550523 | 
2026-01-26 07:09:57.550610 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-26 07:09:57.953967 | instance | changed
2026-01-26 07:09:57.960336 | 
2026-01-26 07:09:57.960396 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-26 07:09:58.139896 | instance | ok
2026-01-26 07:09:58.144791 | 
2026-01-26 07:09:58.144902 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-26 07:09:58.592805 | instance | changed
2026-01-26 07:09:58.600084 | 
2026-01-26 07:09:58.600159 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-26 07:09:59.028330 | instance | changed
2026-01-26 07:09:59.034502 | 
2026-01-26 07:09:59.034565 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-26 07:09:59.059386 | instance | skipping: Conditional result was False
2026-01-26 07:09:59.070711 | 
2026-01-26 07:09:59.070794 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-26 07:09:59.419644 | instance -> localhost | changed
2026-01-26 07:09:59.434411 | 
2026-01-26 07:09:59.434477 | TASK [add-build-sshkey : Add back temp key]
2026-01-26 07:09:59.695832 | instance -> localhost | Identity added: /var/lib/zuul/builds/423107f678a6490eac05f1a6ae5669e8/work/423107f678a6490eac05f1a6ae5669e8_id_rsa (zuul-build-sshkey)
2026-01-26 07:09:59.696020 | instance -> localhost | ok: Runtime: 0:00:00.012861
2026-01-26 07:09:59.700784 | 
2026-01-26 07:09:59.700843 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-26 07:10:00.063741 | instance | ok
2026-01-26 07:10:00.072228 | 
2026-01-26 07:10:00.072318 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-26 07:10:00.096681 | instance | skipping: Conditional result was False
2026-01-26 07:10:00.111663 | 
2026-01-26 07:10:00.111729 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-26 07:10:00.420264 | instance | ok
2026-01-26 07:10:00.428043 | 
2026-01-26 07:10:00.428179 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-26 07:10:02.003833 | instance | Output suppressed because no_log was given
2026-01-26 07:10:02.013317 | 
2026-01-26 07:10:02.013375 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-26 07:10:02.192522 | instance | ok: "logs"
2026-01-26 07:10:02.192785 | instance | ok: All items complete
2026-01-26 07:10:02.192821 | 
2026-01-26 07:10:02.339539 | instance | ok: "artifacts"
2026-01-26 07:10:02.488524 | instance | ok: "docs"
2026-01-26 07:10:02.508734 | 
2026-01-26 07:10:02.508879 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-26 07:10:02.687438 | instance | changed: "logs"
2026-01-26 07:10:02.852727 | instance | changed: "artifacts"
2026-01-26 07:10:03.001984 | instance | changed: "docs"
2026-01-26 07:10:03.021350 | 
2026-01-26 07:10:03.021472 | PLAY RECAP
2026-01-26 07:10:03.021522 | instance | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2026-01-26 07:10:03.021551 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-26 07:10:03.021574 | 
2026-01-26 07:10:03.141476 | PRE-RUN END RESULT_NORMAL: [trusted : vexxhost.dev/zuul-config/playbooks/base/pre.yaml@main]
2026-01-26 07:10:03.145419 | PRE-RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-01-26 07:10:03.730899 | 
2026-01-26 07:10:03.731030 | PLAY [all]
2026-01-26 07:10:03.742352 | 
2026-01-26 07:10:03.742425 | TASK [setup-uv : Extract archive]
2026-01-26 07:10:05.917317 | instance | changed
2026-01-26 07:10:05.926244 | 
2026-01-26 07:10:05.926323 | TASK [setup-uv : Print version]
2026-01-26 07:10:06.680254 | instance | uv 0.8.13
2026-01-26 07:10:06.462757 | instance | ok: Runtime: 0:00:00.014010
2026-01-26 07:10:06.471219 | 
2026-01-26 07:10:06.471272 | PLAY RECAP
2026-01-26 07:10:06.471321 | instance | ok: 2 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-26 07:10:06.471345 | 
2026-01-26 07:10:06.590672 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-01-26 07:10:06.594706 | PRE-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@main]
2026-01-26 07:10:07.141642 | 
2026-01-26 07:10:07.141773 | PLAY [all]
2026-01-26 07:10:07.152569 | 
2026-01-26 07:10:07.152642 | TASK [Install "jq" for log collection]
2026-01-26 07:10:16.751126 | instance | changed
2026-01-26 07:10:16.753028 | 
2026-01-26 07:10:16.753086 | PLAY RECAP
2026-01-26 07:10:16.753135 | instance | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-26 07:10:16.753184 | 
2026-01-26 07:10:16.877576 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@main]
2026-01-26 07:10:16.881356 | RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-01-26 07:10:17.439506 | 
2026-01-26 07:10:17.439644 | PLAY [all]
2026-01-26 07:10:17.450876 | 
2026-01-26 07:10:17.450948 | TASK [Copy inventory file for Zuul]
2026-01-26 07:10:18.226998 | instance | changed
2026-01-26 07:10:18.233727 | 
2026-01-26 07:10:18.233807 | TASK [Switch "ansible_host" to private IP]
2026-01-26 07:10:18.499482 | instance | changed: 1 replacements made
2026-01-26 07:10:18.506044 | 
2026-01-26 07:10:18.506119 | TASK [Run Molecule scenario]
2026-01-26 07:10:18.894368 | instance | Using CPython 3.10.12 interpreter at: /usr/bin/python3
2026-01-26 07:10:18.894521 | instance | Creating virtual environment at: .venv
2026-01-26 07:10:18.937565 | instance |    Building atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere
2026-01-26 07:10:18.964685 | instance | Downloading netaddr (2.2MiB)
2026-01-26 07:10:18.965000 | instance | Downloading openstacksdk (1.7MiB)
2026-01-26 07:10:18.966477 | instance | Downloading kubernetes (1.9MiB)
2026-01-26 07:10:18.966936 | instance | Downloading setuptools (1.1MiB)
2026-01-26 07:10:18.968410 | instance | Downloading ansible-core (2.1MiB)
2026-01-26 07:10:18.968698 | instance | Downloading cryptography (4.2MiB)
2026-01-26 07:10:18.969045 | instance | Downloading pygments (1.2MiB)
2026-01-26 07:10:18.984167 | instance | Downloading rjsonnet (1.2MiB)
2026-01-26 07:10:19.253816 | instance |    Building pyperclip==1.9.0
2026-01-26 07:10:19.275797 | instance |  Downloading rjsonnet
2026-01-26 07:10:19.420675 | instance |  Downloading netaddr
2026-01-26 07:10:19.422688 | instance |  Downloading pygments
2026-01-26 07:10:19.441952 | instance |  Downloading cryptography
2026-01-26 07:10:19.470190 | instance |  Downloading setuptools
2026-01-26 07:10:19.533865 | instance |  Downloading kubernetes
2026-01-26 07:10:19.577720 | instance |  Downloading ansible-core
2026-01-26 07:10:19.599860 | instance |  Downloading openstacksdk
2026-01-26 07:10:19.990584 | instance |       Built pyperclip==1.9.0
2026-01-26 07:10:20.219461 | instance |       Built atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere
2026-01-26 07:10:20.281268 | instance | Installed 79 packages in 60ms
2026-01-26 07:10:20.889327 | instance | WARNING  Molecule scenarios should migrate to 'extensions/molecule'
2026-01-26 07:10:21.526736 | instance | INFO     [csi > discovery] scenario test matrix: dependency, cleanup, destroy, syntax, create, prepare, converge, idempotence, side_effect, verify, cleanup, destroy
2026-01-26 07:10:21.526875 | instance | INFO     [csi > prerun] Performing prerun with role_name_check=0...
2026-01-26 07:10:23.921281 | instance | WARNING  Retrying execution failure 1 of: ansible-galaxy collection install -vvv ansible.netcommon:1.2.0
2026-01-26 07:10:23.921334 | instance | ERROR    Command ansible-galaxy collection install -vvv ansible.netcommon:1.2.0, returned 1 code:
2026-01-26 07:10:23.921340 | instance | Starting galaxy collection install process
2026-01-26 07:10:23.921344 | instance | Process install dependency map
2026-01-26 07:10:23.921349 | instance |
2026-01-26 07:10:23.921353 | instance | ansible-galaxy
2026-01-26 07:10:23.921357 | instance |   config file = None
2026-01-26 07:10:23.921362 | instance |   configured module search path =
2026-01-26 07:10:23.921366 | instance |   ansible python module location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/ansible
2026-01-26 07:10:23.921371 | 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 07:10:23.921383 | instance |   executable location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/ansible-galaxy
2026-01-26 07:10:23.921387 | 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 07:10:23.921391 | instance |   jinja version = 3.1.6
2026-01-26 07:10:23.921395 | instance |   libyaml = True
2026-01-26 07:10:23.921399 | instance | No config file found; using defaults
2026-01-26 07:10:23.921403 | instance | Created /home/zuul/.ansible/galaxy_token
2026-01-26 07:10:23.921408 | 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 07:10:23.921415 | instance |
2026-01-26 07:10:23.921635 | instance | Traceback (most recent call last):
2026-01-26 07:10:23.921980 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/molecule", line 10, in <module>
2026-01-26 07:10:23.922414 | instance |     sys.exit(main())
2026-01-26 07:10:23.922712 | 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 07:10:23.923497 | instance |     return self.main(*args, **kwargs)
2026-01-26 07:10:23.923799 | 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 07:10:23.924217 | instance |     rv = self.invoke(ctx)
2026-01-26 07:10:23.924398 | 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 07:10:23.924904 | instance |     return _process_result(sub_ctx.command.invoke(sub_ctx))
2026-01-26 07:10:23.925089 | 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 07:10:23.925518 | instance |     return ctx.invoke(self.callback, **ctx.params)
2026-01-26 07:10:23.925700 | 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 07:10:23.926067 | instance |     return callback(*args, **kwargs)
2026-01-26 07:10:23.926292 | 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 07:10:23.926606 | instance |     return func(*args, **kwargs)
2026-01-26 07:10:23.926792 | 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 07:10:23.927083 | instance |     return f(get_current_context(), *args, **kwargs)
2026-01-26 07:10:23.927269 | 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 07:10:23.927542 | instance |     return func(ctx)
2026-01-26 07:10:23.927717 | 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 07:10:23.927972 | instance |     base.execute_cmdline_scenarios(scenario_name, args, command_args, ansible_args, exclude)
2026-01-26 07:10:23.928150 | 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 07:10:23.928399 | instance |     _run_scenarios(scenarios, command_args, default_config)
2026-01-26 07:10:23.928573 | 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 07:10:23.928835 | instance |     scenario.config.runtime.prepare_environment(
2026-01-26 07:10:23.929022 | 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 07:10:23.929371 | instance |     self.install_collection(
2026-01-26 07:10:23.929545 | 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 07:10:23.929840 | instance |     raise InvalidPrerequisiteError(msg)
2026-01-26 07:10:23.930640 | instance | ansible_compat.errors.InvalidPrerequisiteError: Command ansible-galaxy collection install -vvv ansible.netcommon:1.2.0, returned 1 code:
2026-01-26 07:10:23.930648 | instance | Starting galaxy collection install process
2026-01-26 07:10:23.930654 | instance | Process install dependency map
2026-01-26 07:10:23.930660 | instance |
2026-01-26 07:10:23.930666 | instance | ansible-galaxy [core 2.17.12]
2026-01-26 07:10:23.930672 | instance |   config file = None
2026-01-26 07:10:23.930679 | 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 07:10:23.930686 | instance |   ansible python module location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/ansible
2026-01-26 07:10:23.930692 | 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 07:10:23.930710 | instance |   executable location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/ansible-galaxy
2026-01-26 07:10:23.930716 | 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 07:10:23.930722 | instance |   jinja version = 3.1.6
2026-01-26 07:10:23.930728 | instance |   libyaml = True
2026-01-26 07:10:23.930734 | instance | No config file found; using defaults
2026-01-26 07:10:23.930740 | instance | Created /home/zuul/.ansible/galaxy_token
2026-01-26 07:10:23.930747 | 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 07:10:23.930811 | instance |
2026-01-26 07:10:24.050247 | instance | ERROR
2026-01-26 07:10:24.050502 | instance | {
2026-01-26 07:10:24.050544 | instance |   "delta": "0:00:05.162230",
2026-01-26 07:10:24.050574 | instance |   "end": "2026-01-26 07:10:24.000606",
2026-01-26 07:10:24.050601 | instance |   "msg": "non-zero return code",
2026-01-26 07:10:24.050627 | instance |   "rc": 1,
2026-01-26 07:10:24.050654 | instance |   "start": "2026-01-26 07:10:18.838376"
2026-01-26 07:10:24.050680 | instance | }
failure
2026-01-26 07:10:24.053474 | 
2026-01-26 07:10:24.053539 | PLAY RECAP
2026-01-26 07:10:24.053598 | instance | ok: 2 changed: 2 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0
2026-01-26 07:10:24.053628 | 
2026-01-26 07:10:24.175154 | RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-01-26 07:10:24.179627 | POST-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@main]
2026-01-26 07:10:24.768406 | 
2026-01-26 07:10:24.768533 | PLAY [all]
2026-01-26 07:10:24.782801 | 
2026-01-26 07:10:24.782881 | TASK [gather-host-logs : creating directory for system status]
2026-01-26 07:10:25.132689 | instance | changed
2026-01-26 07:10:25.138175 | 
2026-01-26 07:10:25.138261 | TASK [gather-host-logs : Get logs for each host]
2026-01-26 07:10:25.485911 | instance | + systemd-cgls --full --all --no-pager
2026-01-26 07:10:25.494111 | instance | + ip addr
2026-01-26 07:10:25.495512 | instance | + ip route
2026-01-26 07:10:25.496721 | instance | + lsblk
2026-01-26 07:10:25.499018 | instance | + mount
2026-01-26 07:10:25.500232 | instance | + docker images
2026-01-26 07:10:25.500465 | instance | /bin/bash: line 7: docker: command not found
2026-01-26 07:10:25.500609 | instance | + brctl show
2026-01-26 07:10:25.500827 | instance | /bin/bash: line 8: brctl: command not found
2026-01-26 07:10:25.500985 | instance | + ps aux --sort=-%mem
2026-01-26 07:10:25.506934 | instance | + dpkg -l
2026-01-26 07:10:25.513482 | instance | + CONTAINERS=($(docker ps -a --format '{{ .Names }}' --filter label=zuul))
2026-01-26 07:10:25.513811 | instance | ++ docker ps -a --format '{{ .Names }}' --filter label=zuul
2026-01-26 07:10:25.513886 | instance | /bin/bash: line 11: docker: command not found
2026-01-26 07:10:25.514147 | instance | + '[' '!' -z '' ']'
2026-01-26 07:10:25.675801 | instance | ok: Runtime: 0:00:00.030762
2026-01-26 07:10:25.684065 | 
2026-01-26 07:10:25.684160 | TASK [gather-host-logs : Downloads logs to executor]
2026-01-26 07:10:26.337384 | instance | changed:
2026-01-26 07:10:26.337600 | instance | created directory /var/lib/zuul/builds/423107f678a6490eac05f1a6ae5669e8/work/logs/instance
2026-01-26 07:10:26.337640 | instance | cd+++++++++ system/
2026-01-26 07:10:26.337672 | instance | >f+++++++++ system/brctl-show.txt
2026-01-26 07:10:26.337701 | instance | >f+++++++++ system/docker-images.txt
2026-01-26 07:10:26.337729 | instance | >f+++++++++ system/ip-addr.txt
2026-01-26 07:10:26.337762 | instance | >f+++++++++ system/ip-route.txt
2026-01-26 07:10:26.337792 | instance | >f+++++++++ system/lsblk.txt
2026-01-26 07:10:26.337820 | instance | >f+++++++++ system/mount.txt
2026-01-26 07:10:26.337850 | instance | >f+++++++++ system/packages.txt
2026-01-26 07:10:26.337877 | instance | >f+++++++++ system/ps.txt
2026-01-26 07:10:26.337915 | instance | >f+++++++++ system/systemd-cgls.txt
2026-01-26 07:10:26.348279 | 
2026-01-26 07:10:26.348347 | LOOP [helm-release-status : creating directory for helm release status]
2026-01-26 07:10:26.527580 | instance | changed: "values"
2026-01-26 07:10:26.682933 | instance | changed: "releases"
2026-01-26 07:10:26.700039 | 
2026-01-26 07:10:26.700231 | TASK [helm-release-status : Gather get release status for helm charts]
2026-01-26 07:10:26.906351 | instance | /bin/bash: line 3: kubectl: command not found
2026-01-26 07:10:27.237894 | instance | ok: Runtime: 0:00:00.004696
2026-01-26 07:10:27.245834 | 
2026-01-26 07:10:27.245928 | TASK [helm-release-status : Downloads logs to executor]
2026-01-26 07:10:27.721296 | instance | changed:
2026-01-26 07:10:27.721525 | instance | cd+++++++++ helm/
2026-01-26 07:10:27.721556 | instance | cd+++++++++ helm/releases/
2026-01-26 07:10:27.721577 | instance | cd+++++++++ helm/values/
2026-01-26 07:10:27.730828 | 
2026-01-26 07:10:27.730898 | TASK [describe-kubernetes-objects : creating directory for cluster scoped objects]
2026-01-26 07:10:27.921103 | instance | changed
2026-01-26 07:10:27.926830 | 
2026-01-26 07:10:27.926901 | TASK [describe-kubernetes-objects : Gathering descriptions for cluster scoped objects]
2026-01-26 07:10:28.138198 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-01-26 07:10:28.138425 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-01-26 07:10:28.143166 | instance | environment: line 1: kubectl: command not found
2026-01-26 07:10:28.144467 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-01-26 07:10:28.144872 | instance | environment: line 1: kubectl: command not found
2026-01-26 07:10:28.145494 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-01-26 07:10:28.147158 | instance | environment: line 1: kubectl: command not found
2026-01-26 07:10:28.148794 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-01-26 07:10:28.148931 | instance | environment: line 1: kubectl: command not found
2026-01-26 07:10:28.149612 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-01-26 07:10:28.150609 | instance | environment: line 1: kubectl: command not found
2026-01-26 07:10:28.151085 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-01-26 07:10:28.465690 | instance | ok: Runtime: 0:00:00.020531
2026-01-26 07:10:28.470920 | 
2026-01-26 07:10:28.470986 | TASK [describe-kubernetes-objects : creating directory for namespace scoped objects]
2026-01-26 07:10:28.659551 | instance | changed
2026-01-26 07:10:28.666159 | 
2026-01-26 07:10:28.666229 | TASK [describe-kubernetes-objects : Gathering descriptions for namespace scoped objects]
2026-01-26 07:10:28.905879 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-01-26 07:10:28.906670 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-01-26 07:10:28.906886 | instance | environment: line 5: kubectl: command not found
2026-01-26 07:10:28.907473 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-01-26 07:10:29.233896 | instance | ok: Runtime: 0:00:00.007985
2026-01-26 07:10:29.240511 | 
2026-01-26 07:10:29.240580 | TASK [describe-kubernetes-objects : Downloads logs to executor]
2026-01-26 07:10:29.744017 | instance | changed:
2026-01-26 07:10:29.744228 | instance | cd+++++++++ objects/
2026-01-26 07:10:29.744270 | instance | cd+++++++++ objects/cluster/
2026-01-26 07:10:29.744292 | instance | cd+++++++++ objects/namespaced/
2026-01-26 07:10:29.753457 | 
2026-01-26 07:10:29.753520 | TASK [gather-pod-logs : creating directory for pod logs]
2026-01-26 07:10:29.946468 | instance | changed
2026-01-26 07:10:29.951465 | 
2026-01-26 07:10:29.951532 | TASK [gather-pod-logs : creating directory for failed pod logs]
2026-01-26 07:10:30.143202 | instance | changed
2026-01-26 07:10:30.149049 | 
2026-01-26 07:10:30.149117 | TASK [gather-pod-logs : retrieve all kubernetes logs, current and previous (if they exist)]
2026-01-26 07:10:30.350846 | instance | environment: line 3: kubectl: command not found
2026-01-26 07:10:30.682955 | instance | ok: Runtime: 0:00:00.007128
2026-01-26 07:10:30.688900 | 
2026-01-26 07:10:30.688983 | TASK [gather-pod-logs : Downloads pod logs to executor]
2026-01-26 07:10:31.186384 | instance | changed:
2026-01-26 07:10:31.186594 | instance | cd+++++++++ pod-logs/
2026-01-26 07:10:31.186632 | instance | cd+++++++++ pod-logs/failed-pods/
2026-01-26 07:10:31.197209 | 
2026-01-26 07:10:31.197270 | TASK [gather-prom-metrics : creating directory for helm release descriptions]
2026-01-26 07:10:31.384972 | instance | changed
2026-01-26 07:10:31.390302 | 
2026-01-26 07:10:31.390375 | TASK [gather-prom-metrics : Get metrics from exporter services in all namespaces]
2026-01-26 07:10:31.592673 | instance | /bin/bash: line 2: kubectl: command not found
2026-01-26 07:10:31.923675 | instance | ok: Runtime: 0:00:00.029221
2026-01-26 07:10:31.929821 | 
2026-01-26 07:10:31.929897 | TASK [gather-prom-metrics : Get ceph metrics from ceph-mgr]
2026-01-26 07:10:32.127648 | instance | /bin/bash: line 2: kubectl: command not found
2026-01-26 07:10:32.149722 | instance | ceph-mgr endpoints:
2026-01-26 07:10:32.463153 | instance | ok: Runtime: 0:00:00.026998
2026-01-26 07:10:32.468434 | 
2026-01-26 07:10:32.468503 | TASK [gather-prom-metrics : Get metrics from fluentd pods]
2026-01-26 07:10:32.668685 | instance | /bin/bash: line 4: kubectl: command not found
2026-01-26 07:10:33.004535 | instance | ok: Runtime: 0:00:00.030666
2026-01-26 07:10:33.009596 | 
2026-01-26 07:10:33.009664 | TASK [gather-prom-metrics : Downloads logs to executor]
2026-01-26 07:10:33.478571 | instance | changed: cd+++++++++ prometheus/
2026-01-26 07:10:33.488621 | 
2026-01-26 07:10:33.488686 | TASK [gather-selenium-data : creating directory for helm release descriptions]
2026-01-26 07:10:33.676035 | instance | changed
2026-01-26 07:10:33.681597 | 
2026-01-26 07:10:33.681659 | TASK [gather-selenium-data : Get selenium data]
2026-01-26 07:10:33.883751 | instance | + cp '/tmp/artifacts/*' /tmp/logs/selenium/.
2026-01-26 07:10:33.885400 | instance | cp: cannot stat '/tmp/artifacts/*': No such file or directory
2026-01-26 07:10:34.214889 | instance | ERROR
2026-01-26 07:10:34.215156 | instance | {
2026-01-26 07:10:34.215198 | instance |   "delta": "0:00:00.005846",
2026-01-26 07:10:34.215228 | instance |   "end": "2026-01-26 07:10:33.885694",
2026-01-26 07:10:34.215254 | instance |   "msg": "non-zero return code",
2026-01-26 07:10:34.215279 | instance |   "rc": 1,
2026-01-26 07:10:34.215304 | instance |   "start": "2026-01-26 07:10:33.879848"
2026-01-26 07:10:34.215328 | instance | }
2026-01-26 07:10:34.215359 | instance | ERROR: Ignoring Errors
2026-01-26 07:10:34.221865 | 
2026-01-26 07:10:34.221931 | TASK [gather-selenium-data : Downloads logs to executor]
2026-01-26 07:10:34.702950 | instance | changed: cd+++++++++ selenium/
2026-01-26 07:10:34.709794 | 
2026-01-26 07:10:34.709847 | PLAY RECAP
2026-01-26 07:10:34.709897 | instance | ok: 23 changed: 23 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 1
2026-01-26 07:10:34.709918 | 
2026-01-26 07:10:34.838995 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@main]
2026-01-26 07:10:34.843134 | POST-RUN START: [trusted : vexxhost.dev/zuul-config/playbooks/base/post.yaml@main]
2026-01-26 07:10:35.436149 | 
2026-01-26 07:10:35.436825 | PLAY [all]
2026-01-26 07:10:35.447863 | 
2026-01-26 07:10:35.447934 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-26 07:10:35.493769 | instance | skipping: Conditional result was False
2026-01-26 07:10:35.503286 | 
2026-01-26 07:10:35.503390 | TASK [fetch-output : Set log path for single node]
2026-01-26 07:10:35.536607 | instance | ok
2026-01-26 07:10:35.542565 | 
2026-01-26 07:10:35.542629 | LOOP [fetch-output : Ensure local output dirs]
2026-01-26 07:10:35.915264 | instance -> localhost | ok: "/var/lib/zuul/builds/423107f678a6490eac05f1a6ae5669e8/work/logs"
2026-01-26 07:10:36.127091 | instance -> localhost | changed: "/var/lib/zuul/builds/423107f678a6490eac05f1a6ae5669e8/work/artifacts"
2026-01-26 07:10:36.342756 | instance -> localhost | changed: "/var/lib/zuul/builds/423107f678a6490eac05f1a6ae5669e8/work/docs"
2026-01-26 07:10:36.358322 | 
2026-01-26 07:10:36.358516 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-26 07:10:36.995134 | instance | changed: .d..t...... ./
2026-01-26 07:10:36.995373 | instance | changed: All items complete
2026-01-26 07:10:36.995400 | 
2026-01-26 07:10:37.452790 | instance | changed: .d..t...... ./
2026-01-26 07:10:37.909484 | instance | changed: .d..t...... ./
2026-01-26 07:10:37.924349 | 
2026-01-26 07:10:37.924527 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-26 07:10:38.332882 | instance -> localhost | ok: Item: artifacts Runtime: 0:00:00.007003
2026-01-26 07:10:38.569446 | instance -> localhost | ok: Item: docs Runtime: 0:00:00.007254
2026-01-26 07:10:38.590788 | 
2026-01-26 07:10:38.590895 | PLAY [all]
2026-01-26 07:10:38.596604 | 
2026-01-26 07:10:38.596664 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-01-26 07:10:39.004586 | instance | changed
2026-01-26 07:10:39.012034 | 
2026-01-26 07:10:39.012086 | PLAY RECAP
2026-01-26 07:10:39.012131 | instance | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-01-26 07:10:39.012152 | 
2026-01-26 07:10:39.133034 | POST-RUN END RESULT_NORMAL: [trusted : vexxhost.dev/zuul-config/playbooks/base/post.yaml@main]
2026-01-26 07:10:39.137221 | POST-RUN START: [trusted : vexxhost.dev/zuul-config/playbooks/base/post-logs.yaml@main]
2026-01-26 07:10:39.691016 | 
2026-01-26 07:10:39.691138 | PLAY [localhost]
2026-01-26 07:10:39.701003 | 
2026-01-26 07:10:39.701070 | TASK [Generate Zuul manifest]
2026-01-26 07:10:39.720888 | localhost | ok
2026-01-26 07:10:39.737808 | 
2026-01-26 07:10:39.737889 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-26 07:10:40.103237 | localhost | changed
2026-01-26 07:10:40.115791 | 
2026-01-26 07:10:40.115865 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-26 07:10:40.145275 | localhost | ok
2026-01-26 07:10:40.154143 | 
2026-01-26 07:10:40.154403 | TASK [Upload logs]
2026-01-26 07:10:40.176478 | localhost | ok
2026-01-26 07:10:40.252008 | 
2026-01-26 07:10:40.252261 | TASK [Set zuul-log-path fact]
2026-01-26 07:10:40.277798 | localhost | ok
2026-01-26 07:10:40.294959 | 
2026-01-26 07:10:40.295029 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-26 07:10:40.328484 | localhost | ok
2026-01-26 07:10:40.338740 | 
2026-01-26 07:10:40.338918 | TASK [upload-logs : Create log directories]
2026-01-26 07:10:40.723354 | localhost | changed
2026-01-26 07:10:40.728794 | 
2026-01-26 07:10:40.728863 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-01-26 07:10:41.135188 | localhost -> localhost | ok: Runtime: 0:00:00.006081
2026-01-26 07:10:41.141372 | 
2026-01-26 07:10:41.141435 | TASK [upload-logs : Upload logs to log server]
2026-01-26 07:10:41.586076 | localhost | Output suppressed because no_log was given
2026-01-26 07:10:41.592254 | 
2026-01-26 07:10:41.592322 | LOOP [upload-logs : Compress console log and json output]
2026-01-26 07:10:41.638932 | localhost | skipping: Conditional result was False
2026-01-26 07:10:41.642607 | localhost | skipping: Conditional result was False
2026-01-26 07:10:41.659056 | 
2026-01-26 07:10:41.659173 | LOOP [upload-logs : Upload compressed console log and json output]
2026-01-26 07:10:41.706374 | localhost | skipping: Conditional result was False
2026-01-26 07:10:41.706743 | 
2026-01-26 07:10:41.710191 | localhost | skipping: Conditional result was False
2026-01-26 07:10:41.723583 | 
2026-01-26 07:10:41.723673 | LOOP [upload-logs : Upload console log and json output]