2026-04-07 05:05:22.810048 | Job console starting
2026-04-07 05:05:22.830887 | Updating git repos
2026-04-07 05:05:22.910839 | Cloning repos into workspace
2026-04-07 05:05:22.999973 | Restoring repo states
2026-04-07 05:05:23.016275 | Merging changes
2026-04-07 05:05:24.068075 | Checking out repos
2026-04-07 05:05:24.160008 | Preparing playbooks
2026-04-07 05:05:29.292599 | Running Ansible setup
2026-04-07 05:05:32.687528 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-04-07 05:05:33.264929 | 
2026-04-07 05:05:33.265185 | PLAY [localhost]
2026-04-07 05:05:33.272380 | 
2026-04-07 05:05:33.272453 | TASK [Gathering Facts]
2026-04-07 05:05:34.671947 | localhost | ok
2026-04-07 05:05:34.678694 | 
2026-04-07 05:05:34.678775 | TASK [Setup log path fact]
2026-04-07 05:05:34.696216 | localhost | ok
2026-04-07 05:05:34.707527 | 
2026-04-07 05:05:34.707593 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-04-07 05:05:34.736293 | localhost | ok
2026-04-07 05:05:34.745001 | 
2026-04-07 05:05:34.745278 | TASK [emit-job-header : Print job information]
2026-04-07 05:05:34.786698 | # Job Information
2026-04-07 05:05:34.786914 | Ansible Version: 2.16.16
2026-04-07 05:05:34.786986 | Job: atmosphere-molecule-keycloak
2026-04-07 05:05:34.787034 | Pipeline: check
2026-04-07 05:05:34.787077 | Executor: 0a8996d2b663
2026-04-07 05:05:34.787120 | Triggered by: https://github.com/vexxhost/atmosphere/pull/3809
2026-04-07 05:05:34.787169 | Event ID: 4c84b510-323f-11f1-9cae-ff3162cc5084
2026-04-07 05:05:34.791838 | 
2026-04-07 05:05:34.791899 | LOOP [emit-job-header : Print node information]
2026-04-07 05:05:34.880206 | localhost | ok:
2026-04-07 05:05:34.880470 | localhost | # Node Information
2026-04-07 05:05:34.880512 | localhost | Inventory Hostname: instance
2026-04-07 05:05:34.880544 | localhost | Hostname: np0000163803
2026-04-07 05:05:34.880573 | localhost | Username: zuul
2026-04-07 05:05:34.880608 | localhost | Distro: Ubuntu 22.04
2026-04-07 05:05:34.880638 | localhost | Provider: yul1
2026-04-07 05:05:34.880666 | localhost | Region: ca-ymq-1
2026-04-07 05:05:34.880694 | localhost | Label: ubuntu-jammy
2026-04-07 05:05:34.880721 | localhost | Product Name: OpenStack Nova
2026-04-07 05:05:34.880748 | localhost | Interface IP: 162.253.55.110
2026-04-07 05:05:34.898409 | 
2026-04-07 05:05:34.898535 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-04-07 05:05:35.267706 | localhost -> localhost | changed
2026-04-07 05:05:35.276687 | 
2026-04-07 05:05:35.276787 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-04-07 05:05:36.130058 | localhost -> localhost | changed
2026-04-07 05:05:36.136105 | 
2026-04-07 05:05:36.136176 | PLAY [all]
2026-04-07 05:05:36.143994 | 
2026-04-07 05:05:36.144061 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-04-07 05:05:36.392004 | instance -> localhost | ok
2026-04-07 05:05:36.398104 | 
2026-04-07 05:05:36.398170 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-04-07 05:05:36.426874 | instance | ok
2026-04-07 05:05:36.439786 | instance | included: /var/lib/zuul/builds/ab03dedca857429ea4295990b898e7c4/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-04-07 05:05:36.445878 | 
2026-04-07 05:05:36.445936 | TASK [add-build-sshkey : Create Temp SSH key]
2026-04-07 05:05:38.628639 | instance -> localhost | Generating public/private rsa key pair.
2026-04-07 05:05:38.628831 | instance -> localhost | Your identification has been saved in /var/lib/zuul/builds/ab03dedca857429ea4295990b898e7c4/work/ab03dedca857429ea4295990b898e7c4_id_rsa
2026-04-07 05:05:38.628872 | instance -> localhost | Your public key has been saved in /var/lib/zuul/builds/ab03dedca857429ea4295990b898e7c4/work/ab03dedca857429ea4295990b898e7c4_id_rsa.pub
2026-04-07 05:05:38.628917 | instance -> localhost | The key fingerprint is:
2026-04-07 05:05:38.628976 | instance -> localhost | SHA256:45f4CnnEvCuMeFJnqJzH+FGb668GvF2OLHZxTfr/xRc zuul-build-sshkey
2026-04-07 05:05:38.629022 | instance -> localhost | The key's randomart image is:
2026-04-07 05:05:38.629054 | instance -> localhost | +---[RSA 3072]----+
2026-04-07 05:05:38.629090 | instance -> localhost | |                 |
2026-04-07 05:05:38.629121 | instance -> localhost | |                 |
2026-04-07 05:05:38.629149 | instance -> localhost | |                 |
2026-04-07 05:05:38.629178 | instance -> localhost | |       o  .      |
2026-04-07 05:05:38.629207 | instance -> localhost | |   . .. S+     E |
2026-04-07 05:05:38.629235 | instance -> localhost | |    =.+*++..   ..|
2026-04-07 05:05:38.629263 | instance -> localhost | | . B.X=*=.o     +|
2026-04-07 05:05:38.629291 | instance -> localhost | |  B O.O+.+.    ..|
2026-04-07 05:05:38.629323 | instance -> localhost | |   *.=+++......  |
2026-04-07 05:05:38.629352 | instance -> localhost | +----[SHA256]-----+
2026-04-07 05:05:38.629411 | instance -> localhost | ok: Runtime: 0:00:01.565905
2026-04-07 05:05:38.636438 | 
2026-04-07 05:05:38.636533 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-04-07 05:05:38.666304 | instance | ok
2026-04-07 05:05:38.677347 | instance | included: /var/lib/zuul/builds/ab03dedca857429ea4295990b898e7c4/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-04-07 05:05:38.684519 | 
2026-04-07 05:05:38.684578 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-04-07 05:05:38.718598 | instance | skipping: Conditional result was False
2026-04-07 05:05:38.729983 | 
2026-04-07 05:05:38.730076 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-04-07 05:05:39.178382 | instance | changed
2026-04-07 05:05:39.199764 | 
2026-04-07 05:05:39.199848 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-04-07 05:05:39.371275 | instance | ok
2026-04-07 05:05:39.378178 | 
2026-04-07 05:05:39.378263 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-04-07 05:05:39.834186 | instance | changed
2026-04-07 05:05:39.841165 | 
2026-04-07 05:05:39.841231 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-04-07 05:05:40.291519 | instance | changed
2026-04-07 05:05:40.297820 | 
2026-04-07 05:05:40.297883 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-04-07 05:05:40.322821 | instance | skipping: Conditional result was False
2026-04-07 05:05:40.330384 | 
2026-04-07 05:05:40.330478 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-04-07 05:05:41.113983 | instance -> localhost | changed
2026-04-07 05:05:41.132320 | 
2026-04-07 05:05:41.132417 | TASK [add-build-sshkey : Add back temp key]
2026-04-07 05:05:41.405208 | instance -> localhost | Identity added: /var/lib/zuul/builds/ab03dedca857429ea4295990b898e7c4/work/ab03dedca857429ea4295990b898e7c4_id_rsa (zuul-build-sshkey)
2026-04-07 05:05:41.405421 | instance -> localhost | ok: Runtime: 0:00:00.013596
2026-04-07 05:05:41.411178 | 
2026-04-07 05:05:41.411239 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-04-07 05:05:41.702242 | instance | ok
2026-04-07 05:05:41.706841 | 
2026-04-07 05:05:41.706903 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-04-07 05:05:41.730634 | instance | skipping: Conditional result was False
2026-04-07 05:05:41.739888 | 
2026-04-07 05:05:41.739949 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-04-07 05:05:42.047565 | instance | ok
2026-04-07 05:05:42.056306 | 
2026-04-07 05:05:42.056453 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-04-07 05:05:43.922607 | instance | Output suppressed because no_log was given
2026-04-07 05:05:43.931116 | 
2026-04-07 05:05:43.931180 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-04-07 05:05:44.114743 | instance | ok: "logs"
2026-04-07 05:05:44.115029 | instance | ok: All items complete
2026-04-07 05:05:44.115058 | 
2026-04-07 05:05:44.265782 | instance | ok: "artifacts"
2026-04-07 05:05:44.423475 | instance | ok: "docs"
2026-04-07 05:05:44.440740 | 
2026-04-07 05:05:44.440886 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-04-07 05:05:44.629073 | instance | changed: "logs"
2026-04-07 05:05:44.780438 | instance | changed: "artifacts"
2026-04-07 05:05:44.928441 | instance | changed: "docs"
2026-04-07 05:05:44.944668 | 
2026-04-07 05:05:44.948756 | PLAY RECAP
2026-04-07 05:05:44.948827 | instance | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2026-04-07 05:05:44.948858 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-04-07 05:05:44.948878 | 
2026-04-07 05:05:45.080698 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-04-07 05:05:45.085895 | PRE-RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-04-07 05:05:45.677394 | 
2026-04-07 05:05:45.677579 | PLAY [all]
2026-04-07 05:05:45.689882 | 
2026-04-07 05:05:45.689962 | TASK [setup-uv : Extract archive]
2026-04-07 05:05:47.857255 | instance | changed
2026-04-07 05:05:47.865951 | 
2026-04-07 05:05:47.866034 | TASK [setup-uv : Print version]
2026-04-07 05:05:47.388803 | instance | uv 0.8.13
2026-04-07 05:05:48.402828 | instance | ok: Runtime: 0:00:00.010493
2026-04-07 05:05:48.411235 | 
2026-04-07 05:05:48.411303 | PLAY RECAP
2026-04-07 05:05:48.411361 | instance | ok: 2 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-04-07 05:05:48.411390 | 
2026-04-07 05:05:48.567396 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-04-07 05:05:48.569853 | PRE-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@main]
2026-04-07 05:05:49.126894 | 
2026-04-07 05:05:49.127019 | PLAY [all]
2026-04-07 05:05:49.138276 | 
2026-04-07 05:05:49.138358 | TASK [Install "jq" for log collection]
2026-04-07 05:06:00.163743 | instance | changed
2026-04-07 05:06:00.166617 | 
2026-04-07 05:06:00.166680 | PLAY RECAP
2026-04-07 05:06:00.166732 | instance | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-04-07 05:06:00.166784 | 
2026-04-07 05:06:00.369945 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/pre.yml@main]
2026-04-07 05:06:00.373455 | RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-04-07 05:06:00.919226 | 
2026-04-07 05:06:00.919349 | PLAY [all]
2026-04-07 05:06:00.930476 | 
2026-04-07 05:06:00.930545 | TASK [Copy inventory file for Zuul]
2026-04-07 05:06:01.784603 | instance | changed
2026-04-07 05:06:01.791882 | 
2026-04-07 05:06:01.791977 | TASK [Switch "ansible_host" to private IP]
2026-04-07 05:06:02.058974 | instance | changed: 1 replacements made
2026-04-07 05:06:02.064127 | 
2026-04-07 05:06:02.064192 | TASK [Run Molecule scenario]
2026-04-07 05:06:02.473739 | instance | Using CPython 3.10.12 interpreter at: /usr/bin/python3
2026-04-07 05:06:02.473981 | instance | Creating virtual environment at: .venv
2026-04-07 05:06:02.497760 | instance |    Building atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere
2026-04-07 05:06:02.528486 | instance | Downloading setuptools (1.1MiB)
2026-04-07 05:06:02.530093 | instance | Downloading pydantic-core (2.0MiB)
2026-04-07 05:06:02.530447 | instance | Downloading kubernetes (1.9MiB)
2026-04-07 05:06:02.530815 | instance | Downloading openstacksdk (1.7MiB)
2026-04-07 05:06:02.531017 | instance | Downloading ansible-core (2.1MiB)
2026-04-07 05:06:02.531401 | instance | Downloading cryptography (4.2MiB)
2026-04-07 05:06:02.532726 | instance | Downloading netaddr (2.2MiB)
2026-04-07 05:06:02.532948 | instance | Downloading rjsonnet (1.2MiB)
2026-04-07 05:06:02.750995 | instance | Downloading pygments (1.2MiB)
2026-04-07 05:06:02.862485 | instance |  Downloading rjsonnet
2026-04-07 05:06:02.868143 | instance |    Building pyperclip==1.9.0
2026-04-07 05:06:02.981870 | instance |  Downloading pydantic-core
2026-04-07 05:06:03.037712 | instance |  Downloading netaddr
2026-04-07 05:06:03.057303 | instance |  Downloading pygments
2026-04-07 05:06:03.058854 | instance |  Downloading cryptography
2026-04-07 05:06:03.088611 | instance |  Downloading setuptools
2026-04-07 05:06:03.142670 | instance |  Downloading kubernetes
2026-04-07 05:06:03.172145 | instance |  Downloading ansible-core
2026-04-07 05:06:03.202106 | instance |  Downloading openstacksdk
2026-04-07 05:06:03.608423 | instance |       Built pyperclip==1.9.0
2026-04-07 05:06:03.767381 | instance |       Built atmosphere @ file:///home/zuul/src/github.com/vexxhost/atmosphere
2026-04-07 05:06:03.804905 | instance | Installed 83 packages in 35ms
2026-04-07 05:06:04.421145 | instance | WARNING  Molecule scenarios should migrate to 'extensions/molecule'
2026-04-07 05:06:05.098169 | instance | INFO     [keycloak > discovery] scenario test matrix: dependency, cleanup, destroy, syntax, create, prepare, converge, idempotence, side_effect, verify, cleanup, destroy
2026-04-07 05:06:05.098941 | instance | INFO     [keycloak > prerun] Performing prerun with role_name_check=0...
2026-04-07 05:06:57.993808 | instance | CRITICAL The source path '/home/zuul/src/github.com/vexxhost/atmosphere/molecule/keycloak/host_vars' does not exist.
2026-04-07 05:06:57.993942 | instance | Traceback (most recent call last):
2026-04-07 05:06:57.993956 | instance |   File "/home/zuul/src/github.com/vexxhost/atmosphere/.venv/bin/molecule", line 10, in <module>
2026-04-07 05:06:57.993978 | instance |     sys.exit(main())
2026-04-07 05:06:57.993989 | 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:06:57.994293 | instance |     return self.main(*args, **kwargs)
2026-04-07 05:06:57.994375 | 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:06:57.994710 | instance |     rv = self.invoke(ctx)
2026-04-07 05:06:57.994793 | 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:06:57.995168 | instance |     return _process_result(sub_ctx.command.invoke(sub_ctx))
2026-04-07 05:06:57.995248 | 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:06:57.995566 | instance |     return ctx.invoke(self.callback, **ctx.params)
2026-04-07 05:06:57.995664 | 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:06:57.995981 | instance |     return callback(*args, **kwargs)
2026-04-07 05:06:57.996064 | 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:06:57.996326 | instance |     return func(*args, **kwargs)
2026-04-07 05:06:57.996397 | 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:06:57.996617 | instance |     return f(get_current_context(), *args, **kwargs)
2026-04-07 05:06:57.996686 | 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:06:57.996939 | instance |     return func(ctx)
2026-04-07 05:06:57.997000 | 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:06:57.997195 | instance |     base.execute_cmdline_scenarios(scenario_name, args, command_args, ansible_args, exclude)
2026-04-07 05:06:57.997303 | 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:06:57.997484 | instance |     _run_scenarios(scenarios, command_args, default_config)
2026-04-07 05:06:57.997610 | 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:06:57.997798 | instance |     execute_scenario(scenario, shared_state=scenarios.shared_state)
2026-04-07 05:06:57.997924 | 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:06:57.998132 | instance |     execute_subcommand(scenario.config, action)
2026-04-07 05:06:57.998251 | 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:06:57.998447 | instance |     return command(current_config).execute(args)
2026-04-07 05:06:57.998574 | 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:06:57.998742 | instance |     self._setup()
2026-04-07 05:06:57.998867 | 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:06:57.999038 | instance |     self._config.provisioner.manage_inventory()
2026-04-07 05:06:57.999166 | 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:06:57.999397 | instance |     self._link_or_update_vars()
2026-04-07 05:06:57.999523 | 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:06:57.999829 | instance |     raise MoleculeError(msg)
2026-04-07 05:06:57.999897 | instance | molecule.exceptions.MoleculeError
2026-04-07 05:06:58.288125 | instance | ERROR
2026-04-07 05:06:58.288334 | instance | {
2026-04-07 05:06:58.288364 | instance |   "delta": "0:00:55.656533",
2026-04-07 05:06:58.288384 | instance |   "end": "2026-04-07 05:06:58.067021",
2026-04-07 05:06:58.288403 | instance |   "msg": "non-zero return code",
2026-04-07 05:06:58.288421 | instance |   "rc": 1,
2026-04-07 05:06:58.288441 | instance |   "start": "2026-04-07 05:06:02.410488"
2026-04-07 05:06:58.288459 | instance | }
failure
2026-04-07 05:06:58.290490 | 
2026-04-07 05:06:58.290539 | PLAY RECAP
2026-04-07 05:06:58.290582 | instance | ok: 2 changed: 2 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0
2026-04-07 05:06:58.290604 | 
2026-04-07 05:06:58.395345 | RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-04-07 05:06:58.401361 | POST-RUN START: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@main]
2026-04-07 05:06:58.966627 | 
2026-04-07 05:06:58.966751 | PLAY [all]
2026-04-07 05:06:58.980711 | 
2026-04-07 05:06:58.980793 | TASK [gather-host-logs : creating directory for system status]
2026-04-07 05:06:59.349416 | instance | changed
2026-04-07 05:06:59.354953 | 
2026-04-07 05:06:59.355038 | TASK [gather-host-logs : Get logs for each host]
2026-04-07 05:06:59.694866 | instance | + systemd-cgls --full --all --no-pager
2026-04-07 05:06:59.706420 | instance | + ip addr
2026-04-07 05:06:59.709373 | instance | + ip route
2026-04-07 05:06:59.711238 | instance | + lsblk
2026-04-07 05:06:59.715313 | instance | + mount
2026-04-07 05:06:59.718173 | instance | + docker images
2026-04-07 05:06:59.718657 | instance | /bin/bash: line 7: docker: command not found
2026-04-07 05:06:59.718891 | instance | + brctl show
2026-04-07 05:06:59.719267 | instance | /bin/bash: line 8: brctl: command not found
2026-04-07 05:06:59.719441 | instance | + ps aux --sort=-%mem
2026-04-07 05:06:59.733993 | instance | + dpkg -l
2026-04-07 05:06:59.743212 | instance | + CONTAINERS=($(docker ps -a --format '{{ .Names }}' --filter label=zuul))
2026-04-07 05:06:59.743671 | instance | ++ docker ps -a --format '{{ .Names }}' --filter label=zuul
2026-04-07 05:06:59.743770 | instance | /bin/bash: line 11: docker: command not found
2026-04-07 05:06:59.744017 | instance | + '[' '!' -z '' ']'
2026-04-07 05:06:59.892422 | instance | ok: Runtime: 0:00:00.054004
2026-04-07 05:06:59.900673 | 
2026-04-07 05:06:59.900743 | TASK [gather-host-logs : Downloads logs to executor]
2026-04-07 05:07:00.529598 | instance | changed:
2026-04-07 05:07:00.529790 | instance | created directory /var/lib/zuul/builds/ab03dedca857429ea4295990b898e7c4/work/logs/instance
2026-04-07 05:07:00.529830 | instance | cd+++++++++ system/
2026-04-07 05:07:00.529861 | instance | >f+++++++++ system/brctl-show.txt
2026-04-07 05:07:00.529893 | instance | >f+++++++++ system/docker-images.txt
2026-04-07 05:07:00.529921 | instance | >f+++++++++ system/ip-addr.txt
2026-04-07 05:07:00.529952 | instance | >f+++++++++ system/ip-route.txt
2026-04-07 05:07:00.529981 | instance | >f+++++++++ system/lsblk.txt
2026-04-07 05:07:00.530009 | instance | >f+++++++++ system/mount.txt
2026-04-07 05:07:00.530038 | instance | >f+++++++++ system/packages.txt
2026-04-07 05:07:00.530065 | instance | >f+++++++++ system/ps.txt
2026-04-07 05:07:00.530092 | instance | >f+++++++++ system/systemd-cgls.txt
2026-04-07 05:07:00.539384 | 
2026-04-07 05:07:00.539449 | LOOP [helm-release-status : creating directory for helm release status]
2026-04-07 05:07:00.742053 | instance | changed: "values"
2026-04-07 05:07:00.935640 | instance | changed: "releases"
2026-04-07 05:07:00.954102 | 
2026-04-07 05:07:00.954373 | TASK [helm-release-status : Gather get release status for helm charts]
2026-04-07 05:07:01.161400 | instance | /bin/bash: line 3: kubectl: command not found
2026-04-07 05:07:01.492483 | instance | ok: Runtime: 0:00:00.006392
2026-04-07 05:07:01.498382 | 
2026-04-07 05:07:01.498458 | TASK [helm-release-status : Downloads logs to executor]
2026-04-07 05:07:01.989163 | instance | changed:
2026-04-07 05:07:01.989353 | instance | cd+++++++++ helm/
2026-04-07 05:07:01.989393 | instance | cd+++++++++ helm/releases/
2026-04-07 05:07:01.989423 | instance | cd+++++++++ helm/values/
2026-04-07 05:07:01.999761 | 
2026-04-07 05:07:01.999827 | TASK [describe-kubernetes-objects : creating directory for cluster scoped objects]
2026-04-07 05:07:02.196294 | instance | changed
2026-04-07 05:07:02.218929 | 
2026-04-07 05:07:02.219029 | TASK [describe-kubernetes-objects : Gathering descriptions for cluster scoped objects]
2026-04-07 05:07:02.432569 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-04-07 05:07:02.432682 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-04-07 05:07:02.438558 | instance | environment: line 1: kubectl: command not found
2026-04-07 05:07:02.439546 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-04-07 05:07:02.441417 | instance | environment: line 1: kubectl: command not found
2026-04-07 05:07:02.442317 | instance | environment: line 1: kubectl: command not found
2026-04-07 05:07:02.442342 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-04-07 05:07:02.444210 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-04-07 05:07:02.445242 | instance | environment: line 1: kubectl: command not found
2026-04-07 05:07:02.446343 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-04-07 05:07:02.446751 | instance | environment: line 1: kubectl: command not found
2026-04-07 05:07:02.448190 | instance | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-04-07 05:07:02.757729 | instance | ok: Runtime: 0:00:00.026142
2026-04-07 05:07:02.764771 | 
2026-04-07 05:07:02.764836 | TASK [describe-kubernetes-objects : creating directory for namespace scoped objects]
2026-04-07 05:07:02.961170 | instance | changed
2026-04-07 05:07:02.965986 | 
2026-04-07 05:07:02.966057 | TASK [describe-kubernetes-objects : Gathering descriptions for namespace scoped objects]
2026-04-07 05:07:03.208180 | instance | environment: line 5: kubectl: command not found
2026-04-07 05:07:03.208712 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-04-07 05:07:03.209217 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-04-07 05:07:03.210018 | instance | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-04-07 05:07:03.536894 | instance | ok: Runtime: 0:00:00.009573
2026-04-07 05:07:03.542795 | 
2026-04-07 05:07:03.542860 | TASK [describe-kubernetes-objects : Downloads logs to executor]
2026-04-07 05:07:04.035272 | instance | changed:
2026-04-07 05:07:04.035420 | instance | cd+++++++++ objects/
2026-04-07 05:07:04.035447 | instance | cd+++++++++ objects/cluster/
2026-04-07 05:07:04.035471 | instance | cd+++++++++ objects/namespaced/
2026-04-07 05:07:04.045463 | 
2026-04-07 05:07:04.045564 | TASK [gather-pod-logs : creating directory for pod logs]
2026-04-07 05:07:04.251357 | instance | changed
2026-04-07 05:07:04.290089 | 
2026-04-07 05:07:04.290221 | TASK [gather-pod-logs : creating directory for failed pod logs]
2026-04-07 05:07:04.487803 | instance | changed
2026-04-07 05:07:04.492498 | 
2026-04-07 05:07:04.492560 | TASK [gather-pod-logs : retrieve all kubernetes logs, current and previous (if they exist)]
2026-04-07 05:07:04.716690 | instance | environment: line 3: kubectl: command not found
2026-04-07 05:07:05.028056 | instance | ok: Runtime: 0:00:00.008264
2026-04-07 05:07:05.033130 | 
2026-04-07 05:07:05.033193 | TASK [gather-pod-logs : Downloads pod logs to executor]
2026-04-07 05:07:05.513232 | instance | changed:
2026-04-07 05:07:05.513425 | instance | cd+++++++++ pod-logs/
2026-04-07 05:07:05.513464 | instance | cd+++++++++ pod-logs/failed-pods/
2026-04-07 05:07:05.524688 | 
2026-04-07 05:07:05.524750 | TASK [gather-prom-metrics : creating directory for helm release descriptions]
2026-04-07 05:07:05.716481 | instance | changed
2026-04-07 05:07:05.721524 | 
2026-04-07 05:07:05.721591 | TASK [gather-prom-metrics : Get metrics from exporter services in all namespaces]
2026-04-07 05:07:05.926461 | instance | /bin/bash: line 2: kubectl: command not found
2026-04-07 05:07:06.258806 | instance | ok: Runtime: 0:00:00.038800
2026-04-07 05:07:06.265266 | 
2026-04-07 05:07:06.265332 | TASK [gather-prom-metrics : Get ceph metrics from ceph-mgr]
2026-04-07 05:07:06.472480 | instance | /bin/bash: line 2: kubectl: command not found
2026-04-07 05:07:06.502470 | instance | ceph-mgr endpoints:
2026-04-07 05:07:06.800921 | instance | ok: Runtime: 0:00:00.037029
2026-04-07 05:07:06.807275 | 
2026-04-07 05:07:06.807343 | TASK [gather-prom-metrics : Get metrics from fluentd pods]
2026-04-07 05:07:07.011680 | instance | /bin/bash: line 4: kubectl: command not found
2026-04-07 05:07:07.342817 | instance | ok: Runtime: 0:00:00.038433
2026-04-07 05:07:07.350074 | 
2026-04-07 05:07:07.350133 | TASK [gather-prom-metrics : Downloads logs to executor]
2026-04-07 05:07:07.820444 | instance | changed: cd+++++++++ prometheus/
2026-04-07 05:07:07.829295 | 
2026-04-07 05:07:07.829366 | TASK [gather-selenium-data : creating directory for helm release descriptions]
2026-04-07 05:07:08.045951 | instance | changed
2026-04-07 05:07:08.050651 | 
2026-04-07 05:07:08.050714 | TASK [gather-selenium-data : Get selenium data]
2026-04-07 05:07:08.259205 | instance | + cp '/tmp/artifacts/*' /tmp/logs/selenium/.
2026-04-07 05:07:08.260874 | instance | cp: cannot stat '/tmp/artifacts/*': No such file or directory
2026-04-07 05:07:08.585203 | instance | ERROR
2026-04-07 05:07:08.585502 | instance | {
2026-04-07 05:07:08.585556 | instance |   "delta": "0:00:00.007495",
2026-04-07 05:07:08.585588 | instance |   "end": "2026-04-07 05:07:08.261296",
2026-04-07 05:07:08.585614 | instance |   "msg": "non-zero return code",
2026-04-07 05:07:08.585640 | instance |   "rc": 1,
2026-04-07 05:07:08.585665 | instance |   "start": "2026-04-07 05:07:08.253801"
2026-04-07 05:07:08.585689 | instance | }
2026-04-07 05:07:08.585722 | instance | ERROR: Ignoring Errors
2026-04-07 05:07:08.591716 | 
2026-04-07 05:07:08.591781 | TASK [gather-selenium-data : Downloads logs to executor]
2026-04-07 05:07:09.081862 | instance | changed: cd+++++++++ selenium/
2026-04-07 05:07:09.087747 | 
2026-04-07 05:07:09.087797 | PLAY RECAP
2026-04-07 05:07:09.087842 | instance | ok: 23 changed: 23 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 1
2026-04-07 05:07:09.087865 | 
2026-04-07 05:07:09.217020 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/atmosphere/test-playbooks/molecule/post.yml@main]
2026-04-07 05:07:09.222489 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-04-07 05:07:09.793739 | 
2026-04-07 05:07:09.794174 | PLAY [all]
2026-04-07 05:07:09.805819 | 
2026-04-07 05:07:09.805892 | TASK [fetch-output : Set log path for multiple nodes]
2026-04-07 05:07:09.851873 | instance | skipping: Conditional result was False
2026-04-07 05:07:09.861033 | 
2026-04-07 05:07:09.861145 | TASK [fetch-output : Set log path for single node]
2026-04-07 05:07:09.904226 | instance | ok
2026-04-07 05:07:09.910404 | 
2026-04-07 05:07:09.910472 | LOOP [fetch-output : Ensure local output dirs]
2026-04-07 05:07:10.274791 | instance -> localhost | ok: "/var/lib/zuul/builds/ab03dedca857429ea4295990b898e7c4/work/logs"
2026-04-07 05:07:10.490061 | instance -> localhost | changed: "/var/lib/zuul/builds/ab03dedca857429ea4295990b898e7c4/work/artifacts"
2026-04-07 05:07:10.687254 | instance -> localhost | changed: "/var/lib/zuul/builds/ab03dedca857429ea4295990b898e7c4/work/docs"
2026-04-07 05:07:10.707850 | 
2026-04-07 05:07:10.708027 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-04-07 05:07:11.317908 | instance | changed: .d..t...... ./
2026-04-07 05:07:11.318242 | instance | changed: All items complete
2026-04-07 05:07:11.318280 | 
2026-04-07 05:07:11.756897 | instance | changed: .d..t...... ./
2026-04-07 05:07:12.197323 | instance | changed: .d..t...... ./
2026-04-07 05:07:12.222571 | 
2026-04-07 05:07:12.222743 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-04-07 05:07:12.622314 | instance -> localhost | ok: Item: artifacts Runtime: 0:00:00.008664
2026-04-07 05:07:12.825608 | instance -> localhost | ok: Item: docs Runtime: 0:00:00.006696
2026-04-07 05:07:12.846651 | 
2026-04-07 05:07:12.846767 | PLAY [all]
2026-04-07 05:07:12.852487 | 
2026-04-07 05:07:12.852547 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-04-07 05:07:13.261602 | instance | changed
2026-04-07 05:07:13.267038 | 
2026-04-07 05:07:13.267089 | PLAY RECAP
2026-04-07 05:07:13.267131 | instance | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-04-07 05:07:13.267153 | 
2026-04-07 05:07:13.385977 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-04-07 05:07:13.390604 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main]
2026-04-07 05:07:13.949048 | 
2026-04-07 05:07:13.949200 | PLAY [localhost]
2026-04-07 05:07:13.960301 | 
2026-04-07 05:07:13.960379 | TASK [Generate Zuul manifest]
2026-04-07 05:07:13.983724 | localhost | ok
2026-04-07 05:07:13.999896 | 
2026-04-07 05:07:13.999975 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-04-07 05:07:14.356531 | localhost | changed
2026-04-07 05:07:14.369272 | 
2026-04-07 05:07:14.369366 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-04-07 05:07:14.402124 | localhost | ok
2026-04-07 05:07:14.410672 | 
2026-04-07 05:07:14.410733 | TASK [Upload logs]
2026-04-07 05:07:14.433436 | localhost | ok
2026-04-07 05:07:14.493479 | 
2026-04-07 05:07:14.493631 | TASK [Set zuul-log-path fact]
2026-04-07 05:07:14.516266 | localhost | ok
2026-04-07 05:07:14.528974 | 
2026-04-07 05:07:14.529041 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-04-07 05:07:14.561716 | localhost | ok
2026-04-07 05:07:14.569834 | 
2026-04-07 05:07:14.569898 | TASK [upload-logs : Create log directories]
2026-04-07 05:07:14.965534 | localhost | changed
2026-04-07 05:07:14.971325 | 
2026-04-07 05:07:14.971394 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-04-07 05:07:15.382629 | localhost -> localhost | ok: Runtime: 0:00:00.007138
2026-04-07 05:07:15.387898 | 
2026-04-07 05:07:15.387968 | TASK [upload-logs : Upload logs to log server]
2026-04-07 05:07:15.838138 | localhost | Output suppressed because no_log was given
2026-04-07 05:07:15.844449 | 
2026-04-07 05:07:15.844515 | LOOP [upload-logs : Compress console log and json output]
2026-04-07 05:07:15.890221 | localhost | skipping: Conditional result was False
2026-04-07 05:07:15.897252 | localhost | skipping: Conditional result was False
2026-04-07 05:07:15.909775 | 
2026-04-07 05:07:15.909989 | LOOP [upload-logs : Upload compressed console log and json output]
2026-04-07 05:07:15.953996 | localhost | skipping: Conditional result was False
2026-04-07 05:07:15.954429 | 
2026-04-07 05:07:15.957987 | localhost | skipping: Conditional result was False
2026-04-07 05:07:15.976420 | 
2026-04-07 05:07:15.976676 | LOOP [upload-logs : Upload console log and json output]