2026-04-07 05:46:56.111151 | Job console starting
2026-04-07 05:46:56.120364 | Updating git repos
2026-04-07 05:46:56.170914 | Cloning repos into workspace
2026-04-07 05:46:56.234426 | Restoring repo states
2026-04-07 05:46:56.254203 | Merging changes
2026-04-07 05:46:57.222954 | Checking out repos
2026-04-07 05:46:57.313727 | Preparing playbooks
2026-04-07 05:47:00.230161 | Running Ansible setup
2026-04-07 05:47:03.579759 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-04-07 05:47:04.181125 | 
2026-04-07 05:47:04.181259 | PLAY [localhost]
2026-04-07 05:47:04.189307 | 
2026-04-07 05:47:04.189393 | TASK [Gathering Facts]
2026-04-07 05:47:05.085116 | localhost | ok
2026-04-07 05:47:05.091887 | 
2026-04-07 05:47:05.091963 | TASK [Setup log path fact]
2026-04-07 05:47:05.123165 | localhost | ok
2026-04-07 05:47:05.134931 | 
2026-04-07 05:47:05.135011 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-04-07 05:47:05.166004 | localhost | ok
2026-04-07 05:47:05.174908 | 
2026-04-07 05:47:05.174977 | TASK [emit-job-header : Print job information]
2026-04-07 05:47:05.215981 | # Job Information
2026-04-07 05:47:05.216198 | Ansible Version: 2.16.16
2026-04-07 05:47:05.216249 | Job: atmosphere-molecule-keycloak
2026-04-07 05:47:05.216280 | Pipeline: check
2026-04-07 05:47:05.216308 | Executor: 0a8996d2b663
2026-04-07 05:47:05.216334 | Triggered by: https://github.com/vexxhost/atmosphere/pull/3809
2026-04-07 05:47:05.216365 | Event ID: 152f0010-3245-11f1-9ccb-719545a04a7a
2026-04-07 05:47:05.220264 | 
2026-04-07 05:47:05.222916 | LOOP [emit-job-header : Print node information]
2026-04-07 05:47:05.327774 | localhost | ok:
2026-04-07 05:47:05.328028 | localhost | # Node Information
2026-04-07 05:47:05.328085 | localhost | Inventory Hostname: instance
2026-04-07 05:47:05.328125 | localhost | Hostname: np0000163853
2026-04-07 05:47:05.328163 | localhost | Username: zuul
2026-04-07 05:47:05.328202 | localhost | Distro: Ubuntu 22.04
2026-04-07 05:47:05.328237 | localhost | Provider: yul1
2026-04-07 05:47:05.328270 | localhost | Region: ca-ymq-1
2026-04-07 05:47:05.328304 | localhost | Label: ubuntu-jammy
2026-04-07 05:47:05.328338 | localhost | Product Name: OpenStack Nova
2026-04-07 05:47:05.328371 | localhost | Interface IP: 162.253.55.204
2026-04-07 05:47:05.339149 | 
2026-04-07 05:47:05.339774 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-04-07 05:47:05.739372 | localhost -> localhost | changed
2026-04-07 05:47:05.745458 | 
2026-04-07 05:47:05.745526 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-04-07 05:47:06.701190 | localhost -> localhost | changed
2026-04-07 05:47:06.707381 | 
2026-04-07 05:47:06.707444 | PLAY [all]
2026-04-07 05:47:06.715288 | 
2026-04-07 05:47:06.715368 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-04-07 05:47:06.984684 | instance -> localhost | ok
2026-04-07 05:47:06.994336 | 
2026-04-07 05:47:06.994432 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-04-07 05:47:07.025185 | instance | ok
2026-04-07 05:47:07.039657 | instance | included: /var/lib/zuul/builds/c349f0d7ce214fbea5a6bb83f93cbb0f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-04-07 05:47:07.045975 | 
2026-04-07 05:47:07.069340 | TASK [add-build-sshkey : Create Temp SSH key]
2026-04-07 05:47:08.302687 | instance -> localhost | Generating public/private rsa key pair.
2026-04-07 05:47:08.302971 | instance -> localhost | Your identification has been saved in /var/lib/zuul/builds/c349f0d7ce214fbea5a6bb83f93cbb0f/work/c349f0d7ce214fbea5a6bb83f93cbb0f_id_rsa
2026-04-07 05:47:08.303039 | instance -> localhost | Your public key has been saved in /var/lib/zuul/builds/c349f0d7ce214fbea5a6bb83f93cbb0f/work/c349f0d7ce214fbea5a6bb83f93cbb0f_id_rsa.pub
2026-04-07 05:47:08.303091 | instance -> localhost | The key fingerprint is:
2026-04-07 05:47:08.303139 | instance -> localhost | SHA256:KOucHvrOEycP0yYqZQrKDyG6pFFpUG+fMOKD1fvoe+4 zuul-build-sshkey
2026-04-07 05:47:08.303208 | instance -> localhost | The key's randomart image is:
2026-04-07 05:47:08.303257 | instance -> localhost | +---[RSA 3072]----+
2026-04-07 05:47:08.303312 | instance -> localhost | |  .              |
2026-04-07 05:47:08.303360 | instance -> localhost | | . o             |
2026-04-07 05:47:08.303405 | instance -> localhost | |. o *            |
2026-04-07 05:47:08.303450 | instance -> localhost | | = + = o         |
2026-04-07 05:47:08.303494 | instance -> localhost | |o.* o.+ S        |
2026-04-07 05:47:08.303782 | instance -> localhost | |+o+.*=+          |
2026-04-07 05:47:08.303945 | instance -> localhost | |** .+X.          |
2026-04-07 05:47:08.304013 | instance -> localhost | |*+o*.oo          |
2026-04-07 05:47:08.304067 | instance -> localhost | |o.o=@*E          |
2026-04-07 05:47:08.304114 | instance -> localhost | +----[SHA256]-----+
2026-04-07 05:47:08.304232 | instance -> localhost | ok: Runtime: 0:00:00.720574
2026-04-07 05:47:08.310719 | 
2026-04-07 05:47:08.310784 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-04-07 05:47:08.345201 | instance | ok
2026-04-07 05:47:08.354427 | instance | included: /var/lib/zuul/builds/c349f0d7ce214fbea5a6bb83f93cbb0f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-04-07 05:47:08.362319 | 
2026-04-07 05:47:08.362381 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-04-07 05:47:08.386886 | instance | skipping: Conditional result was False
2026-04-07 05:47:08.396152 | 
2026-04-07 05:47:08.396346 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-04-07 05:47:08.844813 | instance | changed
2026-04-07 05:47:08.850836 | 
2026-04-07 05:47:08.850901 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-04-07 05:47:09.026383 | instance | ok
2026-04-07 05:47:09.034524 | 
2026-04-07 05:47:09.034619 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-04-07 05:47:09.496186 | instance | changed
2026-04-07 05:47:09.502893 | 
2026-04-07 05:47:09.502971 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-04-07 05:47:09.935286 | instance | changed
2026-04-07 05:47:09.945180 | 
2026-04-07 05:47:09.945259 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-04-07 05:47:09.970751 | instance | skipping: Conditional result was False
2026-04-07 05:47:09.982596 | 
2026-04-07 05:47:09.982744 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-04-07 05:47:10.546206 | instance -> localhost | changed
2026-04-07 05:47:10.559860 | 
2026-04-07 05:47:10.559990 | TASK [add-build-sshkey : Add back temp key]
2026-04-07 05:47:10.867222 | instance -> localhost | Identity added: /var/lib/zuul/builds/c349f0d7ce214fbea5a6bb83f93cbb0f/work/c349f0d7ce214fbea5a6bb83f93cbb0f_id_rsa (zuul-build-sshkey)
2026-04-07 05:47:10.867693 | instance -> localhost | ok: Runtime: 0:00:00.012108
2026-04-07 05:47:10.874387 | 
2026-04-07 05:47:10.874522 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-04-07 05:47:11.171919 | instance | ok
2026-04-07 05:47:11.177925 | 
2026-04-07 05:47:11.177990 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-04-07 05:47:11.202348 | instance | skipping: Conditional result was False
2026-04-07 05:47:11.218213 | 
2026-04-07 05:47:11.218328 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-04-07 05:47:11.558601 | instance | ok
2026-04-07 05:47:11.564242 | 
2026-04-07 05:47:11.564356 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-04-07 05:47:13.213480 | instance | Output suppressed because no_log was given
2026-04-07 05:47:13.223391 | 
2026-04-07 05:47:13.223464 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-04-07 05:47:13.413111 | instance | ok: "logs"
2026-04-07 05:47:13.413334 | instance | ok: All items complete
2026-04-07 05:47:13.413362 | 
2026-04-07 05:47:13.573493 | instance | ok: "artifacts"
2026-04-07 05:47:13.728475 | instance | ok: "docs"
2026-04-07 05:47:13.746158 | 
2026-04-07 05:47:13.746318 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-04-07 05:47:13.920510 | instance | changed: "logs"
2026-04-07 05:47:14.074398 | instance | changed: "artifacts"
2026-04-07 05:47:14.227358 | instance | changed: "docs"
2026-04-07 05:47:14.246803 | 
2026-04-07 05:47:14.246996 | PLAY RECAP
2026-04-07 05:47:14.247058 | instance | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2026-04-07 05:47:14.247088 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-04-07 05:47:14.247108 | 
2026-04-07 05:47:14.422219 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-04-07 05:47:14.455690 | PRE-RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-04-07 05:47:15.070932 | 
2026-04-07 05:47:15.071067 | PLAY [all]
2026-04-07 05:47:15.083476 | 
2026-04-07 05:47:15.083583 | TASK [setup-uv : Extract archive]
2026-04-07 05:47:17.308053 | instance | changed
2026-04-07 05:47:17.314767 | 
2026-04-07 05:47:17.314873 | TASK [setup-uv : Print version]
2026-04-07 05:47:17.173446 | instance | uv 0.8.13
2026-04-07 05:47:17.850822 | instance | ok: Runtime: 0:00:00.013223
2026-04-07 05:47:17.860704 | 
2026-04-07 05:47:17.860803 | PLAY RECAP
2026-04-07 05:47:17.860849 | instance | ok: 2 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-04-07 05:47:17.860875 | 
2026-04-07 05:47:18.008619 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-04-07 05:47:18.013577 | PRE-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@main]
2026-04-07 05:47:18.637300 | 
2026-04-07 05:47:18.637435 | PLAY [all]
2026-04-07 05:47:18.648980 | 
2026-04-07 05:47:18.649087 | TASK [Install "jq" for log collection]
2026-04-07 05:47:29.202605 | instance | changed
2026-04-07 05:47:29.205594 | 
2026-04-07 05:47:29.205657 | PLAY RECAP
2026-04-07 05:47:29.205712 | instance | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-04-07 05:47:29.205761 | 
2026-04-07 05:47:29.319879 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@main]
2026-04-07 05:47:29.323462 | RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-04-07 05:47:29.876501 | 
2026-04-07 05:47:29.877280 | PLAY [all]
2026-04-07 05:47:29.888898 | 
2026-04-07 05:47:29.889018 | TASK [Copy inventory file for Zuul]
2026-04-07 05:47:30.861041 | instance | changed
2026-04-07 05:47:30.866233 | 
2026-04-07 05:47:30.866311 | TASK [Switch "ansible_host" to private IP]
2026-04-07 05:47:31.142039 | instance | changed: 1 replacements made
2026-04-07 05:47:31.150619 | 
2026-04-07 05:47:31.150743 | TASK [Run Molecule scenario]
2026-04-07 05:47:31.552428 | instance | Using CPython 3.10.12 interpreter at: /usr/bin/python3
2026-04-07 05:47:31.552561 | instance | Creating virtual environment at: .venv
2026-04-07 05:47:31.575623 | instance |    Building atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere
2026-04-07 05:47:31.597040 | instance | Downloading rjsonnet (1.2MiB)
2026-04-07 05:47:31.597858 | instance | Downloading openstacksdk (1.7MiB)
2026-04-07 05:47:31.598421 | instance | Downloading pygments (1.2MiB)
2026-04-07 05:47:31.607677 | instance | Downloading cryptography (4.2MiB)
2026-04-07 05:47:31.607943 | instance | Downloading netaddr (2.2MiB)
2026-04-07 05:47:31.608586 | instance | Downloading ansible-core (2.1MiB)
2026-04-07 05:47:31.609032 | instance | Downloading setuptools (1.1MiB)
2026-04-07 05:47:31.609715 | instance | Downloading pydantic-core (2.0MiB)
2026-04-07 05:47:31.609955 | instance | Downloading kubernetes (1.9MiB)
2026-04-07 05:47:31.939212 | instance |    Building pyperclip==1.9.0
2026-04-07 05:47:31.970005 | instance |  Downloading rjsonnet
2026-04-07 05:47:32.060616 | instance |  Downloading pydantic-core
2026-04-07 05:47:32.106579 | instance |  Downloading netaddr
2026-04-07 05:47:32.118138 | instance |  Downloading pygments
2026-04-07 05:47:32.131155 | instance |  Downloading cryptography
2026-04-07 05:47:32.162045 | instance |  Downloading setuptools
2026-04-07 05:47:32.215656 | instance |  Downloading kubernetes
2026-04-07 05:47:32.246872 | instance |  Downloading ansible-core
2026-04-07 05:47:32.277118 | instance |  Downloading openstacksdk
2026-04-07 05:47:32.647470 | instance |       Built pyperclip==1.9.0
2026-04-07 05:47:32.870891 | instance |       Built atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere
2026-04-07 05:47:32.916381 | instance | Installed 83 packages in 43ms
2026-04-07 05:47:33.528156 | instance | WARNING  Molecule scenarios should migrate to 'extensions/molecule'
2026-04-07 05:47:34.173739 | instance | INFO     [keycloak > discovery] scenario test matrix: dependency, cleanup, destroy, syntax, create, prepare, converge, idempotence, side_effect, verify, cleanup, destroy
2026-04-07 05:47:34.173929 | instance | INFO     [keycloak > prerun] Performing prerun with role_name_check=0...
2026-04-07 05:48:13.582628 | instance | CRITICAL The source path '/home/zuul/src/github.com/vexxhost/atmosphere/molecule/keycloak/host_vars' does not exist.
2026-04-07 05:48:13.582812 | instance | Traceback (most recent call last):
2026-04-07 05:48:13.582952 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/molecule", line 10, in <module>
2026-04-07 05:48:13.583150 | instance |     sys.exit(main())
2026-04-07 05:48:13.583283 | 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 05:48:13.583594 | instance |     return self.main(*args, **kwargs)
2026-04-07 05:48:13.583765 | 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 05:48:13.584104 | instance |     rv = self.invoke(ctx)
2026-04-07 05:48:13.584231 | 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 05:48:13.584571 | instance |     return _process_result(sub_ctx.command.invoke(sub_ctx))
2026-04-07 05:48:13.584698 | 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 05:48:13.584972 | instance |     return ctx.invoke(self.callback, **ctx.params)
2026-04-07 05:48:13.585101 | 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 05:48:13.585335 | instance |     return callback(*args, **kwargs)
2026-04-07 05:48:13.585465 | 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 05:48:13.585683 | instance |     return func(*args, **kwargs)
2026-04-07 05:48:13.585798 | 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 05:48:13.585975 | instance |     return f(get_current_context(), *args, **kwargs)
2026-04-07 05:48:13.586093 | 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 05:48:13.586289 | instance |     return func(ctx)
2026-04-07 05:48:13.586414 | 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 05:48:13.586589 | instance |     base.execute_cmdline_scenarios(scenario_name, args, command_args, ansible_args, exclude)
2026-04-07 05:48:13.586714 | 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 05:48:13.586894 | instance |     _run_scenarios(scenarios, command_args, default_config)
2026-04-07 05:48:13.587019 | 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 05:48:13.587209 | instance |     execute_scenario(scenario, shared_state=scenarios.shared_state)
2026-04-07 05:48:13.587341 | 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 05:48:13.587553 | instance |     execute_subcommand(scenario.config, action)
2026-04-07 05:48:13.587666 | 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 05:48:13.587930 | instance |     return command(current_config).execute(args)
2026-04-07 05:48:13.588065 | 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 05:48:13.588239 | instance |     self._setup()
2026-04-07 05:48:13.588364 | 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 05:48:13.588537 | instance |     self._config.provisioner.manage_inventory()
2026-04-07 05:48:13.588666 | 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 05:48:13.588865 | instance |     self._link_or_update_vars()
2026-04-07 05:48:13.588990 | 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 05:48:13.589203 | instance |     raise MoleculeError(msg)
2026-04-07 05:48:13.589326 | instance | molecule.exceptions.MoleculeError
2026-04-07 05:48:13.817912 | instance | ERROR
2026-04-07 05:48:13.818125 | instance | {
2026-04-07 05:48:13.818166 | instance |   "delta": "0:00:42.180782",
2026-04-07 05:48:13.818196 | instance |   "end": "2026-04-07 05:48:13.667571",
2026-04-07 05:48:13.818223 | instance |   "msg": "non-zero return code",
2026-04-07 05:48:13.818249 | instance |   "rc": 1,
2026-04-07 05:48:13.818279 | instance |   "start": "2026-04-07 05:47:31.486789"
2026-04-07 05:48:13.818306 | instance | }
failure
2026-04-07 05:48:13.821127 | 
2026-04-07 05:48:13.821191 | PLAY RECAP
2026-04-07 05:48:13.821251 | instance | ok: 2 changed: 2 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0
2026-04-07 05:48:13.821281 | 
2026-04-07 05:48:13.983192 | RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-04-07 05:48:13.986943 | POST-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@main]
2026-04-07 05:48:14.597522 | 
2026-04-07 05:48:14.597669 | PLAY [all]
2026-04-07 05:48:14.612168 | 
2026-04-07 05:48:14.612257 | TASK [gather-host-logs : creating directory for system status]
2026-04-07 05:48:14.949908 | instance | changed
2026-04-07 05:48:14.959012 | 
2026-04-07 05:48:14.959381 | TASK [gather-host-logs : Get logs for each host]
2026-04-07 05:48:15.310109 | instance | + systemd-cgls --full --all --no-pager
2026-04-07 05:48:15.320762 | instance | + ip addr
2026-04-07 05:48:15.323923 | instance | + ip route
2026-04-07 05:48:15.325595 | instance | + lsblk
2026-04-07 05:48:15.327885 | instance | + mount
2026-04-07 05:48:15.329691 | instance | + docker images
2026-04-07 05:48:15.330121 | instance | /bin/bash: line 7: docker: command not found
2026-04-07 05:48:15.330299 | instance | + brctl show
2026-04-07 05:48:15.330729 | instance | /bin/bash: line 8: brctl: command not found
2026-04-07 05:48:15.330955 | instance | + ps aux --sort=-%mem
2026-04-07 05:48:15.343170 | instance | + dpkg -l
2026-04-07 05:48:15.349378 | instance | + CONTAINERS=($(docker ps -a --format '{{ .Names }}' --filter label=zuul))
2026-04-07 05:48:15.349837 | instance | ++ docker ps -a --format '{{ .Names }}' --filter label=zuul
2026-04-07 05:48:15.349870 | instance | /bin/bash: line 11: docker: command not found
2026-04-07 05:48:15.350160 | instance | + '[' '!' -z '' ']'
2026-04-07 05:48:15.513662 | instance | ok: Runtime: 0:00:00.045903
2026-04-07 05:48:15.521518 | 
2026-04-07 05:48:15.521606 | TASK [gather-host-logs : Downloads logs to executor]
2026-04-07 05:48:16.195553 | instance | changed:
2026-04-07 05:48:16.195794 | instance | created directory /var/lib/zuul/builds/c349f0d7ce214fbea5a6bb83f93cbb0f/work/logs/instance
2026-04-07 05:48:16.195843 | instance | cd+++++++++ system/
2026-04-07 05:48:16.195902 | instance | >f+++++++++ system/brctl-show.txt
2026-04-07 05:48:16.195937 | instance | >f+++++++++ system/docker-images.txt
2026-04-07 05:48:16.195965 | instance | >f+++++++++ system/ip-addr.txt
2026-04-07 05:48:16.195996 | instance | >f+++++++++ system/ip-route.txt
2026-04-07 05:48:16.196025 | instance | >f+++++++++ system/lsblk.txt
2026-04-07 05:48:16.196053 | instance | >f+++++++++ system/mount.txt
2026-04-07 05:48:16.196083 | instance | >f+++++++++ system/packages.txt
2026-04-07 05:48:16.196111 | instance | >f+++++++++ system/ps.txt
2026-04-07 05:48:16.196138 | instance | >f+++++++++ system/systemd-cgls.txt
2026-04-07 05:48:16.206251 | 
2026-04-07 05:48:16.206319 | LOOP [helm-release-status : creating directory for helm release status]
2026-04-07 05:48:16.399240 | instance | changed: "values"
2026-04-07 05:48:16.590162 | instance | changed: "releases"
2026-04-07 05:48:16.611370 | 
2026-04-07 05:48:16.611507 | TASK [helm-release-status : Gather get release status for helm charts]
2026-04-07 05:48:16.820467 | instance | /bin/bash: line 3: kubectl: command not found
2026-04-07 05:48:17.146527 | instance | ok: Runtime: 0:00:00.006780
2026-04-07 05:48:17.152496 | 
2026-04-07 05:48:17.152574 | TASK [helm-release-status : Downloads logs to executor]
2026-04-07 05:48:17.661567 | instance | changed:
2026-04-07 05:48:17.662186 | instance | cd+++++++++ helm/
2026-04-07 05:48:17.662232 | instance | cd+++++++++ helm/releases/
2026-04-07 05:48:17.662264 | instance | cd+++++++++ helm/values/
2026-04-07 05:48:17.677696 | 
2026-04-07 05:48:17.677771 | TASK [describe-kubernetes-objects : creating directory for cluster scoped objects]
2026-04-07 05:48:17.874519 | instance | changed
2026-04-07 05:48:17.879438 | 
2026-04-07 05:48:17.879512 | TASK [describe-kubernetes-objects : Gathering descriptions for cluster scoped objects]
2026-04-07 05:48:18.102401 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-04-07 05:48:18.102873 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-04-07 05:48:18.108025 | instance | environment: line 1: kubectl: command not found
2026-04-07 05:48:18.109148 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-04-07 05:48:18.110974 | instance | environment: line 1: kubectl: command not found
2026-04-07 05:48:18.112646 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-04-07 05:48:18.113264 | instance | environment: line 1: kubectl: command not found
2026-04-07 05:48:18.114231 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-04-07 05:48:18.115979 | instance | environment: line 1: kubectl: command not found
2026-04-07 05:48:18.117206 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-04-07 05:48:18.117317 | instance | environment: line 1: kubectl: command not found
2026-04-07 05:48:18.118263 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-04-07 05:48:18.414021 | instance | ok: Runtime: 0:00:00.026206
2026-04-07 05:48:18.420998 | 
2026-04-07 05:48:18.421077 | TASK [describe-kubernetes-objects : creating directory for namespace scoped objects]
2026-04-07 05:48:18.616487 | instance | changed
2026-04-07 05:48:18.621700 | 
2026-04-07 05:48:18.621807 | TASK [describe-kubernetes-objects : Gathering descriptions for namespace scoped objects]
2026-04-07 05:48:18.874418 | instance | environment: line 5: kubectl: command not found
2026-04-07 05:48:18.875312 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-04-07 05:48:18.875687 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-04-07 05:48:18.875967 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-04-07 05:48:19.205454 | instance | ok: Runtime: 0:00:00.010409
2026-04-07 05:48:19.212122 | 
2026-04-07 05:48:19.212256 | TASK [describe-kubernetes-objects : Downloads logs to executor]
2026-04-07 05:48:19.702168 | instance | changed:
2026-04-07 05:48:19.702425 | instance | cd+++++++++ objects/
2026-04-07 05:48:19.702485 | instance | cd+++++++++ objects/cluster/
2026-04-07 05:48:19.702515 | instance | cd+++++++++ objects/namespaced/
2026-04-07 05:48:19.712051 | 
2026-04-07 05:48:19.712139 | TASK [gather-pod-logs : creating directory for pod logs]
2026-04-07 05:48:19.926694 | instance | changed
2026-04-07 05:48:19.933039 | 
2026-04-07 05:48:19.933135 | TASK [gather-pod-logs : creating directory for failed pod logs]
2026-04-07 05:48:20.130176 | instance | changed
2026-04-07 05:48:20.136575 | 
2026-04-07 05:48:20.136678 | TASK [gather-pod-logs : retrieve all kubernetes logs, current and previous (if they exist)]
2026-04-07 05:48:20.344236 | instance | environment: line 3: kubectl: command not found
2026-04-07 05:48:20.675379 | instance | ok: Runtime: 0:00:00.009413
2026-04-07 05:48:20.704374 | 
2026-04-07 05:48:20.704513 | TASK [gather-pod-logs : Downloads pod logs to executor]
2026-04-07 05:48:21.233884 | instance | changed:
2026-04-07 05:48:21.234097 | instance | cd+++++++++ pod-logs/
2026-04-07 05:48:21.234129 | instance | cd+++++++++ pod-logs/failed-pods/
2026-04-07 05:48:21.243914 | 
2026-04-07 05:48:21.243981 | TASK [gather-prom-metrics : creating directory for helm release descriptions]
2026-04-07 05:48:21.450766 | instance | changed
2026-04-07 05:48:21.457725 | 
2026-04-07 05:48:21.457821 | TASK [gather-prom-metrics : Get metrics from exporter services in all namespaces]
2026-04-07 05:48:21.659602 | instance | /bin/bash: line 2: kubectl: command not found
2026-04-07 05:48:21.994842 | instance | ok: Runtime: 0:00:00.037745
2026-04-07 05:48:21.999592 | 
2026-04-07 05:48:21.999660 | TASK [gather-prom-metrics : Get ceph metrics from ceph-mgr]
2026-04-07 05:48:22.206065 | instance | /bin/bash: line 2: kubectl: command not found
2026-04-07 05:48:22.236566 | instance | ceph-mgr endpoints:
2026-04-07 05:48:22.536731 | instance | ok: Runtime: 0:00:00.037447
2026-04-07 05:48:22.544075 | 
2026-04-07 05:48:22.544174 | TASK [gather-prom-metrics : Get metrics from fluentd pods]
2026-04-07 05:48:22.753027 | instance | /bin/bash: line 4: kubectl: command not found
2026-04-07 05:48:23.432089 | instance | ok: Runtime: 0:00:00.031690
2026-04-07 05:48:23.441940 | 
2026-04-07 05:48:23.442035 | TASK [gather-prom-metrics : Downloads logs to executor]
2026-04-07 05:48:23.930350 | instance | changed: cd+++++++++ prometheus/
2026-04-07 05:48:23.945503 | 
2026-04-07 05:48:23.945688 | TASK [gather-selenium-data : creating directory for helm release descriptions]
2026-04-07 05:48:24.144213 | instance | changed
2026-04-07 05:48:24.150360 | 
2026-04-07 05:48:24.150433 | TASK [gather-selenium-data : Get selenium data]
2026-04-07 05:48:24.348352 | instance | + cp '/tmp/artifacts/*' /tmp/logs/selenium/.
2026-04-07 05:48:24.349813 | instance | cp: cannot stat '/tmp/artifacts/*': No such file or directory
2026-04-07 05:48:24.686832 | instance | ERROR
2026-04-07 05:48:24.687082 | instance | {
2026-04-07 05:48:24.687115 | instance |   "delta": "0:00:00.006034",
2026-04-07 05:48:24.687138 | instance |   "end": "2026-04-07 05:48:24.350212",
2026-04-07 05:48:24.687162 | instance |   "msg": "non-zero return code",
2026-04-07 05:48:24.687187 | instance |   "rc": 1,
2026-04-07 05:48:24.687210 | instance |   "start": "2026-04-07 05:48:24.344178"
2026-04-07 05:48:24.687233 | instance | }
2026-04-07 05:48:24.687261 | instance | ERROR: Ignoring Errors
2026-04-07 05:48:24.692293 | 
2026-04-07 05:48:24.692363 | TASK [gather-selenium-data : Downloads logs to executor]
2026-04-07 05:48:25.181612 | instance | changed: cd+++++++++ selenium/
2026-04-07 05:48:25.189358 | 
2026-04-07 05:48:25.189407 | PLAY RECAP
2026-04-07 05:48:25.189451 | instance | ok: 23 changed: 23 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 1
2026-04-07 05:48:25.189473 | 
2026-04-07 05:48:25.337482 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@main]
2026-04-07 05:48:25.341130 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-04-07 05:48:25.995621 | 
2026-04-07 05:48:25.995748 | PLAY [all]
2026-04-07 05:48:26.007939 | 
2026-04-07 05:48:26.008051 | TASK [fetch-output : Set log path for multiple nodes]
2026-04-07 05:48:26.052895 | instance | skipping: Conditional result was False
2026-04-07 05:48:26.061724 | 
2026-04-07 05:48:26.061837 | TASK [fetch-output : Set log path for single node]
2026-04-07 05:48:26.101416 | instance | ok
2026-04-07 05:48:26.106049 | 
2026-04-07 05:48:26.106115 | LOOP [fetch-output : Ensure local output dirs]
2026-04-07 05:48:26.473965 | instance -> localhost | ok: "/var/lib/zuul/builds/c349f0d7ce214fbea5a6bb83f93cbb0f/work/logs"
2026-04-07 05:48:26.729258 | instance -> localhost | changed: "/var/lib/zuul/builds/c349f0d7ce214fbea5a6bb83f93cbb0f/work/artifacts"
2026-04-07 05:48:26.951081 | instance -> localhost | changed: "/var/lib/zuul/builds/c349f0d7ce214fbea5a6bb83f93cbb0f/work/docs"
2026-04-07 05:48:26.966467 | 
2026-04-07 05:48:26.966603 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-04-07 05:48:27.618386 | instance | changed: .d..t...... ./
2026-04-07 05:48:27.618591 | instance | changed: All items complete
2026-04-07 05:48:27.618619 | 
2026-04-07 05:48:28.068679 | instance | changed: .d..t...... ./
2026-04-07 05:48:28.537144 | instance | changed: .d..t...... ./
2026-04-07 05:48:28.559575 | 
2026-04-07 05:48:28.559730 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-04-07 05:48:29.063311 | instance -> localhost | ok: Item: artifacts Runtime: 0:00:00.008503
2026-04-07 05:48:29.282314 | instance -> localhost | ok: Item: docs Runtime: 0:00:00.008246
2026-04-07 05:48:29.298580 | 
2026-04-07 05:48:29.298717 | PLAY [all]
2026-04-07 05:48:29.305059 | 
2026-04-07 05:48:29.305125 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-04-07 05:48:29.751927 | instance | changed
2026-04-07 05:48:29.759176 | 
2026-04-07 05:48:29.759229 | PLAY RECAP
2026-04-07 05:48:29.759275 | instance | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-04-07 05:48:29.759297 | 
2026-04-07 05:48:29.905185 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-04-07 05:48:29.907855 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main]
2026-04-07 05:48:30.462294 | 
2026-04-07 05:48:30.462407 | PLAY [localhost]
2026-04-07 05:48:30.472424 | 
2026-04-07 05:48:30.472498 | TASK [Generate Zuul manifest]
2026-04-07 05:48:30.490726 | localhost | ok
2026-04-07 05:48:30.506515 | 
2026-04-07 05:48:30.506596 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-04-07 05:48:30.883758 | localhost | changed
2026-04-07 05:48:30.896236 | 
2026-04-07 05:48:30.896323 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-04-07 05:48:30.927422 | localhost | ok
2026-04-07 05:48:30.936060 | 
2026-04-07 05:48:30.936124 | TASK [Upload logs]
2026-04-07 05:48:30.957357 | localhost | ok
2026-04-07 05:48:31.013963 | 
2026-04-07 05:48:31.014056 | TASK [Set zuul-log-path fact]
2026-04-07 05:48:31.034329 | localhost | ok
2026-04-07 05:48:31.046625 | 
2026-04-07 05:48:31.046691 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-04-07 05:48:31.077825 | localhost | ok
2026-04-07 05:48:31.084386 | 
2026-04-07 05:48:31.084451 | TASK [upload-logs : Create log directories]
2026-04-07 05:48:31.511099 | localhost | changed
2026-04-07 05:48:31.517680 | 
2026-04-07 05:48:31.517831 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-04-07 05:48:31.921907 | localhost -> localhost | ok: Runtime: 0:00:00.008398
2026-04-07 05:48:31.927980 | 
2026-04-07 05:48:31.928045 | TASK [upload-logs : Upload logs to log server]
2026-04-07 05:48:32.373652 | localhost | Output suppressed because no_log was given
2026-04-07 05:48:32.378977 | 
2026-04-07 05:48:32.379066 | LOOP [upload-logs : Compress console log and json output]
2026-04-07 05:48:32.423305 | localhost | skipping: Conditional result was False
2026-04-07 05:48:32.430231 | localhost | skipping: Conditional result was False
2026-04-07 05:48:32.443760 | 
2026-04-07 05:48:32.443921 | LOOP [upload-logs : Upload compressed console log and json output]
2026-04-07 05:48:32.493920 | localhost | skipping: Conditional result was False
2026-04-07 05:48:32.494315 | 
2026-04-07 05:48:32.498039 | localhost | skipping: Conditional result was False
2026-04-07 05:48:32.508555 | 
2026-04-07 05:48:32.508660 | LOOP [upload-logs : Upload console log and json output]