2026-04-07 06:15:25.307454 | Job console starting
2026-04-07 06:15:25.329514 | Updating git repos
2026-04-07 06:15:25.396720 | Cloning repos into workspace
2026-04-07 06:15:25.454980 | Restoring repo states
2026-04-07 06:15:25.475412 | Merging changes
2026-04-07 06:15:26.487747 | Checking out repos
2026-04-07 06:15:26.784025 | Preparing playbooks
2026-04-07 06:15:29.350658 | Running Ansible setup
2026-04-07 06:15:32.483537 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-04-07 06:15:33.063354 | 
2026-04-07 06:15:33.063475 | PLAY [localhost]
2026-04-07 06:15:33.070547 | 
2026-04-07 06:15:33.070616 | TASK [Gathering Facts]
2026-04-07 06:15:33.991641 | localhost | ok
2026-04-07 06:15:34.008753 | 
2026-04-07 06:15:34.008943 | TASK [Setup log path fact]
2026-04-07 06:15:34.027355 | localhost | ok
2026-04-07 06:15:34.039357 | 
2026-04-07 06:15:34.039437 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-04-07 06:15:34.067592 | localhost | ok
2026-04-07 06:15:34.075383 | 
2026-04-07 06:15:34.075481 | TASK [emit-job-header : Print job information]
2026-04-07 06:15:34.104719 | # Job Information
2026-04-07 06:15:34.104908 | Ansible Version: 2.16.16
2026-04-07 06:15:34.104954 | Job: atmosphere-molecule-keycloak
2026-04-07 06:15:34.104993 | Pipeline: check
2026-04-07 06:15:34.105043 | Executor: 0a8996d2b663
2026-04-07 06:15:34.105074 | Triggered by: https://github.com/vexxhost/atmosphere/pull/3809
2026-04-07 06:15:34.105107 | Event ID: 119a91e0-3249-11f1-949d-fa1d635d1aa3
2026-04-07 06:15:34.109067 | 
2026-04-07 06:15:34.109170 | LOOP [emit-job-header : Print node information]
2026-04-07 06:15:34.203050 | localhost | ok:
2026-04-07 06:15:34.203305 | localhost | # Node Information
2026-04-07 06:15:34.203404 | localhost | Inventory Hostname: instance
2026-04-07 06:15:34.203440 | localhost | Hostname: np0000163858
2026-04-07 06:15:34.203476 | localhost | Username: zuul
2026-04-07 06:15:34.203525 | localhost | Distro: Ubuntu 22.04
2026-04-07 06:15:34.203564 | localhost | Provider: yul1
2026-04-07 06:15:34.203593 | localhost | Region: ca-ymq-1
2026-04-07 06:15:34.203621 | localhost | Label: ubuntu-jammy
2026-04-07 06:15:34.203647 | localhost | Product Name: OpenStack Nova
2026-04-07 06:15:34.203678 | localhost | Interface IP: 162.253.55.43
2026-04-07 06:15:34.217309 | 
2026-04-07 06:15:34.217494 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-04-07 06:15:34.587080 | localhost -> localhost | changed
2026-04-07 06:15:34.595313 | 
2026-04-07 06:15:34.595415 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-04-07 06:15:35.454086 | localhost -> localhost | changed
2026-04-07 06:15:35.462431 | 
2026-04-07 06:15:35.462492 | PLAY [all]
2026-04-07 06:15:35.470341 | 
2026-04-07 06:15:35.470407 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-04-07 06:15:35.687186 | instance -> localhost | ok
2026-04-07 06:15:35.693939 | 
2026-04-07 06:15:35.694018 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-04-07 06:15:35.725328 | instance | ok
2026-04-07 06:15:35.742307 | instance | included: /var/lib/zuul/builds/15767943126a493db585c40b2259c5de/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-04-07 06:15:35.749052 | 
2026-04-07 06:15:35.749166 | TASK [add-build-sshkey : Create Temp SSH key]
2026-04-07 06:15:37.163585 | instance -> localhost | Generating public/private rsa key pair.
2026-04-07 06:15:37.163814 | instance -> localhost | Your identification has been saved in /var/lib/zuul/builds/15767943126a493db585c40b2259c5de/work/15767943126a493db585c40b2259c5de_id_rsa
2026-04-07 06:15:37.163844 | instance -> localhost | Your public key has been saved in /var/lib/zuul/builds/15767943126a493db585c40b2259c5de/work/15767943126a493db585c40b2259c5de_id_rsa.pub
2026-04-07 06:15:37.163867 | instance -> localhost | The key fingerprint is:
2026-04-07 06:15:37.163889 | instance -> localhost | SHA256:htw+4rupDSVr63hUFywTuQQntO+6ZsnUfyMdw+u8wzg zuul-build-sshkey
2026-04-07 06:15:37.163919 | instance -> localhost | The key's randomart image is:
2026-04-07 06:15:37.163940 | instance -> localhost | +---[RSA 3072]----+
2026-04-07 06:15:37.163967 | instance -> localhost | |   .+.o+         |
2026-04-07 06:15:37.163989 | instance -> localhost | |     += o        |
2026-04-07 06:15:37.164009 | instance -> localhost | |    .. + .       |
2026-04-07 06:15:37.164029 | instance -> localhost | |     ooo.        |
2026-04-07 06:15:37.164049 | instance -> localhost | |    .o=.S.       |
2026-04-07 06:15:37.164069 | instance -> localhost | |    o=.o  +      |
2026-04-07 06:15:37.164088 | instance -> localhost | |   ++.o.o+ +     |
2026-04-07 06:15:37.164107 | instance -> localhost | |   o** oEoB      |
2026-04-07 06:15:37.164129 | instance -> localhost | |  .=*o*o =++     |
2026-04-07 06:15:37.164149 | instance -> localhost | +----[SHA256]-----+
2026-04-07 06:15:37.164194 | instance -> localhost | ok: Runtime: 0:00:01.039958
2026-04-07 06:15:37.169039 | 
2026-04-07 06:15:37.169100 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-04-07 06:15:37.199668 | instance | ok
2026-04-07 06:15:37.209116 | instance | included: /var/lib/zuul/builds/15767943126a493db585c40b2259c5de/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-04-07 06:15:37.216369 | 
2026-04-07 06:15:37.216428 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-04-07 06:15:37.239659 | instance | skipping: Conditional result was False
2026-04-07 06:15:37.249510 | 
2026-04-07 06:15:37.249596 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-04-07 06:15:37.656647 | instance | changed
2026-04-07 06:15:37.662465 | 
2026-04-07 06:15:37.662527 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-04-07 06:15:37.846012 | instance | ok
2026-04-07 06:15:37.852642 | 
2026-04-07 06:15:37.852704 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-04-07 06:15:38.301065 | instance | changed
2026-04-07 06:15:38.307139 | 
2026-04-07 06:15:38.307206 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-04-07 06:15:38.734478 | instance | changed
2026-04-07 06:15:38.739524 | 
2026-04-07 06:15:38.739591 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-04-07 06:15:38.763221 | instance | skipping: Conditional result was False
2026-04-07 06:15:38.772301 | 
2026-04-07 06:15:38.772404 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-04-07 06:15:39.133447 | instance -> localhost | changed
2026-04-07 06:15:39.148774 | 
2026-04-07 06:15:39.148839 | TASK [add-build-sshkey : Add back temp key]
2026-04-07 06:15:39.419697 | instance -> localhost | Identity added: /var/lib/zuul/builds/15767943126a493db585c40b2259c5de/work/15767943126a493db585c40b2259c5de_id_rsa (zuul-build-sshkey)
2026-04-07 06:15:39.419976 | instance -> localhost | ok: Runtime: 0:00:00.010068
2026-04-07 06:15:39.426034 | 
2026-04-07 06:15:39.426111 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-04-07 06:15:39.728396 | instance | ok
2026-04-07 06:15:39.733192 | 
2026-04-07 06:15:39.733259 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-04-07 06:15:39.757118 | instance | skipping: Conditional result was False
2026-04-07 06:15:39.771791 | 
2026-04-07 06:15:39.771881 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-04-07 06:15:40.079141 | instance | ok
2026-04-07 06:15:40.084523 | 
2026-04-07 06:15:40.084591 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-04-07 06:15:41.732048 | instance | Output suppressed because no_log was given
2026-04-07 06:15:41.740225 | 
2026-04-07 06:15:41.740284 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-04-07 06:15:41.932277 | instance | ok: "logs"
2026-04-07 06:15:41.932480 | instance | ok: All items complete
2026-04-07 06:15:41.932509 | 
2026-04-07 06:15:42.082756 | instance | ok: "artifacts"
2026-04-07 06:15:42.250130 | instance | ok: "docs"
2026-04-07 06:15:42.261684 | 
2026-04-07 06:15:42.262286 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-04-07 06:15:42.437190 | instance | changed: "logs"
2026-04-07 06:15:42.595867 | instance | changed: "artifacts"
2026-04-07 06:15:42.759500 | instance | changed: "docs"
2026-04-07 06:15:42.778678 | 
2026-04-07 06:15:42.778786 | PLAY RECAP
2026-04-07 06:15:42.778846 | instance | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2026-04-07 06:15:42.778886 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-04-07 06:15:42.778915 | 
2026-04-07 06:15:42.882921 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-04-07 06:15:42.887444 | PRE-RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-04-07 06:15:43.416082 | 
2026-04-07 06:15:43.416187 | PLAY [all]
2026-04-07 06:15:43.427564 | 
2026-04-07 06:15:43.427638 | TASK [setup-uv : Extract archive]
2026-04-07 06:15:45.652228 | instance | changed
2026-04-07 06:15:45.660240 | 
2026-04-07 06:15:45.660336 | TASK [setup-uv : Print version]
2026-04-07 06:15:45.255868 | instance | uv 0.8.13
2026-04-07 06:15:46.198327 | instance | ok: Runtime: 0:00:00.012680
2026-04-07 06:15:46.205978 | 
2026-04-07 06:15:46.206032 | PLAY RECAP
2026-04-07 06:15:46.206083 | instance | ok: 2 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-04-07 06:15:46.206152 | 
2026-04-07 06:15:46.346201 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-04-07 06:15:46.348337 | PRE-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@main]
2026-04-07 06:15:46.894019 | 
2026-04-07 06:15:46.894128 | PLAY [all]
2026-04-07 06:15:46.905545 | 
2026-04-07 06:15:46.905615 | TASK [Install "jq" for log collection]
2026-04-07 06:15:56.745950 | instance | changed
2026-04-07 06:15:56.747830 | 
2026-04-07 06:15:56.747896 | PLAY RECAP
2026-04-07 06:15:56.747947 | instance | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-04-07 06:15:56.747994 | 
2026-04-07 06:15:56.856680 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@main]
2026-04-07 06:15:56.862016 | RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-04-07 06:15:57.466919 | 
2026-04-07 06:15:57.467033 | PLAY [all]
2026-04-07 06:15:57.495467 | 
2026-04-07 06:15:57.495551 | TASK [Copy inventory file for Zuul]
2026-04-07 06:15:58.309498 | instance | changed
2026-04-07 06:15:58.317134 | 
2026-04-07 06:15:58.317237 | TASK [Switch "ansible_host" to private IP]
2026-04-07 06:15:58.596864 | instance | changed: 1 replacements made
2026-04-07 06:15:58.603141 | 
2026-04-07 06:15:58.603211 | TASK [Run Molecule scenario]
2026-04-07 06:15:59.012981 | instance | Using CPython 3.10.12 interpreter at: /usr/bin/python3
2026-04-07 06:15:59.013123 | instance | Creating virtual environment at: .venv
2026-04-07 06:15:59.041131 | instance |    Building atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere
2026-04-07 06:15:59.065545 | instance | Downloading setuptools (1.1MiB)
2026-04-07 06:15:59.065767 | instance | Downloading pydantic-core (2.0MiB)
2026-04-07 06:15:59.066270 | instance | Downloading cryptography (4.2MiB)
2026-04-07 06:15:59.067017 | instance | Downloading pygments (1.2MiB)
2026-04-07 06:15:59.069641 | instance | Downloading ansible-core (2.1MiB)
2026-04-07 06:15:59.069858 | instance | Downloading kubernetes (1.9MiB)
2026-04-07 06:15:59.070826 | instance | Downloading rjsonnet (1.2MiB)
2026-04-07 06:15:59.071111 | instance | Downloading netaddr (2.2MiB)
2026-04-07 06:15:59.359583 | instance | Downloading openstacksdk (1.7MiB)
2026-04-07 06:15:59.377873 | instance |  Downloading rjsonnet
2026-04-07 06:15:59.395803 | instance |    Building pyperclip==1.9.0
2026-04-07 06:15:59.469674 | instance |  Downloading pydantic-core
2026-04-07 06:15:59.518004 | instance |  Downloading netaddr
2026-04-07 06:15:59.557066 | instance |  Downloading pygments
2026-04-07 06:15:59.568373 | instance |  Downloading cryptography
2026-04-07 06:15:59.602726 | instance |  Downloading setuptools
2026-04-07 06:15:59.655205 | instance |  Downloading kubernetes
2026-04-07 06:15:59.685612 | instance |  Downloading ansible-core
2026-04-07 06:15:59.721578 | instance |  Downloading openstacksdk
2026-04-07 06:16:00.071161 | instance |       Built pyperclip==1.9.0
2026-04-07 06:16:00.265936 | instance |       Built atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere
2026-04-07 06:16:00.313920 | instance | Installed 83 packages in 45ms
2026-04-07 06:16:00.929860 | instance | WARNING  Molecule scenarios should migrate to 'extensions/molecule'
2026-04-07 06:16:01.553905 | instance | INFO     [keycloak > discovery] scenario test matrix: dependency, cleanup, destroy, syntax, create, prepare, converge, idempotence, side_effect, verify, cleanup, destroy
2026-04-07 06:16:01.553995 | instance | INFO     [keycloak > prerun] Performing prerun with role_name_check=0...
2026-04-07 06:16:40.818884 | instance | CRITICAL The source path '/home/zuul/src/github.com/vexxhost/atmosphere/molecule/keycloak/host_vars' does not exist.
2026-04-07 06:16:40.819270 | instance | Traceback (most recent call last):
2026-04-07 06:16:40.819480 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/molecule", line 10, in <module>
2026-04-07 06:16:40.819740 | instance |     sys.exit(main())
2026-04-07 06:16:40.819917 | 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:16:40.820336 | instance |     return self.main(*args, **kwargs)
2026-04-07 06:16:40.820513 | 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:16:40.820805 | instance |     rv = self.invoke(ctx)
2026-04-07 06:16:40.820932 | 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:16:40.821263 | instance |     return _process_result(sub_ctx.command.invoke(sub_ctx))
2026-04-07 06:16:40.821388 | 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:16:40.821660 | instance |     return ctx.invoke(self.callback, **ctx.params)
2026-04-07 06:16:40.821786 | 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:16:40.822020 | instance |     return callback(*args, **kwargs)
2026-04-07 06:16:40.822149 | 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:16:40.822363 | instance |     return func(*args, **kwargs)
2026-04-07 06:16:40.822530 | 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:16:40.822663 | instance |     return f(get_current_context(), *args, **kwargs)
2026-04-07 06:16:40.822786 | 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:16:40.822989 | instance |     return func(ctx)
2026-04-07 06:16:40.823107 | 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:16:40.823287 | instance |     base.execute_cmdline_scenarios(scenario_name, args, command_args, ansible_args, exclude)
2026-04-07 06:16:40.823440 | 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:16:40.823608 | instance |     _run_scenarios(scenarios, command_args, default_config)
2026-04-07 06:16:40.823735 | 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:16:40.823926 | instance |     execute_scenario(scenario, shared_state=scenarios.shared_state)
2026-04-07 06:16:40.824049 | 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:16:40.824260 | instance |     execute_subcommand(scenario.config, action)
2026-04-07 06:16:40.824375 | 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:16:40.824573 | instance |     return command(current_config).execute(args)
2026-04-07 06:16:40.824698 | 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:16:40.824869 | instance |     self._setup()
2026-04-07 06:16:40.824992 | 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:16:40.825163 | instance |     self._config.provisioner.manage_inventory()
2026-04-07 06:16:40.825289 | 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:16:40.825496 | instance |     self._link_or_update_vars()
2026-04-07 06:16:40.825660 | 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:16:40.825892 | instance |     raise MoleculeError(msg)
2026-04-07 06:16:40.826018 | instance | molecule.exceptions.MoleculeError
2026-04-07 06:16:41.201738 | instance | ERROR
2026-04-07 06:16:41.201955 | instance | {
2026-04-07 06:16:41.201984 | instance |   "delta": "0:00:41.949893",
2026-04-07 06:16:41.202004 | instance |   "end": "2026-04-07 06:16:40.897175",
2026-04-07 06:16:41.202023 | instance |   "msg": "non-zero return code",
2026-04-07 06:16:41.202040 | instance |   "rc": 1,
2026-04-07 06:16:41.202060 | instance |   "start": "2026-04-07 06:15:58.947282"
2026-04-07 06:16:41.202078 | instance | }
failure
2026-04-07 06:16:41.203974 | 
2026-04-07 06:16:41.204020 | PLAY RECAP
2026-04-07 06:16:41.204063 | instance | ok: 2 changed: 2 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0
2026-04-07 06:16:41.204084 | 
2026-04-07 06:16:41.294254 | RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-04-07 06:16:41.297464 | POST-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@main]
2026-04-07 06:16:41.877207 | 
2026-04-07 06:16:41.877334 | PLAY [all]
2026-04-07 06:16:41.891455 | 
2026-04-07 06:16:41.891538 | TASK [gather-host-logs : creating directory for system status]
2026-04-07 06:16:42.246545 | instance | changed
2026-04-07 06:16:42.253430 | 
2026-04-07 06:16:42.253532 | TASK [gather-host-logs : Get logs for each host]
2026-04-07 06:16:42.589855 | instance | + systemd-cgls --full --all --no-pager
2026-04-07 06:16:42.602912 | instance | + ip addr
2026-04-07 06:16:42.605212 | instance | + ip route
2026-04-07 06:16:42.607041 | instance | + lsblk
2026-04-07 06:16:42.610329 | instance | + mount
2026-04-07 06:16:42.612278 | instance | + docker images
2026-04-07 06:16:42.612770 | instance | /bin/bash: line 7: docker: command not found
2026-04-07 06:16:42.613047 | instance | + brctl show
2026-04-07 06:16:42.613545 | instance | /bin/bash: line 8: brctl: command not found
2026-04-07 06:16:42.613796 | instance | + ps aux --sort=-%mem
2026-04-07 06:16:42.625434 | instance | + dpkg -l
2026-04-07 06:16:42.635023 | instance | + CONTAINERS=($(docker ps -a --format '{{ .Names }}' --filter label=zuul))
2026-04-07 06:16:42.635320 | instance | ++ docker ps -a --format '{{ .Names }}' --filter label=zuul
2026-04-07 06:16:42.635391 | instance | /bin/bash: line 11: docker: command not found
2026-04-07 06:16:42.636163 | instance | + '[' '!' -z '' ']'
2026-04-07 06:16:42.789772 | instance | ok: Runtime: 0:00:00.051122
2026-04-07 06:16:42.797380 | 
2026-04-07 06:16:42.797460 | TASK [gather-host-logs : Downloads logs to executor]
2026-04-07 06:16:43.417191 | instance | changed:
2026-04-07 06:16:43.417428 | instance | created directory /var/lib/zuul/builds/15767943126a493db585c40b2259c5de/work/logs/instance
2026-04-07 06:16:43.417490 | instance | cd+++++++++ system/
2026-04-07 06:16:43.417537 | instance | >f+++++++++ system/brctl-show.txt
2026-04-07 06:16:43.417587 | instance | >f+++++++++ system/docker-images.txt
2026-04-07 06:16:43.417631 | instance | >f+++++++++ system/ip-addr.txt
2026-04-07 06:16:43.417681 | instance | >f+++++++++ system/ip-route.txt
2026-04-07 06:16:43.417727 | instance | >f+++++++++ system/lsblk.txt
2026-04-07 06:16:43.417770 | instance | >f+++++++++ system/mount.txt
2026-04-07 06:16:43.417816 | instance | >f+++++++++ system/packages.txt
2026-04-07 06:16:43.417859 | instance | >f+++++++++ system/ps.txt
2026-04-07 06:16:43.417900 | instance | >f+++++++++ system/systemd-cgls.txt
2026-04-07 06:16:43.431158 | 
2026-04-07 06:16:43.431223 | LOOP [helm-release-status : creating directory for helm release status]
2026-04-07 06:16:43.631086 | instance | changed: "values"
2026-04-07 06:16:43.791661 | instance | changed: "releases"
2026-04-07 06:16:43.809989 | 
2026-04-07 06:16:43.810103 | TASK [helm-release-status : Gather get release status for helm charts]
2026-04-07 06:16:44.013082 | instance | /bin/bash: line 3: kubectl: command not found
2026-04-07 06:16:44.343592 | instance | ok: Runtime: 0:00:00.005810
2026-04-07 06:16:44.348940 | 
2026-04-07 06:16:44.349023 | TASK [helm-release-status : Downloads logs to executor]
2026-04-07 06:16:44.825477 | instance | changed:
2026-04-07 06:16:44.825650 | instance | cd+++++++++ helm/
2026-04-07 06:16:44.825688 | instance | cd+++++++++ helm/releases/
2026-04-07 06:16:44.825717 | instance | cd+++++++++ helm/values/
2026-04-07 06:16:44.837032 | 
2026-04-07 06:16:44.837098 | TASK [describe-kubernetes-objects : creating directory for cluster scoped objects]
2026-04-07 06:16:45.041483 | instance | changed
2026-04-07 06:16:45.048642 | 
2026-04-07 06:16:45.048745 | TASK [describe-kubernetes-objects : Gathering descriptions for cluster scoped objects]
2026-04-07 06:16:45.267291 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-04-07 06:16:45.267394 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-04-07 06:16:45.272925 | instance | environment: line 1: kubectl: command not found
2026-04-07 06:16:45.274492 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-04-07 06:16:45.275131 | instance | environment: line 1: kubectl: command not found
2026-04-07 06:16:45.276050 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-04-07 06:16:45.277310 | instance | environment: line 1: kubectl: command not found
2026-04-07 06:16:45.278657 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-04-07 06:16:45.278739 | instance | environment: line 1: kubectl: command not found
2026-04-07 06:16:45.280045 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-04-07 06:16:45.281689 | instance | environment: line 1: kubectl: command not found
2026-04-07 06:16:45.282613 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-04-07 06:16:45.582055 | instance | ok: Runtime: 0:00:00.026117
2026-04-07 06:16:45.589679 | 
2026-04-07 06:16:45.589767 | TASK [describe-kubernetes-objects : creating directory for namespace scoped objects]
2026-04-07 06:16:45.783837 | instance | changed
2026-04-07 06:16:45.790479 | 
2026-04-07 06:16:45.790571 | TASK [describe-kubernetes-objects : Gathering descriptions for namespace scoped objects]
2026-04-07 06:16:46.017707 | instance | environment: line 5: kubectl: command not found
2026-04-07 06:16:46.018917 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-04-07 06:16:46.019155 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-04-07 06:16:46.019191 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-04-07 06:16:46.351342 | instance | ok: Runtime: 0:00:00.009168
2026-04-07 06:16:46.359400 | 
2026-04-07 06:16:46.359468 | TASK [describe-kubernetes-objects : Downloads logs to executor]
2026-04-07 06:16:46.837325 | instance | changed:
2026-04-07 06:16:46.837466 | instance | cd+++++++++ objects/
2026-04-07 06:16:46.837493 | instance | cd+++++++++ objects/cluster/
2026-04-07 06:16:46.837516 | instance | cd+++++++++ objects/namespaced/
2026-04-07 06:16:46.846813 | 
2026-04-07 06:16:46.846880 | TASK [gather-pod-logs : creating directory for pod logs]
2026-04-07 06:16:47.041267 | instance | changed
2026-04-07 06:16:47.048323 | 
2026-04-07 06:16:47.048404 | TASK [gather-pod-logs : creating directory for failed pod logs]
2026-04-07 06:16:47.255263 | instance | changed
2026-04-07 06:16:47.262787 | 
2026-04-07 06:16:47.262890 | TASK [gather-pod-logs : retrieve all kubernetes logs, current and previous (if they exist)]
2026-04-07 06:16:47.473231 | instance | environment: line 3: kubectl: command not found
2026-04-07 06:16:47.794431 | instance | ok: Runtime: 0:00:00.009322
2026-04-07 06:16:47.801571 | 
2026-04-07 06:16:47.801659 | TASK [gather-pod-logs : Downloads pod logs to executor]
2026-04-07 06:16:48.278494 | instance | changed:
2026-04-07 06:16:48.278659 | instance | cd+++++++++ pod-logs/
2026-04-07 06:16:48.278765 | instance | cd+++++++++ pod-logs/failed-pods/
2026-04-07 06:16:48.291328 | 
2026-04-07 06:16:48.291404 | TASK [gather-prom-metrics : creating directory for helm release descriptions]
2026-04-07 06:16:48.486110 | instance | changed
2026-04-07 06:16:48.490831 | 
2026-04-07 06:16:48.490891 | TASK [gather-prom-metrics : Get metrics from exporter services in all namespaces]
2026-04-07 06:16:48.685847 | instance | /bin/bash: line 2: kubectl: command not found
2026-04-07 06:16:49.024515 | instance | ok: Runtime: 0:00:00.034721
2026-04-07 06:16:49.030681 | 
2026-04-07 06:16:49.030744 | TASK [gather-prom-metrics : Get ceph metrics from ceph-mgr]
2026-04-07 06:16:49.233680 | instance | /bin/bash: line 2: kubectl: command not found
2026-04-07 06:16:49.264784 | instance | ceph-mgr endpoints:
2026-04-07 06:16:49.568345 | instance | ok: Runtime: 0:00:00.037280
2026-04-07 06:16:49.577157 | 
2026-04-07 06:16:49.577248 | TASK [gather-prom-metrics : Get metrics from fluentd pods]
2026-04-07 06:16:49.768282 | instance | /bin/bash: line 4: kubectl: command not found
2026-04-07 06:16:50.112642 | instance | ok: Runtime: 0:00:00.033958
2026-04-07 06:16:50.117803 | 
2026-04-07 06:16:50.117865 | TASK [gather-prom-metrics : Downloads logs to executor]
2026-04-07 06:16:50.589566 | instance | changed: cd+++++++++ prometheus/
2026-04-07 06:16:50.601202 | 
2026-04-07 06:16:50.601269 | TASK [gather-selenium-data : creating directory for helm release descriptions]
2026-04-07 06:16:50.798316 | instance | changed
2026-04-07 06:16:50.805472 | 
2026-04-07 06:16:50.805610 | TASK [gather-selenium-data : Get selenium data]
2026-04-07 06:16:51.001993 | instance | + cp '/tmp/artifacts/*' /tmp/logs/selenium/.
2026-04-07 06:16:51.003572 | instance | cp: cannot stat '/tmp/artifacts/*': No such file or directory
2026-04-07 06:16:51.343631 | instance | ERROR
2026-04-07 06:16:51.343847 | instance | {
2026-04-07 06:16:51.343906 | instance |   "delta": "0:00:00.006581",
2026-04-07 06:16:51.343965 | instance |   "end": "2026-04-07 06:16:51.004021",
2026-04-07 06:16:51.344308 | instance |   "msg": "non-zero return code",
2026-04-07 06:16:51.344342 | instance |   "rc": 1,
2026-04-07 06:16:51.344369 | instance |   "start": "2026-04-07 06:16:50.997440"
2026-04-07 06:16:51.344394 | instance | }
2026-04-07 06:16:51.344428 | instance | ERROR: Ignoring Errors
2026-04-07 06:16:51.351645 | 
2026-04-07 06:16:51.351743 | TASK [gather-selenium-data : Downloads logs to executor]
2026-04-07 06:16:51.814078 | instance | changed: cd+++++++++ selenium/
2026-04-07 06:16:51.820368 | 
2026-04-07 06:16:51.820419 | PLAY RECAP
2026-04-07 06:16:51.820471 | instance | ok: 23 changed: 23 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 1
2026-04-07 06:16:51.820495 | 
2026-04-07 06:16:51.989000 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@main]
2026-04-07 06:16:51.993841 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-04-07 06:16:52.545507 | 
2026-04-07 06:16:52.545614 | PLAY [all]
2026-04-07 06:16:52.556515 | 
2026-04-07 06:16:52.556592 | TASK [fetch-output : Set log path for multiple nodes]
2026-04-07 06:16:52.600208 | instance | skipping: Conditional result was False
2026-04-07 06:16:52.605891 | 
2026-04-07 06:16:52.605974 | TASK [fetch-output : Set log path for single node]
2026-04-07 06:16:52.645121 | instance | ok
2026-04-07 06:16:52.649574 | 
2026-04-07 06:16:52.649641 | LOOP [fetch-output : Ensure local output dirs]
2026-04-07 06:16:52.991927 | instance -> localhost | ok: "/var/lib/zuul/builds/15767943126a493db585c40b2259c5de/work/logs"
2026-04-07 06:16:53.188294 | instance -> localhost | changed: "/var/lib/zuul/builds/15767943126a493db585c40b2259c5de/work/artifacts"
2026-04-07 06:16:53.383589 | instance -> localhost | changed: "/var/lib/zuul/builds/15767943126a493db585c40b2259c5de/work/docs"
2026-04-07 06:16:53.405103 | 
2026-04-07 06:16:53.405248 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-04-07 06:16:53.993078 | instance | changed: .d..t...... ./
2026-04-07 06:16:53.993258 | instance | changed: All items complete
2026-04-07 06:16:53.993286 | 
2026-04-07 06:16:54.481405 | instance | changed: .d..t...... ./
2026-04-07 06:16:54.913706 | instance | changed: .d..t...... ./
2026-04-07 06:16:54.932567 | 
2026-04-07 06:16:54.932751 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-04-07 06:16:55.351811 | instance -> localhost | ok: Item: artifacts Runtime: 0:00:00.006965
2026-04-07 06:16:55.567588 | instance -> localhost | ok: Item: docs Runtime: 0:00:00.007305
2026-04-07 06:16:55.588615 | 
2026-04-07 06:16:55.588722 | PLAY [all]
2026-04-07 06:16:55.594653 | 
2026-04-07 06:16:55.594713 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-04-07 06:16:55.978592 | instance | changed
2026-04-07 06:16:55.987068 | 
2026-04-07 06:16:55.987157 | PLAY RECAP
2026-04-07 06:16:55.987240 | instance | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-04-07 06:16:55.987290 | 
2026-04-07 06:16:56.098393 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-04-07 06:16:56.103333 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main]
2026-04-07 06:16:56.664084 | 
2026-04-07 06:16:56.664187 | PLAY [localhost]
2026-04-07 06:16:56.674024 | 
2026-04-07 06:16:56.674125 | TASK [Generate Zuul manifest]
2026-04-07 06:16:56.692007 | localhost | ok
2026-04-07 06:16:56.709908 | 
2026-04-07 06:16:56.710001 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-04-07 06:16:57.082942 | localhost | changed
2026-04-07 06:16:57.093562 | 
2026-04-07 06:16:57.093638 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-04-07 06:16:57.123809 | localhost | ok
2026-04-07 06:16:57.134087 | 
2026-04-07 06:16:57.134155 | TASK [Upload logs]
2026-04-07 06:16:57.153473 | localhost | ok
2026-04-07 06:16:57.210643 | 
2026-04-07 06:16:57.210767 | TASK [Set zuul-log-path fact]
2026-04-07 06:16:57.230938 | localhost | ok
2026-04-07 06:16:57.247153 | 
2026-04-07 06:16:57.247227 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-04-07 06:16:57.279275 | localhost | ok
2026-04-07 06:16:57.286903 | 
2026-04-07 06:16:57.286971 | TASK [upload-logs : Create log directories]
2026-04-07 06:16:57.702150 | localhost | changed
2026-04-07 06:16:57.708063 | 
2026-04-07 06:16:57.708152 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-04-07 06:16:58.071636 | localhost -> localhost | ok: Runtime: 0:00:00.004537
2026-04-07 06:16:58.078089 | 
2026-04-07 06:16:58.078182 | TASK [upload-logs : Upload logs to log server]
2026-04-07 06:16:58.530473 | localhost | Output suppressed because no_log was given
2026-04-07 06:16:58.534185 | 
2026-04-07 06:16:58.534250 | LOOP [upload-logs : Compress console log and json output]
2026-04-07 06:16:58.574010 | localhost | skipping: Conditional result was False
2026-04-07 06:16:58.580760 | localhost | skipping: Conditional result was False
2026-04-07 06:16:58.597172 | 
2026-04-07 06:16:58.597312 | LOOP [upload-logs : Upload compressed console log and json output]
2026-04-07 06:16:58.633613 | localhost | skipping: Conditional result was False
2026-04-07 06:16:58.634037 | 
2026-04-07 06:16:58.637824 | localhost | skipping: Conditional result was False
2026-04-07 06:16:58.650571 | 
2026-04-07 06:16:58.650801 | LOOP [upload-logs : Upload console log and json output]