2026-09-07 01:50:28.401227 | Job console starting
2026-09-07 01:50:28.425206 | Updating git repos
2026-09-07 01:50:28.528819 | Cloning repos into workspace
2026-09-07 01:50:28.583093 | Restoring repo states
2026-09-07 01:50:28.597950 | Merging changes
2026-09-07 01:50:29.261036 | Checking out repos
2026-09-07 01:50:29.304189 | Preparing playbooks
2026-09-07 01:50:31.659931 | Running Ansible setup
2026-09-07 01:50:35.620109 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-09-07 01:50:36.296407 | 
2026-09-07 01:50:36.296660 | PLAY [localhost]
2026-09-07 01:50:36.307864 | 
2026-09-07 01:50:36.307978 | TASK [Gathering Facts]
2026-09-07 01:50:37.267605 | localhost | ok
2026-09-07 01:50:37.281809 | 
2026-09-07 01:50:37.281973 | TASK [Setup log path fact]
2026-09-07 01:50:37.303044 | localhost | ok
2026-09-07 01:50:37.324849 | 
2026-09-07 01:50:37.324945 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-09-07 01:50:37.356681 | localhost | ok
2026-09-07 01:50:37.370108 | 
2026-09-07 01:50:37.370256 | TASK [emit-job-header : Print job information]
2026-09-07 01:50:37.416869 | # Job Information
2026-09-07 01:50:37.417093 | Ansible Version: 2.16.18
2026-09-07 01:50:37.417137 | Job: ansible-collection-kubernetes-molecule-aio-ubuntu-noble
2026-09-07 01:50:37.417168 | Pipeline: check
2026-09-07 01:50:37.417194 | Executor: 2d72f0692154
2026-09-07 01:50:37.417220 | Triggered by: https://github.com/vexxhost/ansible-collection-kubernetes/pull/300
2026-09-07 01:50:37.417250 | Event ID: 1a3e6320-aa5e-11f1-83e1-f73eae392cf5
2026-09-07 01:50:37.420984 | 
2026-09-07 01:50:37.421076 | LOOP [emit-job-header : Print node information]
2026-09-07 01:50:37.561440 | localhost | ok:
2026-09-07 01:50:37.561651 | localhost | # Node Information
2026-09-07 01:50:37.561697 | localhost | Inventory Hostname: controller
2026-09-07 01:50:37.561727 | localhost | Hostname: np0000191988
2026-09-07 01:50:37.561751 | localhost | Username: zuul
2026-09-07 01:50:37.561797 | localhost | Distro: Ubuntu 24.04
2026-09-07 01:50:37.561824 | localhost | Provider: yul1
2026-09-07 01:50:37.561848 | localhost | Region: ca-ymq-1
2026-09-07 01:50:37.561871 | localhost | Label: ubuntu-noble
2026-09-07 01:50:37.561893 | localhost | Product Name: OpenStack Nova
2026-09-07 01:50:37.561916 | localhost | Interface IP: 162.253.55.167
2026-09-07 01:50:37.577640 | 
2026-09-07 01:50:37.577836 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-09-07 01:50:37.967717 | localhost -> localhost | changed
2026-09-07 01:50:37.980724 | 
2026-09-07 01:50:37.980887 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-09-07 01:50:38.843071 | localhost -> localhost | changed
2026-09-07 01:50:38.851361 | 
2026-09-07 01:50:38.851466 | PLAY [all]
2026-09-07 01:50:38.864931 | 
2026-09-07 01:50:38.865023 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-09-07 01:50:39.104107 | controller -> localhost | ok
2026-09-07 01:50:39.112929 | 
2026-09-07 01:50:39.113001 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-09-07 01:50:39.150429 | controller | ok
2026-09-07 01:50:39.167122 | controller | included: /var/lib/zuul/builds/3e30fa8293fc455394390cdbe0656cb2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-09-07 01:50:39.173217 | 
2026-09-07 01:50:39.173276 | TASK [add-build-sshkey : Create Temp SSH key]
2026-09-07 01:50:40.408028 | controller -> localhost | Generating public/private rsa key pair.
2026-09-07 01:50:40.408310 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/3e30fa8293fc455394390cdbe0656cb2/work/3e30fa8293fc455394390cdbe0656cb2_id_rsa
2026-09-07 01:50:40.408373 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/3e30fa8293fc455394390cdbe0656cb2/work/3e30fa8293fc455394390cdbe0656cb2_id_rsa.pub
2026-09-07 01:50:40.408420 | controller -> localhost | The key fingerprint is:
2026-09-07 01:50:40.408464 | controller -> localhost | SHA256:ztxU6Djw9x+s/g8ll5IJN2P1Wnlj6hei//M9j8Xjqfg zuul-build-sshkey
2026-09-07 01:50:40.408562 | controller -> localhost | The key's randomart image is:
2026-09-07 01:50:40.408593 | controller -> localhost | +---[RSA 3072]----+
2026-09-07 01:50:40.408626 | controller -> localhost | |               . |
2026-09-07 01:50:40.408652 | controller -> localhost | |           .  . o|
2026-09-07 01:50:40.408677 | controller -> localhost | |      .   ...= ++|
2026-09-07 01:50:40.408701 | controller -> localhost | |       o o .+ Bo+|
2026-09-07 01:50:40.408725 | controller -> localhost | |        S +  *ooo|
2026-09-07 01:50:40.408749 | controller -> localhost | |       + = .o.o=.|
2026-09-07 01:50:40.408787 | controller -> localhost | |        + ....+oo|
2026-09-07 01:50:40.408813 | controller -> localhost | |            oooB+|
2026-09-07 01:50:40.408840 | controller -> localhost | |           o+E*=X|
2026-09-07 01:50:40.408864 | controller -> localhost | +----[SHA256]-----+
2026-09-07 01:50:40.408941 | controller -> localhost | ok: Runtime: 0:00:00.797214
2026-09-07 01:50:40.416395 | 
2026-09-07 01:50:40.416452 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-09-07 01:50:40.444945 | controller | ok
2026-09-07 01:50:40.452425 | controller | included: /var/lib/zuul/builds/3e30fa8293fc455394390cdbe0656cb2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-09-07 01:50:40.460901 | 
2026-09-07 01:50:40.460960 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-09-07 01:50:40.483432 | controller | skipping: Conditional result was False
2026-09-07 01:50:40.490447 | 
2026-09-07 01:50:40.490523 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-09-07 01:50:41.054699 | controller | changed
2026-09-07 01:50:41.066803 | 
2026-09-07 01:50:41.066892 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-09-07 01:50:41.317680 | controller | ok
2026-09-07 01:50:41.324210 | 
2026-09-07 01:50:41.324294 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-09-07 01:50:41.973805 | controller | changed
2026-09-07 01:50:41.986365 | 
2026-09-07 01:50:41.986560 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-09-07 01:50:42.612634 | controller | changed
2026-09-07 01:50:42.623267 | 
2026-09-07 01:50:42.623439 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-09-07 01:50:42.649636 | controller | skipping: Conditional result was False
2026-09-07 01:50:42.663080 | 
2026-09-07 01:50:42.663290 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-09-07 01:50:43.115333 | controller -> localhost | changed
2026-09-07 01:50:43.129825 | 
2026-09-07 01:50:43.129988 | TASK [add-build-sshkey : Add back temp key]
2026-09-07 01:50:43.442026 | controller -> localhost | Identity added: /var/lib/zuul/builds/3e30fa8293fc455394390cdbe0656cb2/work/3e30fa8293fc455394390cdbe0656cb2_id_rsa (zuul-build-sshkey)
2026-09-07 01:50:43.442400 | controller -> localhost | ok: Runtime: 0:00:00.022475
2026-09-07 01:50:43.449441 | 
2026-09-07 01:50:43.449521 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-09-07 01:50:43.819479 | controller | ok
2026-09-07 01:50:43.829490 | 
2026-09-07 01:50:43.829671 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-09-07 01:50:43.865600 | controller | skipping: Conditional result was False
2026-09-07 01:50:43.887595 | 
2026-09-07 01:50:43.887821 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-09-07 01:50:44.376239 | controller | ok
2026-09-07 01:50:44.381602 | 
2026-09-07 01:50:44.381674 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-09-07 01:50:45.584734 | controller | Output suppressed because no_log was given
2026-09-07 01:50:45.612225 | 
2026-09-07 01:50:45.612356 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-09-07 01:50:45.876297 | controller | ok: "logs"
2026-09-07 01:50:45.876688 | controller | ok: All items complete
2026-09-07 01:50:45.876793 | 
2026-09-07 01:50:46.095728 | controller | ok: "artifacts"
2026-09-07 01:50:46.315141 | controller | ok: "docs"
2026-09-07 01:50:46.333704 | 
2026-09-07 01:50:46.334013 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-09-07 01:50:46.593075 | controller | changed: "logs"
2026-09-07 01:50:46.790593 | controller | changed: "artifacts"
2026-09-07 01:50:47.013711 | controller | changed: "docs"
2026-09-07 01:50:47.044973 | 
2026-09-07 01:50:47.045161 | PLAY RECAP
2026-09-07 01:50:47.045210 | controller | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2026-09-07 01:50:47.045236 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-09-07 01:50:47.045257 | 
2026-09-07 01:50:47.198245 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-09-07 01:50:47.199559 | PRE-RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-09-07 01:50:47.820157 | 
2026-09-07 01:50:47.820269 | PLAY [all]
2026-09-07 01:50:47.829882 | 
2026-09-07 01:50:47.829954 | TASK [setup-uv : Extract archive]
2026-09-07 01:50:50.355301 | controller | changed
2026-09-07 01:50:50.363479 | 
2026-09-07 01:50:50.363595 | TASK [setup-uv : Print version]
2026-09-07 01:50:50.778519 | controller | uv 0.8.13
2026-09-07 01:50:50.908091 | controller | ok: Runtime: 0:00:00.019207
2026-09-07 01:50:50.927173 | 
2026-09-07 01:50:50.927266 | TASK [Install Ansible collection siblings]
2026-09-07 01:50:51.362298 | controller | ok:
2026-09-07 01:50:51.532065 | controller | Skipping ansible.posix: no checked-out sibling
2026-09-07 01:50:51.532285 | controller | Skipping community.crypto: no checked-out sibling
2026-09-07 01:50:51.532340 | controller | Skipping community.general: no checked-out sibling
2026-09-07 01:50:51.532421 | controller | Skipping kubernetes.core: no checked-out sibling
2026-09-07 01:50:51.532562 | controller | Skipping vexxhost.containers: no checked-out sibling
2026-09-07 01:50:51.536327 | 
2026-09-07 01:50:51.536440 | PLAY RECAP
2026-09-07 01:50:51.536701 | controller | ok: 3 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-09-07 01:50:51.536819 | 
2026-09-07 01:50:51.711280 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-09-07 01:50:51.714767 | PRE-RUN START: [untrusted : github.com/vexxhost/ansible-collection-kubernetes/test-playbooks/molecule/pre.yml@main]
2026-09-07 01:50:52.260148 | 
2026-09-07 01:50:52.260274 | PLAY [all]
2026-09-07 01:50:52.271377 | 
2026-09-07 01:50:52.271446 | TASK [Update apt cache]
2026-09-07 01:50:57.688954 | controller | changed
2026-09-07 01:50:57.700136 | 
2026-09-07 01:50:57.700322 | TASK [Disable firewalld]
2026-09-07 01:50:57.725691 | controller | skipping: Conditional result was False
2026-09-07 01:50:57.737881 | 
2026-09-07 01:50:57.738013 | TASK [Install "jq" for log collection]
2026-09-07 01:51:01.095814 | controller | changed
2026-09-07 01:51:01.098926 | 
2026-09-07 01:51:01.099016 | PLAY RECAP
2026-09-07 01:51:01.099096 | controller | ok: 2 changed: 2 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-09-07 01:51:01.099137 | 
2026-09-07 01:51:01.220660 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/ansible-collection-kubernetes/test-playbooks/molecule/pre.yml@main]
2026-09-07 01:51:01.223174 | RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-09-07 01:51:01.816992 | 
2026-09-07 01:51:01.817119 | PLAY [all]
2026-09-07 01:51:01.827341 | 
2026-09-07 01:51:01.827409 | LOOP [Check inventory directories]
2026-09-07 01:51:02.240930 | controller | ok: "src/github.com/vexxhost/ansible-collection-kubernetes"
2026-09-07 01:51:02.409943 | controller | ok: "src/github.com/vexxhost/ansible-collection-kubernetes/molecule/aio/inventory"
2026-09-07 01:51:02.588705 | controller | ok: "src/github.com/vexxhost/ansible-collection-kubernetes/extensions/molecule/aio/inventory"
2026-09-07 01:51:02.608705 | 
2026-09-07 01:51:02.609033 | LOOP [Copy inventory file for Zuul]
2026-09-07 01:51:03.598174 | controller | changed:
2026-09-07 01:51:03.598389 | controller | {
2026-09-07 01:51:03.598415 | controller |   "ansible_loop_var": "item",
2026-09-07 01:51:03.598435 | controller |   "changed": false,
2026-09-07 01:51:03.598452 | controller |   "failed": false,
2026-09-07 01:51:03.600606 | controller |   "invocation": {
2026-09-07 01:51:03.600707 | controller |     "module_args": {
2026-09-07 01:51:03.600783 | controller |       "checksum_algorithm": "sha1",
2026-09-07 01:51:03.600823 | controller |       "follow": true,
2026-09-07 01:51:03.600858 | controller |       "get_attributes": true,
2026-09-07 01:51:03.600895 | controller |       "get_checksum": true,
2026-09-07 01:51:03.600929 | controller |       "get_mime": true,
2026-09-07 01:51:03.600978 | controller |       "path": "src/github.com/vexxhost/ansible-collection-kubernetes"
2026-09-07 01:51:03.601012 | controller |     }
2026-09-07 01:51:03.601044 | controller |   },
2026-09-07 01:51:03.601075 | controller |   "item": "src/github.com/vexxhost/ansible-collection-kubernetes",
2026-09-07 01:51:03.601106 | controller |   "stat": {
2026-09-07 01:51:03.601138 | controller |     "atime": 1788745845.4234836,
2026-09-07 01:51:03.601170 | controller |     "attr_flags": "e",
2026-09-07 01:51:03.601202 | controller |     "attributes": [
2026-09-07 01:51:03.601234 | controller |       "extents"
2026-09-07 01:51:03.601265 | controller |     ],
2026-09-07 01:51:03.601297 | controller |     "block_size": 4096,
2026-09-07 01:51:03.601329 | controller |     "blocks": 8,
2026-09-07 01:51:03.601360 | controller |     "charset": "unknown",
2026-09-07 01:51:03.601395 | controller |     "ctime": 1788745845.4634857,
2026-09-07 01:51:03.601427 | controller |     "dev": 64769,
2026-09-07 01:51:03.601459 | controller |     "device_type": 0,
2026-09-07 01:51:03.601490 | controller |     "executable": true,
2026-09-07 01:51:03.601522 | controller |     "exists": true,
2026-09-07 01:51:03.601552 | controller |     "gid": 1000,
2026-09-07 01:51:03.601582 | controller |     "gr_name": "zuul",
2026-09-07 01:51:03.601614 | controller |     "inode": 1034272,
2026-09-07 01:51:03.601644 | controller |     "isblk": false,
2026-09-07 01:51:03.601676 | controller |     "ischr": false,
2026-09-07 01:51:03.601707 | controller |     "isdir": true,
2026-09-07 01:51:03.601756 | controller |     "isfifo": false,
2026-09-07 01:51:03.601790 | controller |     "isgid": false,
2026-09-07 01:51:03.601820 | controller |     "islnk": false,
2026-09-07 01:51:03.601850 | controller |     "isreg": false,
2026-09-07 01:51:03.601994 | controller |     "issock": false,
2026-09-07 01:51:03.602050 | controller |     "isuid": false,
2026-09-07 01:51:03.602085 | controller |     "mimetype": "unknown",
2026-09-07 01:51:03.602119 | controller |     "mode": "0755",
2026-09-07 01:51:03.602151 | controller |     "mtime": 1788745828.7147717,
2026-09-07 01:51:03.602182 | controller |     "nlink": 14,
2026-09-07 01:51:03.602213 | controller |     "path": "src/github.com/vexxhost/ansible-collection-kubernetes",
2026-09-07 01:51:03.602244 | controller |     "pw_name": "zuul",
2026-09-07 01:51:03.602281 | controller |     "readable": true,
2026-09-07 01:51:03.602314 | controller |     "rgrp": true,
2026-09-07 01:51:03.602346 | controller |     "roth": true,
2026-09-07 01:51:03.602377 | controller |     "rusr": true,
2026-09-07 01:51:03.602408 | controller |     "size": 4096,
2026-09-07 01:51:03.602439 | controller |     "uid": 1000,
2026-09-07 01:51:03.602470 | controller |     "version": "1415119960",
2026-09-07 01:51:03.602502 | controller |     "wgrp": false,
2026-09-07 01:51:03.602537 | controller |     "woth": false,
2026-09-07 01:51:03.602569 | controller |     "writeable": true,
2026-09-07 01:51:03.602601 | controller |     "wusr": true,
2026-09-07 01:51:03.602633 | controller |     "xgrp": true,
2026-09-07 01:51:03.602664 | controller |     "xoth": true,
2026-09-07 01:51:03.602694 | controller |     "xusr": true
2026-09-07 01:51:03.602762 | controller |   }
2026-09-07 01:51:03.602799 | controller | }
2026-09-07 01:51:03.602863 | controller | ok: All items complete
2026-09-07 01:51:03.602902 | 
2026-09-07 01:51:03.605683 | controller | skipping: Conditional result was False
2026-09-07 01:51:03.612710 | controller | skipping: Conditional result was False
2026-09-07 01:51:03.645897 | 
2026-09-07 01:51:03.646223 | LOOP [Switch "ansible_host" to private IP]
2026-09-07 01:51:04.045761 | controller | changed: 1 replacements made
2026-09-07 01:51:04.048860 | controller | skipping: Conditional result was False
2026-09-07 01:51:04.050038 | controller | skipping: Conditional result was False
2026-09-07 01:51:04.067714 | 
2026-09-07 01:51:04.067949 | TASK [Run Molecule scenario]
2026-09-07 01:51:04.610246 | controller | Using CPython 3.12.3 interpreter at: /usr/bin/python3
2026-09-07 01:51:04.610462 | controller | Creating virtual environment at: .venv
2026-09-07 01:51:04.988653 | controller | Downloading ansible-core (2.3MiB)
2026-09-07 01:51:04.989467 | controller | Downloading cryptography (4.3MiB)
2026-09-07 01:51:04.991295 | controller | Downloading pygments (1.2MiB)
2026-09-07 01:51:05.185641 | controller |  Downloading cryptography
2026-09-07 01:51:05.256367 | controller |  Downloading pygments
2026-09-07 01:51:05.408564 | controller |  Downloading ansible-core
2026-09-07 01:51:05.478751 | controller | Installed 37 packages in 69ms
2026-09-07 01:51:06.312058 | controller | INFO     Collection 'vexxhost.kubernetes' detected.
2026-09-07 01:51:06.312142 | controller | INFO     Scenarios will be used from 'extensions/molecule'
2026-09-07 01:51:07.184673 | controller | CRITICAL 'extensions/molecule/default/molecule.yml' glob failed.  Exiting.
2026-09-07 01:51:07.184759 | controller | INFO     default scenario not found, disabling shared state.
2026-09-07 01:51:07.184840 | controller | INFO     [aio > discovery] scenario test matrix: dependency, cleanup, destroy, syntax, create, prepare, converge, idempotence, side_effect, verify, cleanup, destroy
2026-09-07 01:51:07.184940 | controller | INFO     [aio > prerun] Performing prerun with role_name_check=0...
2026-09-07 01:52:11.453527 | controller | WARNING  Retrying execution failure 1 of: ansible-galaxy collection install -vvv ansible.posix:>=1.6.0
2026-09-07 01:52:11.453649 | controller | ERROR    Command ansible-galaxy collection install -vvv ansible.posix:>=1.6.0, returned 1 code:
2026-09-07 01:52:11.453684 | controller | Starting galaxy collection install process
2026-09-07 01:52:11.453696 | controller | Process install dependency map
2026-09-07 01:52:11.453709 | controller | Starting collection install process
2026-09-07 01:52:11.453721 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/ansible-posix-2.2.2.tar.gz to /home/zuul/.ansible/tmp/ansible-local-1375wbixjk1o/tmpce6vilkl/ansible-posix-2.2.2-8sufk_ry
2026-09-07 01:52:11.453741 | controller |
2026-09-07 01:52:11.453752 | controller | ansible-galaxy
2026-09-07 01:52:11.453764 | controller |   config file = None
2026-09-07 01:52:11.453775 | controller |   configured module search path =
2026-09-07 01:52:11.453807 | controller |   ansible python module location = /home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/lib/python3.12/site-packages/ansible
2026-09-07 01:52:11.453829 | controller |   ansible collection location = /home/zuul/.ansible/collections:/usr/share/ansible/collections:/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/lib/python3.12/dist-packages:/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/lib/python3/dist-packages:/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/local/lib/python3.12/dist-packages:/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/lib/python3.12/site-packages
2026-09-07 01:52:11.453843 | controller |   executable location = /home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/bin/ansible-galaxy
2026-09-07 01:52:11.453855 | controller |   python version = 3.12.3 (main, Jul 15 2026, 23:46:41)  (/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/bin/python)
2026-09-07 01:52:11.453866 | controller |   jinja version = 3.1.6
2026-09-07 01:52:11.453877 | controller |   pyyaml version = 6.0.3 (with libyaml v0.2.5)
2026-09-07 01:52:11.453888 | controller | No config file found; using defaults
2026-09-07 01:52:11.453899 | controller | Created /home/zuul/.ansible/galaxy_token
2026-09-07 01:52:11.453910 | controller | : Failed to download collection tar from 'default' due to the following unforeseen error: The read operation timed out
2026-09-07 01:52:11.453922 | controller |
2026-09-07 01:52:11.453933 | controller | Traceback (most recent call last):
2026-09-07 01:52:11.453950 | controller |   File "/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/bin/molecule", line 10, in <module>
2026-09-07 01:52:11.454266 | controller |     sys.exit(main())
2026-09-07 01:52:11.454565 | controller |              ^^^^^^
2026-09-07 01:52:11.454816 | controller |   File "/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/lib/python3.12/site-packages/click/core.py", line 1485, in __call__
2026-09-07 01:52:11.455560 | controller |     return self.main(*args, **kwargs)
2026-09-07 01:52:11.455882 | controller |            ^^^^^^^^^^^^^^^^^^^^^^^^^^
2026-09-07 01:52:11.456107 | controller |   File "/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/lib/python3.12/site-packages/click/core.py", line 1406, in main
2026-09-07 01:52:11.456840 | controller |     rv = self.invoke(ctx)
2026-09-07 01:52:11.457163 | controller |          ^^^^^^^^^^^^^^^^
2026-09-07 01:52:11.457385 | controller |   File "/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/lib/python3.12/site-packages/click/core.py", line 1873, in invoke
2026-09-07 01:52:11.458328 | controller |     return _process_result(sub_ctx.command.invoke(sub_ctx))
2026-09-07 01:52:11.458587 | controller |                            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2026-09-07 01:52:11.458831 | controller |   File "/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/lib/python3.12/site-packages/click/core.py", line 1269, in invoke
2026-09-07 01:52:11.459501 | controller |     return ctx.invoke(self.callback, **ctx.params)
2026-09-07 01:52:11.459833 | controller |            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2026-09-07 01:52:11.460060 | controller |   File "/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/lib/python3.12/site-packages/click/core.py", line 824, in invoke
2026-09-07 01:52:11.460603 | controller |     return callback(*args, **kwargs)
2026-09-07 01:52:11.461018 | controller |            ^^^^^^^^^^^^^^^^^^^^^^^^^
2026-09-07 01:52:11.461187 | controller |   File "/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/lib/python3.12/site-packages/molecule/click_cfg.py", line 583, in wrapper
2026-09-07 01:52:11.461699 | controller |     return func(*args, **kwargs)
2026-09-07 01:52:11.462107 | controller |            ^^^^^^^^^^^^^^^^^^^^^
2026-09-07 01:52:11.462272 | controller |   File "/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/lib/python3.12/site-packages/click/decorators.py", line 34, in new_func
2026-09-07 01:52:11.462626 | controller |     return f(get_current_context(), *args, **kwargs)
2026-09-07 01:52:11.463057 | controller |            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2026-09-07 01:52:11.463243 | controller |   File "/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/lib/python3.12/site-packages/molecule/click_cfg.py", line 418, in wrapper
2026-09-07 01:52:11.463675 | controller |     return func(ctx)
2026-09-07 01:52:11.463949 | controller |            ^^^^^^^^^
2026-09-07 01:52:11.464176 | controller |   File "/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/lib/python3.12/site-packages/molecule/command/test.py", line 81, in test
2026-09-07 01:52:11.464569 | controller |     base.execute_cmdline_scenarios(scenario_name, args, command_args, ansible_args, exclude)
2026-09-07 01:52:11.464893 | controller |   File "/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/lib/python3.12/site-packages/molecule/command/base.py", line 169, in execute_cmdline_scenarios
2026-09-07 01:52:11.465264 | controller |     _run_scenarios(scenarios, command_args, default_config)
2026-09-07 01:52:11.465558 | controller |   File "/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/lib/python3.12/site-packages/molecule/command/base.py", line 240, in _run_scenarios
2026-09-07 01:52:11.465993 | controller |     scenario.config.runtime.prepare_environment(
2026-09-07 01:52:11.466206 | controller |   File "/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/lib/python3.12/site-packages/ansible_compat/runtime.py", line 752, in prepare_environment
2026-09-07 01:52:11.466777 | controller |     self.install_collection(
2026-09-07 01:52:11.467038 | controller |   File "/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/lib/python3.12/site-packages/ansible_compat/runtime.py", line 609, in install_collection
2026-09-07 01:52:11.467511 | controller |     raise InvalidPrerequisiteError(msg)
2026-09-07 01:52:11.468931 | controller | ansible_compat.errors.InvalidPrerequisiteError: Command ansible-galaxy collection install -vvv ansible.posix:>=1.6.0, returned 1 code:
2026-09-07 01:52:11.468949 | controller | Starting galaxy collection install process
2026-09-07 01:52:11.468957 | controller | Process install dependency map
2026-09-07 01:52:11.468966 | controller | Starting collection install process
2026-09-07 01:52:11.468974 | controller | Downloading https://galaxy.ansible.com/api/v3/plugin/ansible/content/published/collections/artifacts/ansible-posix-2.2.2.tar.gz to /home/zuul/.ansible/tmp/ansible-local-1375wbixjk1o/tmpce6vilkl/ansible-posix-2.2.2-8sufk_ry
2026-09-07 01:52:11.468997 | controller |
2026-09-07 01:52:11.469006 | controller | ansible-galaxy [core 2.20.1]
2026-09-07 01:52:11.469015 | controller |   config file = None
2026-09-07 01:52:11.469023 | controller |   configured module search path = ['/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/plugins/modules', '/home/zuul/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
2026-09-07 01:52:11.469032 | controller |   ansible python module location = /home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/lib/python3.12/site-packages/ansible
2026-09-07 01:52:11.469049 | controller |   ansible collection location = /home/zuul/.ansible/collections:/usr/share/ansible/collections:/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/lib/python3.12/dist-packages:/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/lib/python3/dist-packages:/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/local/lib/python3.12/dist-packages:/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/lib/python3.12/site-packages
2026-09-07 01:52:11.469059 | controller |   executable location = /home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/bin/ansible-galaxy
2026-09-07 01:52:11.469067 | controller |   python version = 3.12.3 (main, Jul 15 2026, 23:46:41) [GCC 13.3.0] (/home/zuul/src/github.com/vexxhost/ansible-collection-kubernetes/.venv/bin/python)
2026-09-07 01:52:11.469075 | controller |   jinja version = 3.1.6
2026-09-07 01:52:11.469084 | controller |   pyyaml version = 6.0.3 (with libyaml v0.2.5)
2026-09-07 01:52:11.469092 | controller | No config file found; using defaults
2026-09-07 01:52:11.469100 | controller | Created /home/zuul/.ansible/galaxy_token
2026-09-07 01:52:11.469108 | controller | [ERROR]: Failed to download collection tar from 'default' due to the following unforeseen error: The read operation timed out
2026-09-07 01:52:11.469122 | controller |
2026-09-07 01:52:11.680770 | controller | ERROR
2026-09-07 01:52:11.681013 | controller | {
2026-09-07 01:52:11.681069 | controller |   "delta": "0:01:07.084382",
2026-09-07 01:52:11.681122 | controller |   "end": "2026-09-07 01:52:11.578750",
2026-09-07 01:52:11.681158 | controller |   "msg": "non-zero return code",
2026-09-07 01:52:11.681192 | controller |   "rc": 1,
2026-09-07 01:52:11.681225 | controller |   "start": "2026-09-07 01:51:04.494368"
2026-09-07 01:52:11.681258 | controller | }
failure
2026-09-07 01:52:11.686169 | 
2026-09-07 01:52:11.686256 | PLAY RECAP
2026-09-07 01:52:11.686333 | controller | ok: 3 changed: 2 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0
2026-09-07 01:52:11.686645 | 
2026-09-07 01:52:11.833444 | RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-09-07 01:52:11.834802 | POST-RUN START: [untrusted : github.com/vexxhost/ansible-collection-kubernetes/test-playbooks/molecule/post.yml@main]
2026-09-07 01:52:12.459040 | 
2026-09-07 01:52:12.459163 | PLAY [all]
2026-09-07 01:52:12.475675 | 
2026-09-07 01:52:12.475967 | TASK [describe-kubernetes-objects : creating directory for cluster scoped objects]
2026-09-07 01:52:12.851063 | controller | changed
2026-09-07 01:52:12.858028 | 
2026-09-07 01:52:12.858125 | TASK [describe-kubernetes-objects : Gathering descriptions for cluster scoped objects]
2026-09-07 01:52:13.249651 | controller | xargs: xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args valuewarning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-09-07 01:52:13.249857 | controller |
2026-09-07 01:52:13.257633 | controller | environment: line 1: kubectl: command not found
2026-09-07 01:52:13.260025 | controller | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-09-07 01:52:13.260870 | controller | environment: line 1: kubectl: command not found
2026-09-07 01:52:13.263274 | controller | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-09-07 01:52:13.264513 | controller | environment: line 1: kubectl: command not found
2026-09-07 01:52:13.266577 | controller | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-09-07 01:52:13.269033 | controller | environment: line 1: kubectl: command not found
2026-09-07 01:52:13.271011 | controller | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-09-07 01:52:13.272200 | controller | environment: line 1: kubectl: command not found
2026-09-07 01:52:13.273501 | controller | xargs: warning: options --max-lines and --replace/-I/-i are mutually exclusive, ignoring previous --max-lines value
2026-09-07 01:52:13.394686 | controller | ok: Runtime: 0:00:00.040187
2026-09-07 01:52:13.406060 | 
2026-09-07 01:52:13.406292 | TASK [describe-kubernetes-objects : creating directory for namespace scoped objects]
2026-09-07 01:52:13.669038 | controller | changed
2026-09-07 01:52:13.680676 | 
2026-09-07 01:52:13.680954 | TASK [describe-kubernetes-objects : Gathering descriptions for namespace scoped objects]
2026-09-07 01:52:13.995678 | controller | environment: line 5: kubectl: command not found
2026-09-07 01:52:13.996635 | controller | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-09-07 01:52:13.996684 | controller | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-09-07 01:52:13.997011 | controller | xargs: warning: options --max-args and --replace/-I/-i are mutually exclusive, ignoring previous --max-args value
2026-09-07 01:52:14.230366 | controller | ok: Runtime: 0:00:00.010697
2026-09-07 01:52:14.242093 | 
2026-09-07 01:52:14.242217 | TASK [describe-kubernetes-objects : Downloads logs to executor]
2026-09-07 01:52:14.930950 | controller | changed:
2026-09-07 01:52:14.931146 | controller | created directory /var/lib/zuul/builds/3e30fa8293fc455394390cdbe0656cb2/work/logs/controller
2026-09-07 01:52:14.931196 | controller | cd+++++++++ objects/
2026-09-07 01:52:14.931226 | controller | cd+++++++++ objects/cluster/
2026-09-07 01:52:14.931265 | controller | cd+++++++++ objects/namespaced/
2026-09-07 01:52:14.942867 | 
2026-09-07 01:52:14.942934 | TASK [gather-pod-logs : creating directory for pod logs]
2026-09-07 01:52:15.211720 | controller | changed
2026-09-07 01:52:15.221765 | 
2026-09-07 01:52:15.221890 | TASK [gather-pod-logs : creating directory for failed pod logs]
2026-09-07 01:52:15.500441 | controller | changed
2026-09-07 01:52:15.511192 | 
2026-09-07 01:52:15.511350 | TASK [gather-pod-logs : retrieve all kubernetes logs, current and previous (if they exist)]
2026-09-07 01:52:15.788349 | controller | environment: line 3: kubectl: command not found
2026-09-07 01:52:16.058365 | controller | ok: Runtime: 0:00:00.014331
2026-09-07 01:52:16.106145 | 
2026-09-07 01:52:16.106291 | TASK [gather-pod-logs : Downloads pod logs to executor]
2026-09-07 01:52:16.637223 | controller | changed:
2026-09-07 01:52:16.637476 | controller | cd+++++++++ pod-logs/
2026-09-07 01:52:16.637532 | controller | cd+++++++++ pod-logs/failed-pods/
2026-09-07 01:52:16.657596 | 
2026-09-07 01:52:16.657772 | LOOP [helm-release-status : creating directory for helm release status]
2026-09-07 01:52:16.933985 | controller | changed: "values"
2026-09-07 01:52:17.177583 | controller | changed: "releases"
2026-09-07 01:52:17.196546 | 
2026-09-07 01:52:17.196779 | TASK [helm-release-status : Gather get release status for helm charts]
2026-09-07 01:52:17.504196 | controller | /bin/bash: line 3: kubectl: command not found
2026-09-07 01:52:17.743721 | controller | ok: Runtime: 0:00:00.010399
2026-09-07 01:52:17.756888 | 
2026-09-07 01:52:17.757056 | TASK [helm-release-status : Downloads logs to executor]
2026-09-07 01:52:18.311381 | controller | changed:
2026-09-07 01:52:18.311852 | controller | cd+++++++++ helm/
2026-09-07 01:52:18.311892 | controller | cd+++++++++ helm/releases/
2026-09-07 01:52:18.311923 | controller | cd+++++++++ helm/values/
2026-09-07 01:52:18.319771 | 
2026-09-07 01:52:18.319838 | PLAY RECAP
2026-09-07 01:52:18.319898 | controller | ok: 12 changed: 12 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-09-07 01:52:18.319926 | 
2026-09-07 01:52:18.468535 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/ansible-collection-kubernetes/test-playbooks/molecule/post.yml@main]
2026-09-07 01:52:18.497759 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-09-07 01:52:19.156416 | 
2026-09-07 01:52:19.156707 | PLAY [all]
2026-09-07 01:52:19.167835 | 
2026-09-07 01:52:19.167963 | TASK [fetch-output : Set log path for multiple nodes]
2026-09-07 01:52:19.222629 | controller | skipping: Conditional result was False
2026-09-07 01:52:19.230302 | 
2026-09-07 01:52:19.230403 | TASK [fetch-output : Set log path for single node]
2026-09-07 01:52:19.278181 | controller | ok
2026-09-07 01:52:19.286170 | 
2026-09-07 01:52:19.286253 | LOOP [fetch-output : Ensure local output dirs]
2026-09-07 01:52:19.863735 | controller -> localhost | ok: "/var/lib/zuul/builds/3e30fa8293fc455394390cdbe0656cb2/work/logs"
2026-09-07 01:52:20.157042 | controller -> localhost | changed: "/var/lib/zuul/builds/3e30fa8293fc455394390cdbe0656cb2/work/artifacts"
2026-09-07 01:52:20.396708 | controller -> localhost | changed: "/var/lib/zuul/builds/3e30fa8293fc455394390cdbe0656cb2/work/docs"
2026-09-07 01:52:20.406709 | 
2026-09-07 01:52:20.406827 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-09-07 01:52:21.221231 | controller | changed: .d..t...... ./
2026-09-07 01:52:21.221521 | controller | changed: All items complete
2026-09-07 01:52:21.221565 | 
2026-09-07 01:52:21.754466 | controller | changed: .d..t...... ./
2026-09-07 01:52:22.332508 | controller | changed: .d..t...... ./
2026-09-07 01:52:22.359966 | 
2026-09-07 01:52:22.360224 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-09-07 01:52:23.107067 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.009694
2026-09-07 01:52:23.441470 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.011676
2026-09-07 01:52:23.460215 | 
2026-09-07 01:52:23.460340 | PLAY [all]
2026-09-07 01:52:23.467911 | 
2026-09-07 01:52:23.469065 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-09-07 01:52:24.003349 | controller | changed
2026-09-07 01:52:24.016273 | 
2026-09-07 01:52:24.016368 | PLAY RECAP
2026-09-07 01:52:24.016454 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-09-07 01:52:24.016535 | 
2026-09-07 01:52:24.142446 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-09-07 01:52:24.146110 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main]
2026-09-07 01:52:24.719318 | 
2026-09-07 01:52:24.719445 | PLAY [localhost]
2026-09-07 01:52:24.728816 | 
2026-09-07 01:52:24.728890 | TASK [Generate Zuul manifest]
2026-09-07 01:52:24.746154 | localhost | ok
2026-09-07 01:52:24.759859 | 
2026-09-07 01:52:24.759942 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-09-07 01:52:25.123377 | localhost | changed
2026-09-07 01:52:25.136992 | 
2026-09-07 01:52:25.137093 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-09-07 01:52:25.167458 | localhost | ok
2026-09-07 01:52:25.180624 | 
2026-09-07 01:52:25.180739 | TASK [Upload logs]
2026-09-07 01:52:25.200340 | localhost | ok
2026-09-07 01:52:25.266476 | 
2026-09-07 01:52:25.266640 | TASK [Set zuul-log-path fact]
2026-09-07 01:52:25.283644 | localhost | ok
2026-09-07 01:52:25.293662 | 
2026-09-07 01:52:25.293768 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-09-07 01:52:25.345194 | localhost | ok
2026-09-07 01:52:25.357184 | 
2026-09-07 01:52:25.357307 | TASK [upload-logs : Create log directories]
2026-09-07 01:52:25.785367 | localhost | changed
2026-09-07 01:52:25.791457 | 
2026-09-07 01:52:25.791547 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-09-07 01:52:26.271197 | localhost -> localhost | ok: Runtime: 0:00:00.005880
2026-09-07 01:52:26.275994 | 
2026-09-07 01:52:26.276059 | TASK [upload-logs : Upload logs to log server]
2026-09-07 01:52:26.771522 | localhost | Output suppressed because no_log was given
2026-09-07 01:52:26.778756 | 
2026-09-07 01:52:26.778892 | LOOP [upload-logs : Compress console log and json output]
2026-09-07 01:52:26.827162 | localhost | skipping: Conditional result was False
2026-09-07 01:52:26.874352 | localhost | skipping: Conditional result was False
2026-09-07 01:52:26.884328 | 
2026-09-07 01:52:26.884586 | LOOP [upload-logs : Upload compressed console log and json output]
2026-09-07 01:52:26.949059 | localhost | skipping: Conditional result was False
2026-09-07 01:52:26.949420 | 
2026-09-07 01:52:26.958968 | localhost | skipping: Conditional result was False
2026-09-07 01:52:26.969695 | 
2026-09-07 01:52:26.969920 | LOOP [upload-logs : Upload console log and json output]