2026-01-26 08:41:34.080371 | Job console starting
2026-01-26 08:41:34.090500 | Updating git repos
2026-01-26 08:41:34.157417 | Cloning repos into workspace
2026-01-26 08:41:34.220693 | Restoring repo states
2026-01-26 08:41:34.240579 | Merging changes
2026-01-26 08:41:35.216650 | Checking out repos
2026-01-26 08:41:35.343562 | Preparing playbooks
2026-01-26 08:41:37.568159 | Running Ansible setup
2026-01-26 08:41:40.831126 | PRE-RUN START: [trusted : vexxhost.dev/zuul-config/playbooks/base/pre.yaml@main]
2026-01-26 08:41:41.431555 | 
2026-01-26 08:41:41.432371 | PLAY [localhost]
2026-01-26 08:41:41.440325 | 
2026-01-26 08:41:41.440398 | TASK [Gathering Facts]
2026-01-26 08:41:42.319560 | localhost | ok
2026-01-26 08:41:42.327519 | 
2026-01-26 08:41:42.327623 | TASK [Setup log path fact]
2026-01-26 08:41:42.347760 | localhost | ok
2026-01-26 08:41:42.359663 | 
2026-01-26 08:41:42.359777 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-26 08:41:42.390861 | localhost | ok
2026-01-26 08:41:42.401074 | 
2026-01-26 08:41:42.401165 | TASK [emit-job-header : Print job information]
2026-01-26 08:41:42.441750 | # Job Information
2026-01-26 08:41:42.441999 | Ansible Version: 2.16.15
2026-01-26 08:41:42.442046 | Job: atmosphere-molecule-csi-rbd
2026-01-26 08:41:42.442078 | Pipeline: check
2026-01-26 08:41:42.442107 | Executor: 3a2793d2bd32
2026-01-26 08:41:42.442136 | Triggered by: https://github.com/vexxhost/atmosphere/pull/3468
2026-01-26 08:41:42.442168 | Event ID: b3a1cce0-fa92-11f0-8f20-7bd548aca8ba
2026-01-26 08:41:42.446276 | 
2026-01-26 08:41:42.446373 | LOOP [emit-job-header : Print node information]
2026-01-26 08:41:42.538661 | localhost | ok:
2026-01-26 08:41:42.539008 | localhost | # Node Information
2026-01-26 08:41:42.539073 | localhost | Inventory Hostname: instance
2026-01-26 08:41:42.539121 | localhost | Hostname: np0000154467
2026-01-26 08:41:42.539164 | localhost | Username: zuul
2026-01-26 08:41:42.539216 | localhost | Distro: Ubuntu 22.04
2026-01-26 08:41:42.539259 | localhost | Provider: yul1
2026-01-26 08:41:42.539301 | localhost | Region: ca-ymq-1
2026-01-26 08:41:42.539342 | localhost | Label: ubuntu-jammy
2026-01-26 08:41:42.539382 | localhost | Product Name: OpenStack Nova
2026-01-26 08:41:42.539423 | localhost | Interface IP: 162.253.55.195
2026-01-26 08:41:42.556319 | 
2026-01-26 08:41:42.556535 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-26 08:41:42.938759 | localhost -> localhost | changed
2026-01-26 08:41:42.948643 | 
2026-01-26 08:41:42.948815 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-26 08:41:43.798340 | localhost -> localhost | changed
2026-01-26 08:41:43.808897 | 
2026-01-26 08:41:43.809058 | PLAY [all]
2026-01-26 08:41:43.817260 | 
2026-01-26 08:41:43.817336 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-26 08:41:44.084697 | instance -> localhost | ok
2026-01-26 08:41:44.096126 | 
2026-01-26 08:41:44.096228 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-26 08:41:44.129943 | instance | ok
2026-01-26 08:41:44.144939 | instance | included: /var/lib/zuul/builds/5153489966b54c27b3d117b90a5c6b6b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-26 08:41:44.150612 | 
2026-01-26 08:41:44.150673 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-26 08:41:45.623670 | instance -> localhost | Generating public/private rsa key pair.
2026-01-26 08:41:45.623914 | instance -> localhost | Your identification has been saved in /var/lib/zuul/builds/5153489966b54c27b3d117b90a5c6b6b/work/5153489966b54c27b3d117b90a5c6b6b_id_rsa
2026-01-26 08:41:45.623956 | instance -> localhost | Your public key has been saved in /var/lib/zuul/builds/5153489966b54c27b3d117b90a5c6b6b/work/5153489966b54c27b3d117b90a5c6b6b_id_rsa.pub
2026-01-26 08:41:45.623989 | instance -> localhost | The key fingerprint is:
2026-01-26 08:41:45.624020 | instance -> localhost | SHA256:YoSNK3I5L/sd2N/xym3EabYCuqcRlp6VRPrab2uTlXs zuul-build-sshkey
2026-01-26 08:41:45.624068 | instance -> localhost | The key's randomart image is:
2026-01-26 08:41:45.624098 | instance -> localhost | +---[RSA 3072]----+
2026-01-26 08:41:45.624135 | instance -> localhost | |        .        |
2026-01-26 08:41:45.624166 | instance -> localhost | |     + o         |
2026-01-26 08:41:45.624195 | instance -> localhost | |    o + .        |
2026-01-26 08:41:45.624224 | instance -> localhost | |   . o + .       |
2026-01-26 08:41:45.624252 | instance -> localhost | |. = . * S  . o   |
2026-01-26 08:41:45.624281 | instance -> localhost | | o + * B.   O    |
2026-01-26 08:41:45.624309 | instance -> localhost | |  . o B....* o   |
2026-01-26 08:41:45.624338 | instance -> localhost | |   o ..+.+*++ E  |
2026-01-26 08:41:45.624370 | instance -> localhost | |  ... ++.o**o.   |
2026-01-26 08:41:45.624399 | instance -> localhost | +----[SHA256]-----+
2026-01-26 08:41:45.624468 | instance -> localhost | ok: Runtime: 0:00:01.039885
2026-01-26 08:41:45.631927 | 
2026-01-26 08:41:45.632024 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-26 08:41:45.662618 | instance | ok
2026-01-26 08:41:45.671258 | instance | included: /var/lib/zuul/builds/5153489966b54c27b3d117b90a5c6b6b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-26 08:41:45.678993 | 
2026-01-26 08:41:45.679069 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-26 08:41:45.695523 | instance | skipping: Conditional result was False
2026-01-26 08:41:45.704557 | 
2026-01-26 08:41:45.704667 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-26 08:41:46.132441 | instance | changed
2026-01-26 08:41:46.139059 | 
2026-01-26 08:41:46.139147 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-26 08:41:46.327358 | instance | ok
2026-01-26 08:41:46.334282 | 
2026-01-26 08:41:46.334371 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-26 08:41:46.785311 | instance | changed
2026-01-26 08:41:46.790903 | 
2026-01-26 08:41:46.790973 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-26 08:41:47.229664 | instance | changed
2026-01-26 08:41:47.235284 | 
2026-01-26 08:41:47.235366 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-26 08:41:47.260028 | instance | skipping: Conditional result was False
2026-01-26 08:41:47.272592 | 
2026-01-26 08:41:47.272790 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-26 08:41:47.613471 | instance -> localhost | changed
2026-01-26 08:41:47.627442 | 
2026-01-26 08:41:47.627562 | TASK [add-build-sshkey : Add back temp key]
2026-01-26 08:41:47.906164 | instance -> localhost | Identity added: /var/lib/zuul/builds/5153489966b54c27b3d117b90a5c6b6b/work/5153489966b54c27b3d117b90a5c6b6b_id_rsa (zuul-build-sshkey)
2026-01-26 08:41:47.906384 | instance -> localhost | ok: Runtime: 0:00:00.016465
2026-01-26 08:41:47.911242 | 
2026-01-26 08:41:47.911304 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-26 08:41:48.220258 | instance | ok
2026-01-26 08:41:48.227179 | 
2026-01-26 08:41:48.227250 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-26 08:41:48.252870 | instance | skipping: Conditional result was False
2026-01-26 08:41:48.267341 | 
2026-01-26 08:41:48.267423 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-26 08:41:48.585677 | instance | ok
2026-01-26 08:41:48.591235 | 
2026-01-26 08:41:48.591295 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-26 08:41:50.148714 | instance | Output suppressed because no_log was given
2026-01-26 08:41:50.158541 | 
2026-01-26 08:41:50.158607 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-26 08:41:50.347088 | instance | ok: "logs"
2026-01-26 08:41:50.347385 | instance | ok: All items complete
2026-01-26 08:41:50.347418 | 
2026-01-26 08:41:50.500110 | instance | ok: "artifacts"
2026-01-26 08:41:50.656202 | instance | ok: "docs"
2026-01-26 08:41:50.673888 | 
2026-01-26 08:41:50.674056 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-26 08:41:50.865357 | instance | changed: "logs"
2026-01-26 08:41:51.031077 | instance | changed: "artifacts"
2026-01-26 08:41:51.191546 | instance | changed: "docs"
2026-01-26 08:41:51.214418 | 
2026-01-26 08:41:51.214553 | PLAY RECAP
2026-01-26 08:41:51.214620 | instance | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2026-01-26 08:41:51.214659 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-26 08:41:51.214688 | 
2026-01-26 08:41:51.404297 | PRE-RUN END RESULT_NORMAL: [trusted : vexxhost.dev/zuul-config/playbooks/base/pre.yaml@main]
2026-01-26 08:41:51.406190 | PRE-RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-01-26 08:41:52.015484 | 
2026-01-26 08:41:52.015666 | PLAY [all]
2026-01-26 08:41:52.028013 | 
2026-01-26 08:41:52.028124 | TASK [setup-uv : Extract archive]
2026-01-26 08:41:54.206506 | instance | changed
2026-01-26 08:41:54.216171 | 
2026-01-26 08:41:54.216276 | TASK [setup-uv : Print version]
2026-01-26 08:41:53.587436 | instance | uv 0.8.13
2026-01-26 08:41:54.752723 | instance | ok: Runtime: 0:00:00.012108
2026-01-26 08:41:54.760328 | 
2026-01-26 08:41:54.760582 | PLAY RECAP
2026-01-26 08:41:54.760630 | instance | ok: 2 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-26 08:41:54.760654 | 
2026-01-26 08:41:54.884399 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-01-26 08:41:54.887064 | PRE-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@main]
2026-01-26 08:41:55.500759 | 
2026-01-26 08:41:55.500914 | PLAY [all]
2026-01-26 08:41:55.511944 | 
2026-01-26 08:41:55.512018 | TASK [Install "jq" for log collection]
2026-01-26 08:42:05.471700 | instance | changed
2026-01-26 08:42:05.473991 | 
2026-01-26 08:42:05.474055 | PLAY RECAP
2026-01-26 08:42:05.474107 | instance | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-26 08:42:05.474159 | 
2026-01-26 08:42:05.584500 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@main]
2026-01-26 08:42:05.589282 | RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-01-26 08:42:06.175915 | 
2026-01-26 08:42:06.176073 | PLAY [all]
2026-01-26 08:42:06.188312 | 
2026-01-26 08:42:06.188415 | TASK [Copy inventory file for Zuul]
2026-01-26 08:42:07.035180 | instance | changed
2026-01-26 08:42:07.041504 | 
2026-01-26 08:42:07.041592 | TASK [Switch "ansible_host" to private IP]
2026-01-26 08:42:07.309394 | instance | changed: 1 replacements made
2026-01-26 08:42:07.316675 | 
2026-01-26 08:42:07.316764 | TASK [Run Molecule scenario]
2026-01-26 08:42:07.725805 | instance | Using CPython 3.10.12 interpreter at: /usr/bin/python3
2026-01-26 08:42:07.725951 | instance | Creating virtual environment at: .venv
2026-01-26 08:42:07.761565 | instance |    Building atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere
2026-01-26 08:42:07.790493 | instance | Downloading pygments (1.2MiB)
2026-01-26 08:42:07.792768 | instance | Downloading ansible-core (2.1MiB)
2026-01-26 08:42:07.876566 | instance | Downloading netaddr (2.2MiB)
2026-01-26 08:42:07.883821 | instance | Downloading cryptography (4.2MiB)
2026-01-26 08:42:07.891742 | instance | Downloading kubernetes (1.9MiB)
2026-01-26 08:42:07.912682 | instance | Downloading rjsonnet (1.2MiB)
2026-01-26 08:42:07.914800 | instance | Downloading openstacksdk (1.7MiB)
2026-01-26 08:42:07.915993 | instance | Downloading setuptools (1.1MiB)
2026-01-26 08:42:08.115650 | instance |    Building pyperclip==1.9.0
2026-01-26 08:42:08.162690 | instance |  Downloading rjsonnet
2026-01-26 08:42:08.305879 | instance |  Downloading netaddr
2026-01-26 08:42:08.318109 | instance |  Downloading pygments
2026-01-26 08:42:08.340107 | instance |  Downloading cryptography
2026-01-26 08:42:08.389270 | instance |  Downloading setuptools
2026-01-26 08:42:08.479385 | instance |  Downloading kubernetes
2026-01-26 08:42:08.519496 | instance |  Downloading ansible-core
2026-01-26 08:42:08.545821 | instance |  Downloading openstacksdk
2026-01-26 08:42:08.927328 | instance |       Built pyperclip==1.9.0
2026-01-26 08:42:09.178089 | instance |       Built atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere
2026-01-26 08:42:09.249555 | instance | Installed 79 packages in 70ms
2026-01-26 08:42:09.971860 | instance | WARNING  Molecule scenarios should migrate to 'extensions/molecule'
2026-01-26 08:42:10.555354 | 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:10.555474 | instance | INFO     [csi > prerun] Performing prerun with role_name_check=0...
2026-01-26 08:42:12.679360 | instance | WARNING  Retrying execution failure 1 of: ansible-galaxy collection install -vvv ansible.netcommon:1.2.0
2026-01-26 08:42:12.679462 | instance | ERROR    Command ansible-galaxy collection install -vvv ansible.netcommon:1.2.0, returned 1 code:
2026-01-26 08:42:12.679469 | instance | Starting galaxy collection install process
2026-01-26 08:42:12.679475 | instance | Process install dependency map
2026-01-26 08:42:12.679480 | instance |
2026-01-26 08:42:12.679485 | instance | ansible-galaxy
2026-01-26 08:42:12.679489 | instance |   config file = None
2026-01-26 08:42:12.679493 | instance |   configured module search path =
2026-01-26 08:42:12.679498 | instance |   ansible python module location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/ansible
2026-01-26 08:42:12.679503 | 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:12.679509 | instance |   executable location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/ansible-galaxy
2026-01-26 08:42:12.679514 | 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:12.679518 | instance |   jinja version = 3.1.6
2026-01-26 08:42:12.679522 | instance |   libyaml = True
2026-01-26 08:42:12.679527 | instance | No config file found; using defaults
2026-01-26 08:42:12.679531 | instance | Created /home/zuul/.ansible/galaxy_token
2026-01-26 08:42:12.679536 | 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:12.679546 | instance |
2026-01-26 08:42:12.680235 | instance | Traceback (most recent call last):
2026-01-26 08:42:12.680662 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/molecule", line 10, in <module>
2026-01-26 08:42:12.681119 | instance |     sys.exit(main())
2026-01-26 08:42:12.681436 | 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:12.682167 | instance |     return self.main(*args, **kwargs)
2026-01-26 08:42:12.682446 | 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:12.683092 | instance |     rv = self.invoke(ctx)
2026-01-26 08:42:12.683368 | 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:12.684168 | instance |     return _process_result(sub_ctx.command.invoke(sub_ctx))
2026-01-26 08:42:12.684453 | 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:12.685080 | instance |     return ctx.invoke(self.callback, **ctx.params)
2026-01-26 08:42:12.685392 | 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:12.685969 | instance |     return callback(*args, **kwargs)
2026-01-26 08:42:12.686256 | 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:12.686893 | instance |     return func(*args, **kwargs)
2026-01-26 08:42:12.687301 | 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:12.687777 | instance |     return f(get_current_context(), *args, **kwargs)
2026-01-26 08:42:12.688063 | 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:12.688511 | instance |     return func(ctx)
2026-01-26 08:42:12.688789 | 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:12.689292 | instance |     base.execute_cmdline_scenarios(scenario_name, args, command_args, ansible_args, exclude)
2026-01-26 08:42:12.689575 | 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:12.689760 | instance |     _run_scenarios(scenarios, command_args, default_config)
2026-01-26 08:42:12.689903 | 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:12.690095 | instance |     scenario.config.runtime.prepare_environment(
2026-01-26 08:42:12.690220 | 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:12.690485 | instance |     self.install_collection(
2026-01-26 08:42:12.690616 | 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:12.690831 | instance |     raise InvalidPrerequisiteError(msg)
2026-01-26 08:42:12.691447 | instance | ansible_compat.errors.InvalidPrerequisiteError: Command ansible-galaxy collection install -vvv ansible.netcommon:1.2.0, returned 1 code:
2026-01-26 08:42:12.691457 | instance | Starting galaxy collection install process
2026-01-26 08:42:12.691466 | instance | Process install dependency map
2026-01-26 08:42:12.691475 | instance |
2026-01-26 08:42:12.691483 | instance | ansible-galaxy [core 2.17.12]
2026-01-26 08:42:12.691492 | instance |   config file = None
2026-01-26 08:42:12.691501 | 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:12.691511 | instance |   ansible python module location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/ansible
2026-01-26 08:42:12.691520 | 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:12.691541 | instance |   executable location = /home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/ansible-galaxy
2026-01-26 08:42:12.691550 | 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:12.691559 | instance |   jinja version = 3.1.6
2026-01-26 08:42:12.691568 | instance |   libyaml = True
2026-01-26 08:42:12.691577 | instance | No config file found; using defaults
2026-01-26 08:42:12.691585 | instance | Created /home/zuul/.ansible/galaxy_token
2026-01-26 08:42:12.691594 | 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:12.691606 | instance |
2026-01-26 08:42:12.873772 | instance | ERROR
2026-01-26 08:42:12.874032 | instance | {
2026-01-26 08:42:12.874073 | instance |   "delta": "0:00:05.098062",
2026-01-26 08:42:12.874101 | instance |   "end": "2026-01-26 08:42:12.769726",
2026-01-26 08:42:12.874128 | instance |   "msg": "non-zero return code",
2026-01-26 08:42:12.874152 | instance |   "rc": 1,
2026-01-26 08:42:12.874182 | instance |   "start": "2026-01-26 08:42:07.671664"
2026-01-26 08:42:12.874207 | instance | }
failure
2026-01-26 08:42:12.877289 | 
2026-01-26 08:42:12.877355 | PLAY RECAP
2026-01-26 08:42:12.877416 | instance | ok: 2 changed: 2 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0
2026-01-26 08:42:12.877445 | 
2026-01-26 08:42:12.996923 | RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-01-26 08:42:13.000925 | POST-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@main]
2026-01-26 08:42:13.572672 | 
2026-01-26 08:42:13.572818 | PLAY [all]
2026-01-26 08:42:13.588301 | 
2026-01-26 08:42:13.588452 | TASK [gather-host-logs : creating directory for system status]
2026-01-26 08:42:13.957123 | instance | changed
2026-01-26 08:42:13.963365 | 
2026-01-26 08:42:13.963477 | TASK [gather-host-logs : Get logs for each host]
2026-01-26 08:42:14.305854 | instance | + systemd-cgls --full --all --no-pager
2026-01-26 08:42:14.313174 | instance | + ip addr
2026-01-26 08:42:14.314568 | instance | + ip route
2026-01-26 08:42:14.315800 | instance | + lsblk
2026-01-26 08:42:14.317998 | instance | + mount
2026-01-26 08:42:14.319214 | instance | + docker images
2026-01-26 08:42:14.319534 | instance | /bin/bash: line 7: docker: command not found
2026-01-26 08:42:14.319750 | instance | + brctl show
2026-01-26 08:42:14.320039 | instance | /bin/bash: line 8: brctl: command not found
2026-01-26 08:42:14.320243 | instance | + ps aux --sort=-%mem
2026-01-26 08:42:14.327149 | instance | + dpkg -l
2026-01-26 08:42:14.332734 | instance | + CONTAINERS=($(docker ps -a --format '{{ .Names }}' --filter label=zuul))
2026-01-26 08:42:14.333176 | instance | ++ docker ps -a --format '{{ .Names }}' --filter label=zuul
2026-01-26 08:42:14.333245 | instance | /bin/bash: line 11: docker: command not found
2026-01-26 08:42:14.333552 | instance | + '[' '!' -z '' ']'
2026-01-26 08:42:14.498933 | instance | ok: Runtime: 0:00:00.033783
2026-01-26 08:42:14.506503 | 
2026-01-26 08:42:14.506592 | TASK [gather-host-logs : Downloads logs to executor]
2026-01-26 08:42:15.170871 | instance | changed:
2026-01-26 08:42:15.171102 | instance | created directory /var/lib/zuul/builds/5153489966b54c27b3d117b90a5c6b6b/work/logs/instance
2026-01-26 08:42:15.171145 | instance | cd+++++++++ system/
2026-01-26 08:42:15.171178 | instance | >f+++++++++ system/brctl-show.txt
2026-01-26 08:42:15.171209 | instance | >f+++++++++ system/docker-images.txt
2026-01-26 08:42:15.171239 | instance | >f+++++++++ system/ip-addr.txt
2026-01-26 08:42:15.171275 | instance | >f+++++++++ system/ip-route.txt
2026-01-26 08:42:15.171307 | instance | >f+++++++++ system/lsblk.txt
2026-01-26 08:42:15.171339 | instance | >f+++++++++ system/mount.txt
2026-01-26 08:42:15.171384 | instance | >f+++++++++ system/packages.txt
2026-01-26 08:42:15.171420 | instance | >f+++++++++ system/ps.txt
2026-01-26 08:42:15.171562 | instance | >f+++++++++ system/systemd-cgls.txt
2026-01-26 08:42:15.182463 | 
2026-01-26 08:42:15.182550 | LOOP [helm-release-status : creating directory for helm release status]
2026-01-26 08:42:15.408044 | instance | changed: "values"
2026-01-26 08:42:15.614498 | instance | changed: "releases"
2026-01-26 08:42:15.627373 | 
2026-01-26 08:42:15.627607 | TASK [helm-release-status : Gather get release status for helm charts]
2026-01-26 08:42:15.837513 | instance | /bin/bash: line 3: kubectl: command not found
2026-01-26 08:42:16.166836 | instance | ok: Runtime: 0:00:00.007193
2026-01-26 08:42:16.175276 | 
2026-01-26 08:42:16.175450 | TASK [helm-release-status : Downloads logs to executor]
2026-01-26 08:42:16.681184 | instance | changed:
2026-01-26 08:42:16.681404 | instance | cd+++++++++ helm/
2026-01-26 08:42:16.681435 | instance | cd+++++++++ helm/releases/
2026-01-26 08:42:16.681459 | instance | cd+++++++++ helm/values/
2026-01-26 08:42:16.691726 | 
2026-01-26 08:42:16.691872 | TASK [describe-kubernetes-objects : creating directory for cluster scoped objects]
2026-01-26 08:42:16.889190 | instance | changed
2026-01-26 08:42:16.895252 | 
2026-01-26 08:42:16.895323 | TASK [describe-kubernetes-objects : Gathering descriptions for cluster scoped objects]
2026-01-26 08:42:17.110398 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-01-26 08:42:17.110642 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-01-26 08:42:17.115066 | instance | environment: line 1: kubectl: command not found
2026-01-26 08:42:17.115593 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-01-26 08:42:17.117148 | instance | environment: line 1: kubectl: command not found
2026-01-26 08:42:17.118598 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-01-26 08:42:17.119522 | instance | environment: line 1: kubectl: command not found
2026-01-26 08:42:17.120636 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-01-26 08:42:17.123001 | instance | environment: line 1: kubectl: command not found
2026-01-26 08:42:17.124060 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-01-26 08:42:17.124643 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-01-26 08:42:17.124769 | instance | environment: line 1: kubectl: command not found
2026-01-26 08:42:17.430408 | instance | ok: Runtime: 0:00:00.024594
2026-01-26 08:42:17.437229 | 
2026-01-26 08:42:17.437327 | TASK [describe-kubernetes-objects : creating directory for namespace scoped objects]
2026-01-26 08:42:17.643878 | instance | changed
2026-01-26 08:42:17.650059 | 
2026-01-26 08:42:17.650128 | TASK [describe-kubernetes-objects : Gathering descriptions for namespace scoped objects]
2026-01-26 08:42:17.900367 | instance | environment: line 5: kubectl: command not found
2026-01-26 08:42:17.900422 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-01-26 08:42:17.901764 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-01-26 08:42:17.902051 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-01-26 08:42:18.216349 | instance | ok: Runtime: 0:00:00.009514
2026-01-26 08:42:18.223628 | 
2026-01-26 08:42:18.223754 | TASK [describe-kubernetes-objects : Downloads logs to executor]
2026-01-26 08:42:18.705419 | instance | changed:
2026-01-26 08:42:18.705610 | instance | cd+++++++++ objects/
2026-01-26 08:42:18.705656 | instance | cd+++++++++ objects/cluster/
2026-01-26 08:42:18.705677 | instance | cd+++++++++ objects/namespaced/
2026-01-26 08:42:18.714425 | 
2026-01-26 08:42:18.714521 | TASK [gather-pod-logs : creating directory for pod logs]
2026-01-26 08:42:18.910814 | instance | changed
2026-01-26 08:42:18.917533 | 
2026-01-26 08:42:18.917617 | TASK [gather-pod-logs : creating directory for failed pod logs]
2026-01-26 08:42:19.113784 | instance | changed
2026-01-26 08:42:19.120518 | 
2026-01-26 08:42:19.120593 | TASK [gather-pod-logs : retrieve all kubernetes logs, current and previous (if they exist)]
2026-01-26 08:42:19.323668 | instance | environment: line 3: kubectl: command not found
2026-01-26 08:42:19.655737 | instance | ok: Runtime: 0:00:00.006551
2026-01-26 08:42:19.661301 | 
2026-01-26 08:42:19.661370 | TASK [gather-pod-logs : Downloads pod logs to executor]
2026-01-26 08:42:20.141407 | instance | changed:
2026-01-26 08:42:20.141675 | instance | cd+++++++++ pod-logs/
2026-01-26 08:42:20.141717 | instance | cd+++++++++ pod-logs/failed-pods/
2026-01-26 08:42:20.151513 | 
2026-01-26 08:42:20.151583 | TASK [gather-prom-metrics : creating directory for helm release descriptions]
2026-01-26 08:42:20.335164 | instance | changed
2026-01-26 08:42:20.340191 | 
2026-01-26 08:42:20.340264 | TASK [gather-prom-metrics : Get metrics from exporter services in all namespaces]
2026-01-26 08:42:20.551032 | instance | /bin/bash: line 2: kubectl: command not found
2026-01-26 08:42:20.875352 | instance | ok: Runtime: 0:00:00.032683
2026-01-26 08:42:20.881929 | 
2026-01-26 08:42:20.882008 | TASK [gather-prom-metrics : Get ceph metrics from ceph-mgr]
2026-01-26 08:42:21.097473 | instance | /bin/bash: line 2: kubectl: command not found
2026-01-26 08:42:21.127198 | instance | ceph-mgr endpoints:
2026-01-26 08:42:21.420223 | instance | ok: Runtime: 0:00:00.035604
2026-01-26 08:42:21.426793 | 
2026-01-26 08:42:21.426859 | TASK [gather-prom-metrics : Get metrics from fluentd pods]
2026-01-26 08:42:21.633017 | instance | /bin/bash: line 4: kubectl: command not found
2026-01-26 08:42:21.963868 | instance | ok: Runtime: 0:00:00.030022
2026-01-26 08:42:21.968870 | 
2026-01-26 08:42:21.968934 | TASK [gather-prom-metrics : Downloads logs to executor]
2026-01-26 08:42:22.461335 | instance | changed: cd+++++++++ prometheus/
2026-01-26 08:42:22.470132 | 
2026-01-26 08:42:22.470193 | TASK [gather-selenium-data : creating directory for helm release descriptions]
2026-01-26 08:42:22.657781 | instance | changed
2026-01-26 08:42:22.665098 | 
2026-01-26 08:42:22.665171 | TASK [gather-selenium-data : Get selenium data]
2026-01-26 08:42:22.870557 | instance | + cp '/tmp/artifacts/*' /tmp/logs/selenium/.
2026-01-26 08:42:22.872093 | instance | cp: cannot stat '/tmp/artifacts/*': No such file or directory
2026-01-26 08:42:23.201757 | instance | ERROR
2026-01-26 08:42:23.202157 | instance | {
2026-01-26 08:42:23.202231 | instance |   "delta": "0:00:00.006992",
2026-01-26 08:42:23.202280 | instance |   "end": "2026-01-26 08:42:22.872430",
2026-01-26 08:42:23.202321 | instance |   "msg": "non-zero return code",
2026-01-26 08:42:23.202362 | instance |   "rc": 1,
2026-01-26 08:42:23.202400 | instance |   "start": "2026-01-26 08:42:22.865438"
2026-01-26 08:42:23.202438 | instance | }
2026-01-26 08:42:23.202488 | instance | ERROR: Ignoring Errors
2026-01-26 08:42:23.207959 | 
2026-01-26 08:42:23.208030 | TASK [gather-selenium-data : Downloads logs to executor]
2026-01-26 08:42:23.716794 | instance | changed: cd+++++++++ selenium/
2026-01-26 08:42:23.723652 | 
2026-01-26 08:42:23.723712 | PLAY RECAP
2026-01-26 08:42:23.723762 | instance | ok: 23 changed: 23 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 1
2026-01-26 08:42:23.723783 | 
2026-01-26 08:42:23.850834 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@main]
2026-01-26 08:42:23.855972 | POST-RUN START: [trusted : vexxhost.dev/zuul-config/playbooks/base/post.yaml@main]
2026-01-26 08:42:24.449434 | 
2026-01-26 08:42:24.449569 | PLAY [all]
2026-01-26 08:42:24.460765 | 
2026-01-26 08:42:24.460840 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-26 08:42:24.505875 | instance | skipping: Conditional result was False
2026-01-26 08:42:24.515980 | 
2026-01-26 08:42:24.516109 | TASK [fetch-output : Set log path for single node]
2026-01-26 08:42:24.549334 | instance | ok
2026-01-26 08:42:24.555277 | 
2026-01-26 08:42:24.555345 | LOOP [fetch-output : Ensure local output dirs]
2026-01-26 08:42:24.927727 | instance -> localhost | ok: "/var/lib/zuul/builds/5153489966b54c27b3d117b90a5c6b6b/work/logs"
2026-01-26 08:42:25.142554 | instance -> localhost | changed: "/var/lib/zuul/builds/5153489966b54c27b3d117b90a5c6b6b/work/artifacts"
2026-01-26 08:42:25.353499 | instance -> localhost | changed: "/var/lib/zuul/builds/5153489966b54c27b3d117b90a5c6b6b/work/docs"
2026-01-26 08:42:25.370745 | 
2026-01-26 08:42:25.370897 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-26 08:42:26.011181 | instance | changed: .d..t...... ./
2026-01-26 08:42:26.011491 | instance | changed: All items complete
2026-01-26 08:42:26.011533 | 
2026-01-26 08:42:26.460196 | instance | changed: .d..t...... ./
2026-01-26 08:42:26.915556 | instance | changed: .d..t...... ./
2026-01-26 08:42:26.932853 | 
2026-01-26 08:42:26.933027 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-26 08:42:27.364369 | instance -> localhost | ok: Item: artifacts Runtime: 0:00:00.007248
2026-01-26 08:42:27.596856 | instance -> localhost | ok: Item: docs Runtime: 0:00:00.008245
2026-01-26 08:42:27.618225 | 
2026-01-26 08:42:27.618384 | PLAY [all]
2026-01-26 08:42:27.624576 | 
2026-01-26 08:42:27.624645 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-01-26 08:42:28.033984 | instance | changed
2026-01-26 08:42:28.040626 | 
2026-01-26 08:42:28.040679 | PLAY RECAP
2026-01-26 08:42:28.040729 | instance | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-01-26 08:42:28.040750 | 
2026-01-26 08:42:28.151367 | POST-RUN END RESULT_NORMAL: [trusted : vexxhost.dev/zuul-config/playbooks/base/post.yaml@main]
2026-01-26 08:42:28.156012 | POST-RUN START: [trusted : vexxhost.dev/zuul-config/playbooks/base/post-logs.yaml@main]
2026-01-26 08:42:28.816434 | 
2026-01-26 08:42:28.816632 | PLAY [localhost]
2026-01-26 08:42:28.827647 | 
2026-01-26 08:42:28.827762 | TASK [Generate Zuul manifest]
2026-01-26 08:42:28.851360 | localhost | ok
2026-01-26 08:42:28.874469 | 
2026-01-26 08:42:28.874680 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-26 08:42:29.196938 | localhost | changed
2026-01-26 08:42:29.208656 | 
2026-01-26 08:42:29.208771 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-26 08:42:29.240459 | localhost | ok
2026-01-26 08:42:29.249599 | 
2026-01-26 08:42:29.249676 | TASK [Upload logs]
2026-01-26 08:42:29.275398 | localhost | ok
2026-01-26 08:42:29.337695 | 
2026-01-26 08:42:29.337863 | TASK [Set zuul-log-path fact]
2026-01-26 08:42:29.359773 | localhost | ok
2026-01-26 08:42:29.372133 | 
2026-01-26 08:42:29.372200 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-26 08:42:29.404419 | localhost | ok
2026-01-26 08:42:29.412455 | 
2026-01-26 08:42:29.412521 | TASK [upload-logs : Create log directories]
2026-01-26 08:42:29.799538 | localhost | changed
2026-01-26 08:42:29.806131 | 
2026-01-26 08:42:29.806202 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-01-26 08:42:30.235556 | localhost -> localhost | ok: Runtime: 0:00:00.006245
2026-01-26 08:42:30.242597 | 
2026-01-26 08:42:30.242665 | TASK [upload-logs : Upload logs to log server]
2026-01-26 08:42:30.719273 | localhost | Output suppressed because no_log was given
2026-01-26 08:42:30.723019 | 
2026-01-26 08:42:30.723085 | LOOP [upload-logs : Compress console log and json output]
2026-01-26 08:42:30.767996 | localhost | skipping: Conditional result was False
2026-01-26 08:42:30.774320 | localhost | skipping: Conditional result was False
2026-01-26 08:42:30.787677 | 
2026-01-26 08:42:30.787824 | LOOP [upload-logs : Upload compressed console log and json output]
2026-01-26 08:42:30.827571 | localhost | skipping: Conditional result was False
2026-01-26 08:42:30.828143 | 
2026-01-26 08:42:30.830479 | localhost | skipping: Conditional result was False
2026-01-26 08:42:30.842091 | 
2026-01-26 08:42:30.842222 | LOOP [upload-logs : Upload console log and json output]