2026-04-07 06:30:24.588242 | Job console starting
2026-04-07 06:30:24.596009 | Updating git repos
2026-04-07 06:30:24.651891 | Cloning repos into workspace
2026-04-07 06:30:25.370065 | Restoring repo states
2026-04-07 06:30:25.386309 | Merging changes
2026-04-07 06:30:26.297651 | Checking out repos
2026-04-07 06:30:26.511542 | Preparing playbooks
2026-04-07 06:30:32.152622 | Running Ansible setup
2026-04-07 06:30:35.491643 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-04-07 06:30:36.091099 | 
2026-04-07 06:30:36.091262 | PLAY [localhost]
2026-04-07 06:30:36.099228 | 
2026-04-07 06:30:36.099302 | TASK [Gathering Facts]
2026-04-07 06:30:36.945252 | localhost | ok
2026-04-07 06:30:36.954484 | 
2026-04-07 06:30:36.954560 | TASK [Setup log path fact]
2026-04-07 06:30:36.995287 | localhost | ok
2026-04-07 06:30:37.007802 | 
2026-04-07 06:30:37.007898 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-04-07 06:30:37.040943 | localhost | ok
2026-04-07 06:30:37.050374 | 
2026-04-07 06:30:37.050571 | TASK [emit-job-header : Print job information]
2026-04-07 06:30:37.083787 | # Job Information
2026-04-07 06:30:37.084059 | Ansible Version: 2.16.16
2026-04-07 06:30:37.084130 | Job: atmosphere-molecule-keycloak
2026-04-07 06:30:37.084164 | Pipeline: check
2026-04-07 06:30:37.084194 | Executor: 0a8996d2b663
2026-04-07 06:30:37.084222 | Triggered by: https://github.com/vexxhost/atmosphere/pull/3809
2026-04-07 06:30:37.084255 | Event ID: 21cc2900-324b-11f1-92a5-f931b05d336f
2026-04-07 06:30:37.088577 | 
2026-04-07 06:30:37.088674 | LOOP [emit-job-header : Print node information]
2026-04-07 06:30:37.185588 | localhost | ok:
2026-04-07 06:30:37.185910 | localhost | # Node Information
2026-04-07 06:30:37.185986 | localhost | Inventory Hostname: instance
2026-04-07 06:30:37.186042 | localhost | Hostname: np0000163873
2026-04-07 06:30:37.186094 | localhost | Username: zuul
2026-04-07 06:30:37.186148 | localhost | Distro: Ubuntu 22.04
2026-04-07 06:30:37.186199 | localhost | Provider: yul1
2026-04-07 06:30:37.186246 | localhost | Region: ca-ymq-1
2026-04-07 06:30:37.186293 | localhost | Label: ubuntu-jammy
2026-04-07 06:30:37.186338 | localhost | Product Name: OpenStack Nova
2026-04-07 06:30:37.186385 | localhost | Interface IP: 162.253.55.207
2026-04-07 06:30:37.197707 | 
2026-04-07 06:30:37.197875 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-04-07 06:30:37.567775 | localhost -> localhost | changed
2026-04-07 06:30:37.577484 | 
2026-04-07 06:30:37.577613 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-04-07 06:30:38.388927 | localhost -> localhost | changed
2026-04-07 06:30:38.398764 | 
2026-04-07 06:30:38.398833 | PLAY [all]
2026-04-07 06:30:38.408715 | 
2026-04-07 06:30:38.408777 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-04-07 06:30:38.625864 | instance -> localhost | ok
2026-04-07 06:30:38.633010 | 
2026-04-07 06:30:38.633100 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-04-07 06:30:38.663061 | instance | ok
2026-04-07 06:30:38.678068 | instance | included: /var/lib/zuul/builds/9e704877d0dc4b359b5cfc80242ecfe8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-04-07 06:30:38.684248 | 
2026-04-07 06:30:38.684305 | TASK [add-build-sshkey : Create Temp SSH key]
2026-04-07 06:30:39.568383 | instance -> localhost | Generating public/private rsa key pair.
2026-04-07 06:30:39.568546 | instance -> localhost | Your identification has been saved in /var/lib/zuul/builds/9e704877d0dc4b359b5cfc80242ecfe8/work/9e704877d0dc4b359b5cfc80242ecfe8_id_rsa
2026-04-07 06:30:39.568575 | instance -> localhost | Your public key has been saved in /var/lib/zuul/builds/9e704877d0dc4b359b5cfc80242ecfe8/work/9e704877d0dc4b359b5cfc80242ecfe8_id_rsa.pub
2026-04-07 06:30:39.568598 | instance -> localhost | The key fingerprint is:
2026-04-07 06:30:39.568619 | instance -> localhost | SHA256:JSbBYIUYOBPj6/spP3WqRonhR1kVcnZJbdxyT/g9p0M zuul-build-sshkey
2026-04-07 06:30:39.568651 | instance -> localhost | The key's randomart image is:
2026-04-07 06:30:39.568673 | instance -> localhost | +---[RSA 3072]----+
2026-04-07 06:30:39.568699 | instance -> localhost | |oo.oo*+=oo+ . .  |
2026-04-07 06:30:39.568721 | instance -> localhost | |=.....=... = + . |
2026-04-07 06:30:39.568741 | instance -> localhost | | +  o . o o o + .|
2026-04-07 06:30:39.568761 | instance -> localhost | | ..o   o o    E+o|
2026-04-07 06:30:39.568781 | instance -> localhost | |..+ .   S    . .o|
2026-04-07 06:30:39.568801 | instance -> localhost | |.o + . .      o  |
2026-04-07 06:30:39.568821 | instance -> localhost | | .o . o        . |
2026-04-07 06:30:39.568841 | instance -> localhost | | ..o..           |
2026-04-07 06:30:39.568863 | instance -> localhost | | .==o            |
2026-04-07 06:30:39.568884 | instance -> localhost | +----[SHA256]-----+
2026-04-07 06:30:39.568932 | instance -> localhost | ok: Runtime: 0:00:00.490141
2026-04-07 06:30:39.573841 | 
2026-04-07 06:30:39.573902 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-04-07 06:30:39.606754 | instance | ok
2026-04-07 06:30:39.615434 | instance | included: /var/lib/zuul/builds/9e704877d0dc4b359b5cfc80242ecfe8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-04-07 06:30:39.622545 | 
2026-04-07 06:30:39.622603 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-04-07 06:30:39.646433 | instance | skipping: Conditional result was False
2026-04-07 06:30:39.656360 | 
2026-04-07 06:30:39.656445 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-04-07 06:30:40.103177 | instance | changed
2026-04-07 06:30:40.108886 | 
2026-04-07 06:30:40.108957 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-04-07 06:30:40.298367 | instance | ok
2026-04-07 06:30:40.304538 | 
2026-04-07 06:30:40.304606 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-04-07 06:30:40.769957 | instance | changed
2026-04-07 06:30:40.776608 | 
2026-04-07 06:30:40.776670 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-04-07 06:30:41.227082 | instance | changed
2026-04-07 06:30:41.263152 | 
2026-04-07 06:30:41.263219 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-04-07 06:30:41.287958 | instance | skipping: Conditional result was False
2026-04-07 06:30:41.297390 | 
2026-04-07 06:30:41.297480 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-04-07 06:30:41.669232 | instance -> localhost | changed
2026-04-07 06:30:41.683563 | 
2026-04-07 06:30:41.683651 | TASK [add-build-sshkey : Add back temp key]
2026-04-07 06:30:41.961216 | instance -> localhost | Identity added: /var/lib/zuul/builds/9e704877d0dc4b359b5cfc80242ecfe8/work/9e704877d0dc4b359b5cfc80242ecfe8_id_rsa (zuul-build-sshkey)
2026-04-07 06:30:41.961444 | instance -> localhost | ok: Runtime: 0:00:00.014652
2026-04-07 06:30:41.966588 | 
2026-04-07 06:30:41.966649 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-04-07 06:30:42.255700 | instance | ok
2026-04-07 06:30:42.266434 | 
2026-04-07 06:30:42.266498 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-04-07 06:30:42.290518 | instance | skipping: Conditional result was False
2026-04-07 06:30:42.303591 | 
2026-04-07 06:30:42.303656 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-04-07 06:30:42.632941 | instance | ok
2026-04-07 06:30:42.638406 | 
2026-04-07 06:30:42.638485 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-04-07 06:30:44.224758 | instance | Output suppressed because no_log was given
2026-04-07 06:30:44.234130 | 
2026-04-07 06:30:44.234208 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-04-07 06:30:44.421353 | instance | ok: "logs"
2026-04-07 06:30:44.421915 | instance | ok: All items complete
2026-04-07 06:30:44.421946 | 
2026-04-07 06:30:44.589878 | instance | ok: "artifacts"
2026-04-07 06:30:44.746334 | instance | ok: "docs"
2026-04-07 06:30:44.764449 | 
2026-04-07 06:30:44.764613 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-04-07 06:30:44.951515 | instance | changed: "logs"
2026-04-07 06:30:45.113742 | instance | changed: "artifacts"
2026-04-07 06:30:45.272757 | instance | changed: "docs"
2026-04-07 06:30:45.291575 | 
2026-04-07 06:30:45.291704 | PLAY RECAP
2026-04-07 06:30:45.291767 | instance | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2026-04-07 06:30:45.291806 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-04-07 06:30:45.291837 | 
2026-04-07 06:30:45.397614 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-04-07 06:30:45.402236 | PRE-RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-04-07 06:30:45.996494 | 
2026-04-07 06:30:45.996676 | PLAY [all]
2026-04-07 06:30:46.009337 | 
2026-04-07 06:30:46.010341 | TASK [setup-uv : Extract archive]
2026-04-07 06:30:48.112311 | instance | changed
2026-04-07 06:30:48.123180 | 
2026-04-07 06:30:48.123278 | TASK [setup-uv : Print version]
2026-04-07 06:30:48.414265 | instance | uv 0.8.13
2026-04-07 06:30:48.664348 | instance | ok: Runtime: 0:00:00.012745
2026-04-07 06:30:48.670584 | 
2026-04-07 06:30:48.670641 | PLAY RECAP
2026-04-07 06:30:48.671274 | instance | ok: 2 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-04-07 06:30:48.671351 | 
2026-04-07 06:30:48.770642 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-04-07 06:30:48.775350 | PRE-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@main]
2026-04-07 06:30:49.333259 | 
2026-04-07 06:30:49.333375 | PLAY [all]
2026-04-07 06:30:49.344282 | 
2026-04-07 06:30:49.344352 | TASK [Install "jq" for log collection]
2026-04-07 06:31:05.912842 | instance | changed
2026-04-07 06:31:05.914750 | 
2026-04-07 06:31:05.914804 | PLAY RECAP
2026-04-07 06:31:05.914856 | instance | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-04-07 06:31:05.914903 | 
2026-04-07 06:31:06.002931 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@main]
2026-04-07 06:31:06.007509 | RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-04-07 06:31:06.534684 | 
2026-04-07 06:31:06.534804 | PLAY [all]
2026-04-07 06:31:06.545435 | 
2026-04-07 06:31:06.545502 | TASK [Copy inventory file for Zuul]
2026-04-07 06:31:07.369470 | instance | changed
2026-04-07 06:31:07.374354 | 
2026-04-07 06:31:07.374423 | TASK [Switch "ansible_host" to private IP]
2026-04-07 06:31:07.630432 | instance | changed: 1 replacements made
2026-04-07 06:31:07.637320 | 
2026-04-07 06:31:07.637406 | TASK [Run Molecule scenario]
2026-04-07 06:31:08.002291 | instance | Using CPython 3.10.12 interpreter at: /usr/bin/python3
2026-04-07 06:31:08.002393 | instance | Creating virtual environment at: .venv
2026-04-07 06:31:08.024233 | instance |    Building atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere
2026-04-07 06:31:08.048966 | instance | Downloading setuptools (1.1MiB)
2026-04-07 06:31:08.051677 | instance | Downloading cryptography (4.2MiB)
2026-04-07 06:31:08.051879 | instance | Downloading ansible-core (2.1MiB)
2026-04-07 06:31:08.052114 | instance | Downloading rjsonnet (1.2MiB)
2026-04-07 06:31:08.052516 | instance | Downloading kubernetes (1.9MiB)
2026-04-07 06:31:08.052724 | instance | Downloading openstacksdk (1.7MiB)
2026-04-07 06:31:08.052942 | instance | Downloading netaddr (2.2MiB)
2026-04-07 06:31:08.053206 | instance | Downloading pydantic-core (2.0MiB)
2026-04-07 06:31:08.053704 | instance | Downloading pygments (1.2MiB)
2026-04-07 06:31:08.336854 | instance |    Building pyperclip==1.9.0
2026-04-07 06:31:08.339467 | instance |  Downloading rjsonnet
2026-04-07 06:31:08.436207 | instance |  Downloading pydantic-core
2026-04-07 06:31:08.489877 | instance |  Downloading netaddr
2026-04-07 06:31:08.503164 | instance |  Downloading pygments
2026-04-07 06:31:08.511188 | instance |  Downloading cryptography
2026-04-07 06:31:08.540895 | instance |  Downloading setuptools
2026-04-07 06:31:08.588636 | instance |  Downloading kubernetes
2026-04-07 06:31:08.618440 | instance |  Downloading ansible-core
2026-04-07 06:31:08.645567 | instance |  Downloading openstacksdk
2026-04-07 06:31:09.015161 | instance |       Built pyperclip==1.9.0
2026-04-07 06:31:09.215271 | instance |       Built atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere
2026-04-07 06:31:09.253543 | instance | Installed 83 packages in 36ms
2026-04-07 06:31:09.867311 | instance | WARNING  Molecule scenarios should migrate to 'extensions/molecule'
2026-04-07 06:31:10.460574 | instance | INFO     [keycloak > discovery] scenario test matrix: dependency, cleanup, destroy, syntax, create, prepare, converge, idempotence, side_effect, verify, cleanup, destroy
2026-04-07 06:31:10.460632 | instance | INFO     [keycloak > prerun] Performing prerun with role_name_check=0...
2026-04-07 06:31:56.194478 | instance | CRITICAL The source path '/home/zuul/src/github.com/vexxhost/atmosphere/molecule/keycloak/host_vars' does not exist.
2026-04-07 06:31:56.194595 | instance | Traceback (most recent call last):
2026-04-07 06:31:56.194766 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/molecule", line 10, in <module>
2026-04-07 06:31:56.195002 | instance |     sys.exit(main())
2026-04-07 06:31:56.195075 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 1442, in __call__
2026-04-07 06:31:56.195440 | instance |     return self.main(*args, **kwargs)
2026-04-07 06:31:56.195523 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 1363, in main
2026-04-07 06:31:56.195857 | instance |     rv = self.invoke(ctx)
2026-04-07 06:31:56.195926 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 1830, in invoke
2026-04-07 06:31:56.196358 | instance |     return _process_result(sub_ctx.command.invoke(sub_ctx))
2026-04-07 06:31:56.196427 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 1226, in invoke
2026-04-07 06:31:56.196704 | instance |     return ctx.invoke(self.callback, **ctx.params)
2026-04-07 06:31:56.196831 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/core.py", line 794, in invoke
2026-04-07 06:31:56.197055 | instance |     return callback(*args, **kwargs)
2026-04-07 06:31:56.197181 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/molecule/click_cfg.py", line 583, in wrapper
2026-04-07 06:31:56.197397 | instance |     return func(*args, **kwargs)
2026-04-07 06:31:56.197523 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/click/decorators.py", line 34, in new_func
2026-04-07 06:31:56.197671 | instance |     return f(get_current_context(), *args, **kwargs)
2026-04-07 06:31:56.197794 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/molecule/click_cfg.py", line 418, in wrapper
2026-04-07 06:31:56.197984 | instance |     return func(ctx)
2026-04-07 06:31:56.198106 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/molecule/command/test.py", line 81, in test
2026-04-07 06:31:56.198277 | instance |     base.execute_cmdline_scenarios(scenario_name, args, command_args, ansible_args, exclude)
2026-04-07 06:31:56.198400 | 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-04-07 06:31:56.198576 | instance |     _run_scenarios(scenarios, command_args, default_config)
2026-04-07 06:31:56.198698 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/molecule/command/base.py", line 254, in _run_scenarios
2026-04-07 06:31:56.198953 | instance |     execute_scenario(scenario, shared_state=scenarios.shared_state)
2026-04-07 06:31:56.199082 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/molecule/command/base.py", line 373, in execute_scenario
2026-04-07 06:31:56.199288 | instance |     execute_subcommand(scenario.config, action)
2026-04-07 06:31:56.199411 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/molecule/command/base.py", line 358, in execute_subcommand
2026-04-07 06:31:56.199607 | instance |     return command(current_config).execute(args)
2026-04-07 06:31:56.199723 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/molecule/command/base.py", line 77, in __init__
2026-04-07 06:31:56.199887 | instance |     self._setup()
2026-04-07 06:31:56.200036 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/molecule/command/base.py", line 111, in _setup
2026-04-07 06:31:56.200192 | instance |     self._config.provisioner.manage_inventory()
2026-04-07 06:31:56.200314 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/molecule/provisioner/ansible.py", line 445, in manage_inventory
2026-04-07 06:31:56.200525 | instance |     self._link_or_update_vars()
2026-04-07 06:31:56.200653 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/lib/python3.10/site-packages/molecule/provisioner/ansible.py", line 513, in _link_or_update_vars
2026-04-07 06:31:56.200874 | instance |     raise MoleculeError(msg)
2026-04-07 06:31:56.200995 | instance | molecule.exceptions.MoleculeError
2026-04-07 06:31:56.738439 | instance | ERROR
2026-04-07 06:31:56.738752 | instance | {
2026-04-07 06:31:56.738818 | instance |   "delta": "0:00:48.331338",
2026-04-07 06:31:56.738863 | instance |   "end": "2026-04-07 06:31:56.267696",
2026-04-07 06:31:56.738905 | instance |   "msg": "non-zero return code",
2026-04-07 06:31:56.738944 | instance |   "rc": 1,
2026-04-07 06:31:56.738991 | instance |   "start": "2026-04-07 06:31:07.936358"
2026-04-07 06:31:56.739032 | instance | }
failure
2026-04-07 06:31:56.741719 | 
2026-04-07 06:31:56.741777 | PLAY RECAP
2026-04-07 06:31:56.741824 | instance | ok: 2 changed: 2 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0
2026-04-07 06:31:56.741844 | 
2026-04-07 06:31:56.833131 | RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-04-07 06:31:56.836076 | POST-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@main]
2026-04-07 06:31:57.390392 | 
2026-04-07 06:31:57.390529 | PLAY [all]
2026-04-07 06:31:57.404481 | 
2026-04-07 06:31:57.404566 | TASK [gather-host-logs : creating directory for system status]
2026-04-07 06:31:57.722775 | instance | changed
2026-04-07 06:31:57.729140 | 
2026-04-07 06:31:57.729220 | TASK [gather-host-logs : Get logs for each host]
2026-04-07 06:31:58.044934 | instance | + systemd-cgls --full --all --no-pager
2026-04-07 06:31:58.063955 | instance | + ip addr
2026-04-07 06:31:58.065202 | instance | + ip route
2026-04-07 06:31:58.066449 | instance | + lsblk
2026-04-07 06:31:58.070352 | instance | + mount
2026-04-07 06:31:58.072918 | instance | + docker images
2026-04-07 06:31:58.073392 | instance | /bin/bash: line 7: docker: command not found
2026-04-07 06:31:58.073634 | instance | + brctl show
2026-04-07 06:31:58.074025 | instance | /bin/bash: line 8: brctl: command not found
2026-04-07 06:31:58.074258 | instance | + ps aux --sort=-%mem
2026-04-07 06:31:58.087393 | instance | + dpkg -l
2026-04-07 06:31:58.094804 | instance | + CONTAINERS=($(docker ps -a --format '{{ .Names }}' --filter label=zuul))
2026-04-07 06:31:58.095132 | instance | ++ docker ps -a --format '{{ .Names }}' --filter label=zuul
2026-04-07 06:31:58.095158 | instance | /bin/bash: line 11: docker: command not found
2026-04-07 06:31:58.095444 | instance | + '[' '!' -z '' ']'
2026-04-07 06:31:58.266276 | instance | ok: Runtime: 0:00:00.055247
2026-04-07 06:31:58.273633 | 
2026-04-07 06:31:58.273705 | TASK [gather-host-logs : Downloads logs to executor]
2026-04-07 06:31:58.913433 | instance | changed:
2026-04-07 06:31:58.913644 | instance | created directory /var/lib/zuul/builds/9e704877d0dc4b359b5cfc80242ecfe8/work/logs/instance
2026-04-07 06:31:58.913682 | instance | cd+++++++++ system/
2026-04-07 06:31:58.913713 | instance | >f+++++++++ system/brctl-show.txt
2026-04-07 06:31:58.913744 | instance | >f+++++++++ system/docker-images.txt
2026-04-07 06:31:58.913772 | instance | >f+++++++++ system/ip-addr.txt
2026-04-07 06:31:58.913802 | instance | >f+++++++++ system/ip-route.txt
2026-04-07 06:31:58.913845 | instance | >f+++++++++ system/lsblk.txt
2026-04-07 06:31:58.913890 | instance | >f+++++++++ system/mount.txt
2026-04-07 06:31:58.913934 | instance | >f+++++++++ system/packages.txt
2026-04-07 06:31:58.913974 | instance | >f+++++++++ system/ps.txt
2026-04-07 06:31:58.914010 | instance | >f+++++++++ system/systemd-cgls.txt
2026-04-07 06:31:58.924990 | 
2026-04-07 06:31:58.925058 | LOOP [helm-release-status : creating directory for helm release status]
2026-04-07 06:31:59.122140 | instance | changed: "values"
2026-04-07 06:31:59.273839 | instance | changed: "releases"
2026-04-07 06:31:59.294583 | 
2026-04-07 06:31:59.294772 | TASK [helm-release-status : Gather get release status for helm charts]
2026-04-07 06:31:59.495076 | instance | /bin/bash: line 3: kubectl: command not found
2026-04-07 06:31:59.830963 | instance | ok: Runtime: 0:00:00.005378
2026-04-07 06:31:59.836743 | 
2026-04-07 06:31:59.836823 | TASK [helm-release-status : Downloads logs to executor]
2026-04-07 06:32:00.317342 | instance | changed:
2026-04-07 06:32:00.317582 | instance | cd+++++++++ helm/
2026-04-07 06:32:00.317641 | instance | cd+++++++++ helm/releases/
2026-04-07 06:32:00.317688 | instance | cd+++++++++ helm/values/
2026-04-07 06:32:00.326681 | 
2026-04-07 06:32:00.326756 | TASK [describe-kubernetes-objects : creating directory for cluster scoped objects]
2026-04-07 06:32:00.513599 | instance | changed
2026-04-07 06:32:00.518290 | 
2026-04-07 06:32:00.518353 | TASK [describe-kubernetes-objects : Gathering descriptions for cluster scoped objects]
2026-04-07 06:32:00.711946 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-04-07 06:32:00.712062 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-04-07 06:32:00.717261 | instance | environment: line 1: kubectl: command not found
2026-04-07 06:32:00.718700 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-04-07 06:32:00.719485 | instance | environment: line 1: kubectl: command not found
2026-04-07 06:32:00.721003 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-04-07 06:32:00.722001 | instance | environment: line 1: kubectl: command not found
2026-04-07 06:32:00.723361 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-04-07 06:32:00.723617 | instance | environment: line 1: kubectl: command not found
2026-04-07 06:32:00.725296 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-04-07 06:32:00.726253 | instance | environment: line 1: kubectl: command not found
2026-04-07 06:32:00.727386 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-04-07 06:32:01.054721 | instance | ok: Runtime: 0:00:00.024259
2026-04-07 06:32:01.061318 | 
2026-04-07 06:32:01.061382 | TASK [describe-kubernetes-objects : creating directory for namespace scoped objects]
2026-04-07 06:32:01.277846 | instance | changed
2026-04-07 06:32:01.282708 | 
2026-04-07 06:32:01.282776 | TASK [describe-kubernetes-objects : Gathering descriptions for namespace scoped objects]
2026-04-07 06:32:01.505911 | instance | environment: line 5: kubectl: command not found
2026-04-07 06:32:01.506749 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-04-07 06:32:01.507170 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-04-07 06:32:01.507198 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-04-07 06:32:01.843329 | instance | ok: Runtime: 0:00:00.008889
2026-04-07 06:32:01.850394 | 
2026-04-07 06:32:01.850455 | TASK [describe-kubernetes-objects : Downloads logs to executor]
2026-04-07 06:32:02.319863 | instance | changed:
2026-04-07 06:32:02.320123 | instance | cd+++++++++ objects/
2026-04-07 06:32:02.320183 | instance | cd+++++++++ objects/cluster/
2026-04-07 06:32:02.320229 | instance | cd+++++++++ objects/namespaced/
2026-04-07 06:32:02.329739 | 
2026-04-07 06:32:02.329800 | TASK [gather-pod-logs : creating directory for pod logs]
2026-04-07 06:32:02.523905 | instance | changed
2026-04-07 06:32:02.530921 | 
2026-04-07 06:32:02.531009 | TASK [gather-pod-logs : creating directory for failed pod logs]
2026-04-07 06:32:02.727620 | instance | changed
2026-04-07 06:32:02.732465 | 
2026-04-07 06:32:02.732529 | TASK [gather-pod-logs : retrieve all kubernetes logs, current and previous (if they exist)]
2026-04-07 06:32:02.936127 | instance | environment: line 3: kubectl: command not found
2026-04-07 06:32:03.267289 | instance | ok: Runtime: 0:00:00.007877
2026-04-07 06:32:03.274286 | 
2026-04-07 06:32:03.274385 | TASK [gather-pod-logs : Downloads pod logs to executor]
2026-04-07 06:32:03.743630 | instance | changed:
2026-04-07 06:32:03.743830 | instance | cd+++++++++ pod-logs/
2026-04-07 06:32:03.743868 | instance | cd+++++++++ pod-logs/failed-pods/
2026-04-07 06:32:03.755152 | 
2026-04-07 06:32:03.755217 | TASK [gather-prom-metrics : creating directory for helm release descriptions]
2026-04-07 06:32:03.950442 | instance | changed
2026-04-07 06:32:03.955547 | 
2026-04-07 06:32:03.955614 | TASK [gather-prom-metrics : Get metrics from exporter services in all namespaces]
2026-04-07 06:32:04.156395 | instance | /bin/bash: line 2: kubectl: command not found
2026-04-07 06:32:04.489424 | instance | ok: Runtime: 0:00:00.038684
2026-04-07 06:32:04.495887 | 
2026-04-07 06:32:04.495953 | TASK [gather-prom-metrics : Get ceph metrics from ceph-mgr]
2026-04-07 06:32:04.695055 | instance | /bin/bash: line 2: kubectl: command not found
2026-04-07 06:32:04.730063 | instance | ceph-mgr endpoints:
2026-04-07 06:32:05.029554 | instance | ok: Runtime: 0:00:00.042175
2026-04-07 06:32:05.036277 | 
2026-04-07 06:32:05.036345 | TASK [gather-prom-metrics : Get metrics from fluentd pods]
2026-04-07 06:32:05.249469 | instance | /bin/bash: line 4: kubectl: command not found
2026-04-07 06:32:05.570832 | instance | ok: Runtime: 0:00:00.037666
2026-04-07 06:32:05.577984 | 
2026-04-07 06:32:05.578069 | TASK [gather-prom-metrics : Downloads logs to executor]
2026-04-07 06:32:06.047696 | instance | changed: cd+++++++++ prometheus/
2026-04-07 06:32:06.056495 | 
2026-04-07 06:32:06.056556 | TASK [gather-selenium-data : creating directory for helm release descriptions]
2026-04-07 06:32:06.252210 | instance | changed
2026-04-07 06:32:06.256944 | 
2026-04-07 06:32:06.257061 | TASK [gather-selenium-data : Get selenium data]
2026-04-07 06:32:06.475132 | instance | + cp '/tmp/artifacts/*' /tmp/logs/selenium/.
2026-04-07 06:32:06.476633 | instance | cp: cannot stat '/tmp/artifacts/*': No such file or directory
2026-04-07 06:32:06.792222 | instance | ERROR
2026-04-07 06:32:06.792528 | instance | {
2026-04-07 06:32:06.792595 | instance |   "delta": "0:00:00.006457",
2026-04-07 06:32:06.792642 | instance |   "end": "2026-04-07 06:32:06.477018",
2026-04-07 06:32:06.792683 | instance |   "msg": "non-zero return code",
2026-04-07 06:32:06.792724 | instance |   "rc": 1,
2026-04-07 06:32:06.792763 | instance |   "start": "2026-04-07 06:32:06.470561"
2026-04-07 06:32:06.792801 | instance | }
2026-04-07 06:32:06.792853 | instance | ERROR: Ignoring Errors
2026-04-07 06:32:06.799327 | 
2026-04-07 06:32:06.799393 | TASK [gather-selenium-data : Downloads logs to executor]
2026-04-07 06:32:07.296760 | instance | changed: cd+++++++++ selenium/
2026-04-07 06:32:07.304104 | 
2026-04-07 06:32:07.304151 | PLAY RECAP
2026-04-07 06:32:07.304192 | instance | ok: 23 changed: 23 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 1
2026-04-07 06:32:07.304213 | 
2026-04-07 06:32:07.397063 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@main]
2026-04-07 06:32:07.402281 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-04-07 06:32:07.933501 | 
2026-04-07 06:32:07.933604 | PLAY [all]
2026-04-07 06:32:07.944435 | 
2026-04-07 06:32:07.944508 | TASK [fetch-output : Set log path for multiple nodes]
2026-04-07 06:32:07.988819 | instance | skipping: Conditional result was False
2026-04-07 06:32:07.997976 | 
2026-04-07 06:32:07.998048 | TASK [fetch-output : Set log path for single node]
2026-04-07 06:32:08.041462 | instance | ok
2026-04-07 06:32:08.046113 | 
2026-04-07 06:32:08.046181 | LOOP [fetch-output : Ensure local output dirs]
2026-04-07 06:32:08.406483 | instance -> localhost | ok: "/var/lib/zuul/builds/9e704877d0dc4b359b5cfc80242ecfe8/work/logs"
2026-04-07 06:32:08.594082 | instance -> localhost | changed: "/var/lib/zuul/builds/9e704877d0dc4b359b5cfc80242ecfe8/work/artifacts"
2026-04-07 06:32:08.792643 | instance -> localhost | changed: "/var/lib/zuul/builds/9e704877d0dc4b359b5cfc80242ecfe8/work/docs"
2026-04-07 06:32:08.814086 | 
2026-04-07 06:32:08.814231 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-04-07 06:32:09.398909 | instance | changed: .d..t...... ./
2026-04-07 06:32:09.399144 | instance | changed: All items complete
2026-04-07 06:32:09.399183 | 
2026-04-07 06:32:09.831637 | instance | changed: .d..t...... ./
2026-04-07 06:32:10.262803 | instance | changed: .d..t...... ./
2026-04-07 06:32:10.277627 | 
2026-04-07 06:32:10.277795 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-04-07 06:32:10.680664 | instance -> localhost | ok: Item: artifacts Runtime: 0:00:00.006556
2026-04-07 06:32:10.924881 | instance -> localhost | ok: Item: docs Runtime: 0:00:00.007221
2026-04-07 06:32:10.937265 | 
2026-04-07 06:32:10.937389 | PLAY [all]
2026-04-07 06:32:10.943354 | 
2026-04-07 06:32:10.943414 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-04-07 06:32:11.380260 | instance | changed
2026-04-07 06:32:11.386031 | 
2026-04-07 06:32:11.386080 | PLAY RECAP
2026-04-07 06:32:11.386126 | instance | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-04-07 06:32:11.386148 | 
2026-04-07 06:32:11.483606 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-04-07 06:32:11.487779 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main]
2026-04-07 06:32:12.012073 | 
2026-04-07 06:32:12.012187 | PLAY [localhost]
2026-04-07 06:32:12.022426 | 
2026-04-07 06:32:12.022503 | TASK [Generate Zuul manifest]
2026-04-07 06:32:12.039424 | localhost | ok
2026-04-07 06:32:12.052683 | 
2026-04-07 06:32:12.052761 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-04-07 06:32:12.396333 | localhost | changed
2026-04-07 06:32:12.407249 | 
2026-04-07 06:32:12.407319 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-04-07 06:32:12.436808 | localhost | ok
2026-04-07 06:32:12.445479 | 
2026-04-07 06:32:12.445539 | TASK [Upload logs]
2026-04-07 06:32:12.465499 | localhost | ok
2026-04-07 06:32:12.519253 | 
2026-04-07 06:32:12.519347 | TASK [Set zuul-log-path fact]
2026-04-07 06:32:12.538530 | localhost | ok
2026-04-07 06:32:12.551245 | 
2026-04-07 06:32:12.551319 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-04-07 06:32:12.581820 | localhost | ok
2026-04-07 06:32:12.588847 | 
2026-04-07 06:32:12.588909 | TASK [upload-logs : Create log directories]
2026-04-07 06:32:12.954662 | localhost | changed
2026-04-07 06:32:12.961985 | 
2026-04-07 06:32:12.962052 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-04-07 06:32:13.328673 | localhost -> localhost | ok: Runtime: 0:00:00.004949
2026-04-07 06:32:13.334816 | 
2026-04-07 06:32:13.334901 | TASK [upload-logs : Upload logs to log server]
2026-04-07 06:32:13.760217 | localhost | Output suppressed because no_log was given
2026-04-07 06:32:13.764862 | 
2026-04-07 06:32:13.764942 | LOOP [upload-logs : Compress console log and json output]
2026-04-07 06:32:13.802499 | localhost | skipping: Conditional result was False
2026-04-07 06:32:13.809380 | localhost | skipping: Conditional result was False
2026-04-07 06:32:13.818598 | 
2026-04-07 06:32:13.818808 | LOOP [upload-logs : Upload compressed console log and json output]
2026-04-07 06:32:13.859254 | localhost | skipping: Conditional result was False
2026-04-07 06:32:13.859602 | 
2026-04-07 06:32:13.863646 | localhost | skipping: Conditional result was False
2026-04-07 06:32:13.880934 | 
2026-04-07 06:32:13.881121 | LOOP [upload-logs : Upload console log and json output]