2026-01-26 02:47:03.961973 | Job console starting
2026-01-26 02:47:03.972508 | Updating git repos
2026-01-26 02:47:04.047685 | Cloning repos into workspace
2026-01-26 02:47:04.126589 | Restoring repo states
2026-01-26 02:47:04.156140 | Merging changes
2026-01-26 02:47:05.197179 | Checking out repos
2026-01-26 02:47:05.334273 | Preparing playbooks
2026-01-26 02:47:08.704020 | Running Ansible setup
2026-01-26 02:47:12.339739 | PRE-RUN START: [trusted : vexxhost.dev/zuul-config/playbooks/base/pre.yaml@main]
2026-01-26 02:47:13.021080 | 
2026-01-26 02:47:13.021229 | PLAY [localhost]
2026-01-26 02:47:13.032690 | 
2026-01-26 02:47:13.032765 | TASK [Gathering Facts]
2026-01-26 02:47:13.928705 | localhost | ok
2026-01-26 02:47:13.938829 | 
2026-01-26 02:47:13.938919 | TASK [Setup log path fact]
2026-01-26 02:47:13.958960 | localhost | ok
2026-01-26 02:47:13.972579 | 
2026-01-26 02:47:13.972670 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-26 02:47:14.002450 | localhost | ok
2026-01-26 02:47:14.010917 | 
2026-01-26 02:47:14.011020 | TASK [emit-job-header : Print job information]
2026-01-26 02:47:14.052662 | # Job Information
2026-01-26 02:47:14.052889 | Ansible Version: 2.16.15
2026-01-26 02:47:14.052989 | Job: atmosphere-molecule-csi-local-path-provisioner
2026-01-26 02:47:14.053048 | Pipeline: check
2026-01-26 02:47:14.053094 | Executor: 3a2793d2bd32
2026-01-26 02:47:14.053137 | Triggered by: https://github.com/vexxhost/atmosphere/pull/3297
2026-01-26 02:47:14.053186 | Event ID: 2afcd5f0-fa61-11f0-8174-da289b5141fa
2026-01-26 02:47:14.058065 | 
2026-01-26 02:47:14.058130 | LOOP [emit-job-header : Print node information]
2026-01-26 02:47:14.158285 | localhost | ok:
2026-01-26 02:47:14.159221 | localhost | # Node Information
2026-01-26 02:47:14.159277 | localhost | Inventory Hostname: instance
2026-01-26 02:47:14.159315 | localhost | Hostname: np0000154458
2026-01-26 02:47:14.159350 | localhost | Username: zuul
2026-01-26 02:47:14.159391 | localhost | Distro: Ubuntu 22.04
2026-01-26 02:47:14.159425 | localhost | Provider: yul1
2026-01-26 02:47:14.159458 | localhost | Region: ca-ymq-1
2026-01-26 02:47:14.159491 | localhost | Label: ubuntu-jammy
2026-01-26 02:47:14.159520 | localhost | Product Name: OpenStack Nova
2026-01-26 02:47:14.159552 | localhost | Interface IP: 162.253.55.209
2026-01-26 02:47:14.178086 | 
2026-01-26 02:47:14.178244 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-26 02:47:14.588617 | localhost -> localhost | changed
2026-01-26 02:47:14.596356 | 
2026-01-26 02:47:14.596477 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-26 02:47:15.530159 | localhost -> localhost | changed
2026-01-26 02:47:15.548085 | 
2026-01-26 02:47:15.548209 | PLAY [all]
2026-01-26 02:47:15.556302 | 
2026-01-26 02:47:15.556376 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-26 02:47:15.793341 | instance -> localhost | ok
2026-01-26 02:47:15.800618 | 
2026-01-26 02:47:15.800687 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-26 02:47:15.832447 | instance | ok
2026-01-26 02:47:15.847491 | instance | included: /var/lib/zuul/builds/a1bb55cb70e647478678b9555a0e653c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-26 02:47:15.853455 | 
2026-01-26 02:47:15.853521 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-26 02:47:16.514467 | instance -> localhost | Generating public/private rsa key pair.
2026-01-26 02:47:16.514693 | instance -> localhost | Your identification has been saved in /var/lib/zuul/builds/a1bb55cb70e647478678b9555a0e653c/work/a1bb55cb70e647478678b9555a0e653c_id_rsa
2026-01-26 02:47:16.514730 | instance -> localhost | Your public key has been saved in /var/lib/zuul/builds/a1bb55cb70e647478678b9555a0e653c/work/a1bb55cb70e647478678b9555a0e653c_id_rsa.pub
2026-01-26 02:47:16.514760 | instance -> localhost | The key fingerprint is:
2026-01-26 02:47:16.514786 | instance -> localhost | SHA256:C93fpfcX5Hm64jWNG/JXSeJlPEHlq0mN5zOeI6cmLbM zuul-build-sshkey
2026-01-26 02:47:16.514830 | instance -> localhost | The key's randomart image is:
2026-01-26 02:47:16.514856 | instance -> localhost | +---[RSA 3072]----+
2026-01-26 02:47:16.514885 | instance -> localhost | |              ..o|
2026-01-26 02:47:16.514911 | instance -> localhost | |               o |
2026-01-26 02:47:16.514936 | instance -> localhost | |              . o|
2026-01-26 02:47:16.514961 | instance -> localhost | |       . .   .oB.|
2026-01-26 02:47:16.514985 | instance -> localhost | |      . S . .oB+=|
2026-01-26 02:47:16.515009 | instance -> localhost | |       . . ..o=Xo|
2026-01-26 02:47:16.515033 | instance -> localhost | |        .   +oB=*|
2026-01-26 02:47:16.515057 | instance -> localhost | |           +.BoBB|
2026-01-26 02:47:16.515084 | instance -> localhost | |           EBoB=+|
2026-01-26 02:47:16.515109 | instance -> localhost | +----[SHA256]-----+
2026-01-26 02:47:16.515169 | instance -> localhost | ok: Runtime: 0:00:00.243391
2026-01-26 02:47:16.521906 | 
2026-01-26 02:47:16.521973 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-26 02:47:16.551987 | instance | ok
2026-01-26 02:47:16.561294 | instance | included: /var/lib/zuul/builds/a1bb55cb70e647478678b9555a0e653c/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-26 02:47:16.570980 | 
2026-01-26 02:47:16.571044 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-26 02:47:16.595992 | instance | skipping: Conditional result was False
2026-01-26 02:47:16.605959 | 
2026-01-26 02:47:16.606161 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-26 02:47:17.123048 | instance | changed
2026-01-26 02:47:17.128117 | 
2026-01-26 02:47:17.128184 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-26 02:47:17.315358 | instance | ok
2026-01-26 02:47:17.321939 | 
2026-01-26 02:47:17.322055 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-26 02:47:17.775375 | instance | changed
2026-01-26 02:47:17.780539 | 
2026-01-26 02:47:17.780603 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-26 02:47:18.251627 | instance | changed
2026-01-26 02:47:18.256694 | 
2026-01-26 02:47:18.256756 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-26 02:47:18.281930 | instance | skipping: Conditional result was False
2026-01-26 02:47:18.293803 | 
2026-01-26 02:47:18.293894 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-26 02:47:18.710264 | instance -> localhost | changed
2026-01-26 02:47:18.727037 | 
2026-01-26 02:47:18.727126 | TASK [add-build-sshkey : Add back temp key]
2026-01-26 02:47:19.035042 | instance -> localhost | Identity added: /var/lib/zuul/builds/a1bb55cb70e647478678b9555a0e653c/work/a1bb55cb70e647478678b9555a0e653c_id_rsa (zuul-build-sshkey)
2026-01-26 02:47:19.035300 | instance -> localhost | ok: Runtime: 0:00:00.016226
2026-01-26 02:47:19.040117 | 
2026-01-26 02:47:19.040181 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-26 02:47:19.468570 | instance | ok
2026-01-26 02:47:19.476637 | 
2026-01-26 02:47:19.476714 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-26 02:47:19.501966 | instance | skipping: Conditional result was False
2026-01-26 02:47:19.516860 | 
2026-01-26 02:47:19.516932 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-26 02:47:19.844095 | instance | ok
2026-01-26 02:47:19.851682 | 
2026-01-26 02:47:19.851748 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-26 02:47:21.491674 | instance | Output suppressed because no_log was given
2026-01-26 02:47:21.507554 | 
2026-01-26 02:47:21.507739 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-26 02:47:21.692312 | instance | ok: "logs"
2026-01-26 02:47:21.692628 | instance | ok: All items complete
2026-01-26 02:47:21.692664 | 
2026-01-26 02:47:21.859497 | instance | ok: "artifacts"
2026-01-26 02:47:22.055469 | instance | ok: "docs"
2026-01-26 02:47:22.071176 | 
2026-01-26 02:47:22.071387 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-26 02:47:22.258619 | instance | changed: "logs"
2026-01-26 02:47:22.424668 | instance | changed: "artifacts"
2026-01-26 02:47:22.595903 | instance | changed: "docs"
2026-01-26 02:47:22.613287 | 
2026-01-26 02:47:22.613430 | PLAY RECAP
2026-01-26 02:47:22.613488 | instance | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2026-01-26 02:47:22.613516 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-26 02:47:22.613540 | 
2026-01-26 02:47:22.801710 | PRE-RUN END RESULT_NORMAL: [trusted : vexxhost.dev/zuul-config/playbooks/base/pre.yaml@main]
2026-01-26 02:47:22.806190 | PRE-RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-01-26 02:47:23.355768 | 
2026-01-26 02:47:23.355927 | PLAY [all]
2026-01-26 02:47:23.367867 | 
2026-01-26 02:47:23.367982 | TASK [setup-uv : Extract archive]
2026-01-26 02:47:25.831463 | instance | changed
2026-01-26 02:47:25.838474 | 
2026-01-26 02:47:25.838569 | TASK [setup-uv : Print version]
2026-01-26 02:47:25.747138 | instance | uv 0.8.13
2026-01-26 02:47:26.377019 | instance | ok: Runtime: 0:00:00.011350
2026-01-26 02:47:26.385653 | 
2026-01-26 02:47:26.385714 | PLAY RECAP
2026-01-26 02:47:26.385760 | instance | ok: 2 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-26 02:47:26.385803 | 
2026-01-26 02:47:26.562763 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-01-26 02:47:26.567581 | PRE-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@main]
2026-01-26 02:47:27.227438 | 
2026-01-26 02:47:27.227640 | PLAY [all]
2026-01-26 02:47:27.239506 | 
2026-01-26 02:47:27.239586 | TASK [Install "jq" for log collection]
2026-01-26 02:47:36.061825 | instance | changed
2026-01-26 02:47:36.064202 | 
2026-01-26 02:47:36.064260 | PLAY RECAP
2026-01-26 02:47:36.064311 | instance | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-26 02:47:36.064363 | 
2026-01-26 02:47:36.207285 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@main]
2026-01-26 02:47:36.209841 | RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-01-26 02:47:36.839950 | 
2026-01-26 02:47:36.840192 | PLAY [all]
2026-01-26 02:47:36.852900 | 
2026-01-26 02:47:36.853097 | TASK [Copy inventory file for Zuul]
2026-01-26 02:47:37.666744 | instance | changed
2026-01-26 02:47:37.673291 | 
2026-01-26 02:47:37.673401 | TASK [Switch "ansible_host" to private IP]
2026-01-26 02:47:37.964046 | instance | changed: 1 replacements made
2026-01-26 02:47:37.972370 | 
2026-01-26 02:47:37.972485 | TASK [Run Molecule scenario]
2026-01-26 02:47:38.359458 | instance | Using CPython 3.10.12 interpreter at: /usr/bin/python3
2026-01-26 02:47:38.359655 | instance | Creating virtual environment at: .venv
2026-01-26 02:47:38.389253 | instance |    Building atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere
2026-01-26 02:47:38.441711 | instance | Downloading kubernetes (1.9MiB)
2026-01-26 02:47:38.442060 | instance | Downloading cryptography (4.2MiB)
2026-01-26 02:47:38.443313 | instance | Downloading setuptools (1.1MiB)
2026-01-26 02:47:38.443750 | instance | Downloading openstacksdk (1.7MiB)
2026-01-26 02:47:38.444571 | instance | Downloading netaddr (2.2MiB)
2026-01-26 02:47:38.446269 | instance | Downloading pygments (1.2MiB)
2026-01-26 02:47:38.463579 | instance | Downloading rjsonnet (1.2MiB)
2026-01-26 02:47:38.464570 | instance | Downloading ansible-core (2.1MiB)
2026-01-26 02:47:38.729462 | instance |    Building pyperclip==1.9.0
2026-01-26 02:47:38.769261 | instance |  Downloading rjsonnet
2026-01-26 02:47:38.894948 | instance |  Downloading netaddr
2026-01-26 02:47:38.911249 | instance |  Downloading pygments
2026-01-26 02:47:38.928720 | instance |  Downloading cryptography
2026-01-26 02:47:38.977402 | instance |  Downloading setuptools
2026-01-26 02:47:39.044274 | instance |  Downloading kubernetes
2026-01-26 02:47:39.074090 | instance |  Downloading ansible-core
2026-01-26 02:47:39.082787 | instance |  Downloading openstacksdk
2026-01-26 02:47:39.482112 | instance |       Built pyperclip==1.9.0
2026-01-26 02:47:39.700855 | instance |       Built atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere
2026-01-26 02:47:39.758698 | instance | Installed 79 packages in 56ms
2026-01-26 02:47:40.365150 | instance | WARNING  Molecule scenarios should migrate to 'extensions/molecule'
2026-01-26 02:47:40.918251 | instance | INFO     [csi > discovery] scenario test matrix: dependency, cleanup, destroy, syntax, create, prepare, converge, idempotence, side_effect, verify, cleanup, destroy
2026-01-26 02:47:40.918390 | instance | INFO     [csi > prerun] Performing prerun with role_name_check=0...
2026-01-26 02:47:42.677296 | instance | WARNING  Retrying execution failure 1 of: ansible-galaxy collection install -vvv ansible.netcommon:1.2.0
2026-01-26 02:47:42.677397 | instance | ERROR    Command ansible-galaxy collection install -vvv ansible.netcommon:1.2.0, returned 1 code:
2026-01-26 02:47:42.677411 | instance | Starting galaxy collection install process
2026-01-26 02:47:42.677421 | instance | Process install dependency map
2026-01-26 02:47:42.677432 | instance |
2026-01-26 02:47:42.677441 | instance | ansible-galaxy
2026-01-26 02:47:42.677450 | instance |   config file = None
2026-01-26 02:47:42.677459 | instance |   configured module search path =
2026-01-26 02:47:42.677468 | instance |   ansible python module location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/ansible
2026-01-26 02:47:42.677479 | 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 02:47:42.677509 | instance |   executable location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/ansible-galaxy
2026-01-26 02:47:42.677518 | 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 02:47:42.677528 | instance |   jinja version = 3.1.6
2026-01-26 02:47:42.677537 | instance |   libyaml = True
2026-01-26 02:47:42.677546 | instance | No config file found; using defaults
2026-01-26 02:47:42.677554 | instance | Created /home/zuul/.ansible/galaxy_token
2026-01-26 02:47:42.677565 | 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 02:47:42.677581 | instance |
2026-01-26 02:47:42.677589 | instance | Traceback (most recent call last):
2026-01-26 02:47:42.677598 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/molecule", line 10, in <module>
2026-01-26 02:47:42.677607 | instance |     sys.exit(main())
2026-01-26 02:47:42.677616 | 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 02:47:42.677649 | instance |     return self.main(*args, **kwargs)
2026-01-26 02:47:42.677659 | 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 02:47:42.677668 | instance |     rv = self.invoke(ctx)
2026-01-26 02:47:42.677965 | 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 02:47:42.678779 | instance |     return _process_result(sub_ctx.command.invoke(sub_ctx))
2026-01-26 02:47:42.679154 | 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 02:47:42.679850 | instance |     return ctx.invoke(self.callback, **ctx.params)
2026-01-26 02:47:42.680195 | 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 02:47:42.680768 | instance |     return callback(*args, **kwargs)
2026-01-26 02:47:42.681115 | 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 02:47:42.681709 | instance |     return func(*args, **kwargs)
2026-01-26 02:47:42.682063 | 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 02:47:42.682478 | instance |     return f(get_current_context(), *args, **kwargs)
2026-01-26 02:47:42.682817 | 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 02:47:42.683308 | instance |     return func(ctx)
2026-01-26 02:47:42.683647 | 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 02:47:42.684093 | instance |     base.execute_cmdline_scenarios(scenario_name, args, command_args, ansible_args, exclude)
2026-01-26 02:47:42.684436 | 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 02:47:42.684893 | instance |     _run_scenarios(scenarios, command_args, default_config)
2026-01-26 02:47:42.685285 | 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 02:47:42.685831 | instance |     scenario.config.runtime.prepare_environment(
2026-01-26 02:47:42.686021 | 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 02:47:42.686285 | instance |     self.install_collection(
2026-01-26 02:47:42.686439 | 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 02:47:42.686681 | instance |     raise InvalidPrerequisiteError(msg)
2026-01-26 02:47:42.687342 | instance | ansible_compat.errors.InvalidPrerequisiteError: Command ansible-galaxy collection install -vvv ansible.netcommon:1.2.0, returned 1 code:
2026-01-26 02:47:42.687353 | instance | Starting galaxy collection install process
2026-01-26 02:47:42.687358 | instance | Process install dependency map
2026-01-26 02:47:42.687362 | instance |
2026-01-26 02:47:42.687366 | instance | ansible-galaxy [core 2.17.12]
2026-01-26 02:47:42.687370 | instance |   config file = None
2026-01-26 02:47:42.687374 | 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 02:47:42.687379 | instance |   ansible python module location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/ansible
2026-01-26 02:47:42.687383 | 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 02:47:42.687394 | instance |   executable location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/ansible-galaxy
2026-01-26 02:47:42.687398 | 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 02:47:42.687402 | instance |   jinja version = 3.1.6
2026-01-26 02:47:42.687406 | instance |   libyaml = True
2026-01-26 02:47:42.687410 | instance | No config file found; using defaults
2026-01-26 02:47:42.687414 | instance | Created /home/zuul/.ansible/galaxy_token
2026-01-26 02:47:42.687418 | 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 02:47:42.687561 | instance |
2026-01-26 02:47:43.019363 | instance | ERROR
2026-01-26 02:47:43.019702 | instance | {
2026-01-26 02:47:43.019760 | instance |   "delta": "0:00:04.471178",
2026-01-26 02:47:43.019800 | instance |   "end": "2026-01-26 02:47:42.777604",
2026-01-26 02:47:43.019834 | instance |   "msg": "non-zero return code",
2026-01-26 02:47:43.019866 | instance |   "rc": 1,
2026-01-26 02:47:43.019902 | instance |   "start": "2026-01-26 02:47:38.306426"
2026-01-26 02:47:43.019935 | instance | }
failure
2026-01-26 02:47:43.023247 | 
2026-01-26 02:47:43.023314 | PLAY RECAP
2026-01-26 02:47:43.023385 | instance | ok: 2 changed: 2 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0
2026-01-26 02:47:43.023423 | 
2026-01-26 02:47:43.231313 | RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-01-26 02:47:43.234573 | POST-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@main]
2026-01-26 02:47:43.870678 | 
2026-01-26 02:47:43.870819 | PLAY [all]
2026-01-26 02:47:43.886697 | 
2026-01-26 02:47:43.886826 | TASK [gather-host-logs : creating directory for system status]
2026-01-26 02:47:44.217150 | instance | changed
2026-01-26 02:47:44.223015 | 
2026-01-26 02:47:44.223116 | TASK [gather-host-logs : Get logs for each host]
2026-01-26 02:47:44.576729 | instance | + systemd-cgls --full --all --no-pager
2026-01-26 02:47:44.582835 | instance | + ip addr
2026-01-26 02:47:44.584386 | instance | + ip route
2026-01-26 02:47:44.585819 | instance | + lsblk
2026-01-26 02:47:44.588320 | instance | + mount
2026-01-26 02:47:44.589884 | instance | + docker images
2026-01-26 02:47:44.590223 | instance | /bin/bash: line 7: docker: command not found
2026-01-26 02:47:44.590449 | instance | + brctl show
2026-01-26 02:47:44.590824 | instance | /bin/bash: line 8: brctl: command not found
2026-01-26 02:47:44.591045 | instance | + ps aux --sort=-%mem
2026-01-26 02:47:44.597574 | instance | + dpkg -l
2026-01-26 02:47:44.604178 | instance | + CONTAINERS=($(docker ps -a --format '{{ .Names }}' --filter label=zuul))
2026-01-26 02:47:44.604536 | instance | ++ docker ps -a --format '{{ .Names }}' --filter label=zuul
2026-01-26 02:47:44.604614 | instance | /bin/bash: line 11: docker: command not found
2026-01-26 02:47:44.604909 | instance | + '[' '!' -z '' ']'
2026-01-26 02:47:44.760853 | instance | ok: Runtime: 0:00:00.032732
2026-01-26 02:47:44.768497 | 
2026-01-26 02:47:44.768576 | TASK [gather-host-logs : Downloads logs to executor]
2026-01-26 02:47:45.425352 | instance | changed:
2026-01-26 02:47:45.425578 | instance | created directory /var/lib/zuul/builds/a1bb55cb70e647478678b9555a0e653c/work/logs/instance
2026-01-26 02:47:45.425627 | instance | cd+++++++++ system/
2026-01-26 02:47:45.425663 | instance | >f+++++++++ system/brctl-show.txt
2026-01-26 02:47:45.425699 | instance | >f+++++++++ system/docker-images.txt
2026-01-26 02:47:45.425733 | instance | >f+++++++++ system/ip-addr.txt
2026-01-26 02:47:45.425770 | instance | >f+++++++++ system/ip-route.txt
2026-01-26 02:47:45.425810 | instance | >f+++++++++ system/lsblk.txt
2026-01-26 02:47:45.425847 | instance | >f+++++++++ system/mount.txt
2026-01-26 02:47:45.425882 | instance | >f+++++++++ system/packages.txt
2026-01-26 02:47:45.425910 | instance | >f+++++++++ system/ps.txt
2026-01-26 02:47:45.425956 | instance | >f+++++++++ system/systemd-cgls.txt
2026-01-26 02:47:45.436853 | 
2026-01-26 02:47:45.436961 | LOOP [helm-release-status : creating directory for helm release status]
2026-01-26 02:47:45.653348 | instance | changed: "values"
2026-01-26 02:47:45.810298 | instance | changed: "releases"
2026-01-26 02:47:45.826085 | 
2026-01-26 02:47:45.826321 | TASK [helm-release-status : Gather get release status for helm charts]
2026-01-26 02:47:46.039573 | instance | /bin/bash: line 3: kubectl: command not found
2026-01-26 02:47:46.367975 | instance | ok: Runtime: 0:00:00.004721
2026-01-26 02:47:46.373921 | 
2026-01-26 02:47:46.373993 | TASK [helm-release-status : Downloads logs to executor]
2026-01-26 02:47:46.872573 | instance | changed:
2026-01-26 02:47:46.872739 | instance | cd+++++++++ helm/
2026-01-26 02:47:46.872768 | instance | cd+++++++++ helm/releases/
2026-01-26 02:47:46.872790 | instance | cd+++++++++ helm/values/
2026-01-26 02:47:46.881685 | 
2026-01-26 02:47:46.881754 | TASK [describe-kubernetes-objects : creating directory for cluster scoped objects]
2026-01-26 02:47:47.063674 | instance | changed
2026-01-26 02:47:47.070543 | 
2026-01-26 02:47:47.070642 | TASK [describe-kubernetes-objects : Gathering descriptions for cluster scoped objects]
2026-01-26 02:47:47.282877 | instance | xargs: xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-01-26 02:47:47.282940 | instance | warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-01-26 02:47:47.285796 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-01-26 02:47:47.286966 | instance | environment: line 1: kubectl: command not found
2026-01-26 02:47:47.288054 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-01-26 02:47:47.288265 | instance | environment: line 1: kubectl: command not found
2026-01-26 02:47:47.289761 | instance | environment: line 1: kubectl: command not found
2026-01-26 02:47:47.291714 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-01-26 02:47:47.291898 | instance | environment: line 1: kubectl: command not found
2026-01-26 02:47:47.292681 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-01-26 02:47:47.293649 | instance | environment: line 1: kubectl: command not found
2026-01-26 02:47:47.294236 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-01-26 02:47:47.616345 | instance | ok: Runtime: 0:00:00.019208
2026-01-26 02:47:47.623181 | 
2026-01-26 02:47:47.623326 | TASK [describe-kubernetes-objects : creating directory for namespace scoped objects]
2026-01-26 02:47:47.810375 | instance | changed
2026-01-26 02:47:47.815579 | 
2026-01-26 02:47:47.815695 | TASK [describe-kubernetes-objects : Gathering descriptions for namespace scoped objects]
2026-01-26 02:47:48.066428 | instance | xargs: xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-01-26 02:47:48.066494 | instance | warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-01-26 02:47:48.066705 | instance | environment: line 5: kubectl: command not found
2026-01-26 02:47:48.067725 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-01-26 02:47:48.407082 | instance | ok: Runtime: 0:00:00.007660
2026-01-26 02:47:48.414876 | 
2026-01-26 02:47:48.414984 | TASK [describe-kubernetes-objects : Downloads logs to executor]
2026-01-26 02:47:48.937641 | instance | changed:
2026-01-26 02:47:48.937893 | instance | cd+++++++++ objects/
2026-01-26 02:47:48.937958 | instance | cd+++++++++ objects/cluster/
2026-01-26 02:47:48.937992 | instance | cd+++++++++ objects/namespaced/
2026-01-26 02:47:48.950812 | 
2026-01-26 02:47:48.950919 | TASK [gather-pod-logs : creating directory for pod logs]
2026-01-26 02:47:49.149189 | instance | changed
2026-01-26 02:47:49.154210 | 
2026-01-26 02:47:49.154280 | TASK [gather-pod-logs : creating directory for failed pod logs]
2026-01-26 02:47:49.350262 | instance | changed
2026-01-26 02:47:49.357404 | 
2026-01-26 02:47:49.357485 | TASK [gather-pod-logs : retrieve all kubernetes logs, current and previous (if they exist)]
2026-01-26 02:47:49.563090 | instance | environment: line 3: kubectl: command not found
2026-01-26 02:47:49.893434 | instance | ok: Runtime: 0:00:00.008051
2026-01-26 02:47:49.906378 | 
2026-01-26 02:47:49.906559 | TASK [gather-pod-logs : Downloads pod logs to executor]
2026-01-26 02:47:50.406771 | instance | changed:
2026-01-26 02:47:50.407005 | instance | cd+++++++++ pod-logs/
2026-01-26 02:47:50.407047 | instance | cd+++++++++ pod-logs/failed-pods/
2026-01-26 02:47:50.418679 | 
2026-01-26 02:47:50.418833 | TASK [gather-prom-metrics : creating directory for helm release descriptions]
2026-01-26 02:47:50.608599 | instance | changed
2026-01-26 02:47:50.613897 | 
2026-01-26 02:47:50.613998 | TASK [gather-prom-metrics : Get metrics from exporter services in all namespaces]
2026-01-26 02:47:50.813603 | instance | /bin/bash: line 2: kubectl: command not found
2026-01-26 02:47:51.150890 | instance | ok: Runtime: 0:00:00.031256
2026-01-26 02:47:51.157526 | 
2026-01-26 02:47:51.157631 | TASK [gather-prom-metrics : Get ceph metrics from ceph-mgr]
2026-01-26 02:47:51.357841 | instance | /bin/bash: line 2: kubectl: command not found
2026-01-26 02:47:51.383178 | instance | ceph-mgr endpoints:
2026-01-26 02:47:51.698004 | instance | ok: Runtime: 0:00:00.030598
2026-01-26 02:47:51.702878 | 
2026-01-26 02:47:51.702948 | TASK [gather-prom-metrics : Get metrics from fluentd pods]
2026-01-26 02:47:51.895689 | instance | /bin/bash: line 4: kubectl: command not found
2026-01-26 02:47:52.240993 | instance | ok: Runtime: 0:00:00.030161
2026-01-26 02:47:52.246443 | 
2026-01-26 02:47:52.246523 | TASK [gather-prom-metrics : Downloads logs to executor]
2026-01-26 02:47:52.757850 | instance | changed: cd+++++++++ prometheus/
2026-01-26 02:47:52.774244 | 
2026-01-26 02:47:52.774499 | TASK [gather-selenium-data : creating directory for helm release descriptions]
2026-01-26 02:47:52.962779 | instance | changed
2026-01-26 02:47:52.968860 | 
2026-01-26 02:47:52.968936 | TASK [gather-selenium-data : Get selenium data]
2026-01-26 02:47:53.163039 | instance | + cp '/tmp/artifacts/*' /tmp/logs/selenium/.
2026-01-26 02:47:53.164318 | instance | cp: cannot stat '/tmp/artifacts/*': No such file or directory
2026-01-26 02:47:53.501999 | instance | ERROR
2026-01-26 02:47:53.502220 | instance | {
2026-01-26 02:47:53.502266 | instance |   "delta": "0:00:00.005663",
2026-01-26 02:47:53.502299 | instance |   "end": "2026-01-26 02:47:53.164542",
2026-01-26 02:47:53.502327 | instance |   "msg": "non-zero return code",
2026-01-26 02:47:53.502354 | instance |   "rc": 1,
2026-01-26 02:47:53.502379 | instance |   "start": "2026-01-26 02:47:53.158879"
2026-01-26 02:47:53.502404 | instance | }
2026-01-26 02:47:53.502439 | instance | ERROR: Ignoring Errors
2026-01-26 02:47:53.510174 | 
2026-01-26 02:47:53.510328 | TASK [gather-selenium-data : Downloads logs to executor]
2026-01-26 02:47:54.009818 | instance | changed: cd+++++++++ selenium/
2026-01-26 02:47:54.016267 | 
2026-01-26 02:47:54.016313 | PLAY RECAP
2026-01-26 02:47:54.016358 | instance | ok: 23 changed: 23 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 1
2026-01-26 02:47:54.016380 | 
2026-01-26 02:47:54.141172 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@main]
2026-01-26 02:47:54.143899 | POST-RUN START: [trusted : vexxhost.dev/zuul-config/playbooks/base/post.yaml@main]
2026-01-26 02:47:54.746403 | 
2026-01-26 02:47:54.746613 | PLAY [all]
2026-01-26 02:47:54.758995 | 
2026-01-26 02:47:54.759152 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-26 02:47:54.804908 | instance | skipping: Conditional result was False
2026-01-26 02:47:54.816140 | 
2026-01-26 02:47:54.816303 | TASK [fetch-output : Set log path for single node]
2026-01-26 02:47:54.859381 | instance | ok
2026-01-26 02:47:54.865259 | 
2026-01-26 02:47:54.865353 | LOOP [fetch-output : Ensure local output dirs]
2026-01-26 02:47:55.287082 | instance -> localhost | ok: "/var/lib/zuul/builds/a1bb55cb70e647478678b9555a0e653c/work/logs"
2026-01-26 02:47:55.514678 | instance -> localhost | changed: "/var/lib/zuul/builds/a1bb55cb70e647478678b9555a0e653c/work/artifacts"
2026-01-26 02:47:55.742794 | instance -> localhost | changed: "/var/lib/zuul/builds/a1bb55cb70e647478678b9555a0e653c/work/docs"
2026-01-26 02:47:55.760751 | 
2026-01-26 02:47:55.761171 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-26 02:47:56.421889 | instance | changed: .d..t...... ./
2026-01-26 02:47:56.422202 | instance | changed: All items complete
2026-01-26 02:47:56.422247 | 
2026-01-26 02:47:56.881808 | instance | changed: .d..t...... ./
2026-01-26 02:47:57.344649 | instance | changed: .d..t...... ./
2026-01-26 02:47:57.362876 | 
2026-01-26 02:47:57.363057 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-26 02:47:57.809041 | instance -> localhost | ok: Item: artifacts Runtime: 0:00:00.008631
2026-01-26 02:47:58.032136 | instance -> localhost | ok: Item: docs Runtime: 0:00:00.008978
2026-01-26 02:47:58.047191 | 
2026-01-26 02:47:58.047332 | PLAY [all]
2026-01-26 02:47:58.054153 | 
2026-01-26 02:47:58.054221 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-01-26 02:47:58.461279 | instance | changed
2026-01-26 02:47:58.467854 | 
2026-01-26 02:47:58.467910 | PLAY RECAP
2026-01-26 02:47:58.467961 | instance | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-01-26 02:47:58.467984 | 
2026-01-26 02:47:58.606529 | POST-RUN END RESULT_NORMAL: [trusted : vexxhost.dev/zuul-config/playbooks/base/post.yaml@main]
2026-01-26 02:47:58.609467 | POST-RUN START: [trusted : vexxhost.dev/zuul-config/playbooks/base/post-logs.yaml@main]
2026-01-26 02:47:59.232460 | 
2026-01-26 02:47:59.233130 | PLAY [localhost]
2026-01-26 02:47:59.243335 | 
2026-01-26 02:47:59.243421 | TASK [Generate Zuul manifest]
2026-01-26 02:47:59.262986 | localhost | ok
2026-01-26 02:47:59.282972 | 
2026-01-26 02:47:59.283172 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-26 02:47:59.619568 | localhost | changed
2026-01-26 02:47:59.631234 | 
2026-01-26 02:47:59.631337 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-26 02:47:59.662559 | localhost | ok
2026-01-26 02:47:59.670675 | 
2026-01-26 02:47:59.670743 | TASK [Upload logs]
2026-01-26 02:47:59.692463 | localhost | ok
2026-01-26 02:47:59.763105 | 
2026-01-26 02:47:59.763246 | TASK [Set zuul-log-path fact]
2026-01-26 02:47:59.785971 | localhost | ok
2026-01-26 02:47:59.798887 | 
2026-01-26 02:47:59.798998 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-26 02:47:59.831539 | localhost | ok
2026-01-26 02:47:59.840809 | 
2026-01-26 02:47:59.840903 | TASK [upload-logs : Create log directories]
2026-01-26 02:48:00.268116 | localhost | changed
2026-01-26 02:48:00.277470 | 
2026-01-26 02:48:00.277589 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-01-26 02:48:00.738045 | localhost -> localhost | ok: Runtime: 0:00:00.006536
2026-01-26 02:48:00.743125 | 
2026-01-26 02:48:00.743196 | TASK [upload-logs : Upload logs to log server]
2026-01-26 02:48:01.299694 | localhost | Output suppressed because no_log was given
2026-01-26 02:48:01.305155 | 
2026-01-26 02:48:01.305264 | LOOP [upload-logs : Compress console log and json output]
2026-01-26 02:48:01.350113 | localhost | skipping: Conditional result was False
2026-01-26 02:48:01.356480 | localhost | skipping: Conditional result was False
2026-01-26 02:48:01.370635 | 
2026-01-26 02:48:01.370866 | LOOP [upload-logs : Upload compressed console log and json output]
2026-01-26 02:48:01.414134 | localhost | skipping: Conditional result was False
2026-01-26 02:48:01.414591 | 
2026-01-26 02:48:01.417497 | localhost | skipping: Conditional result was False
2026-01-26 02:48:01.432787 | 
2026-01-26 02:48:01.432895 | LOOP [upload-logs : Upload console log and json output]