2026-04-18 16:34:15.265167 | Job console starting
2026-04-18 16:34:15.292524 | Updating git repos
2026-04-18 16:34:15.362663 | Cloning repos into workspace
2026-04-18 16:34:15.820546 | Restoring repo states
2026-04-18 16:34:15.827129 | Merging changes
2026-04-18 16:34:16.610179 | Checking out repos
2026-04-18 16:34:16.863523 | Preparing playbooks
2026-04-18 16:34:19.058373 | Running Ansible setup
2026-04-18 16:34:23.167628 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-04-18 16:34:23.816508 | 
2026-04-18 16:34:23.816655 | PLAY [localhost]
2026-04-18 16:34:23.824841 | 
2026-04-18 16:34:23.825016 | TASK [Gathering Facts]
2026-04-18 16:34:24.691202 | localhost | ok
2026-04-18 16:34:24.702808 | 
2026-04-18 16:34:24.702974 | TASK [Setup log path fact]
2026-04-18 16:34:24.721975 | localhost | ok
2026-04-18 16:34:24.741849 | 
2026-04-18 16:34:24.741997 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-04-18 16:34:24.773367 | localhost | ok
2026-04-18 16:34:24.782329 | 
2026-04-18 16:34:24.782527 | TASK [emit-job-header : Print job information]
2026-04-18 16:34:24.835686 | # Job Information
2026-04-18 16:34:24.835990 | Ansible Version: 2.16.16
2026-04-18 16:34:24.836043 | Job: ansible-collection-containers-molecule-containerd-rockylinux-9
2026-04-18 16:34:24.836713 | Pipeline: check
2026-04-18 16:34:24.836751 | Executor: 0a8996d2b663
2026-04-18 16:34:24.836774 | Triggered by: https://github.com/vexxhost/ansible-collection-containers/pull/108
2026-04-18 16:34:24.836797 | Event ID: 36cd11a0-3b44-11f1-896b-295e87a423e5
2026-04-18 16:34:24.842352 | 
2026-04-18 16:34:24.842517 | LOOP [emit-job-header : Print node information]
2026-04-18 16:34:24.939982 | localhost | ok:
2026-04-18 16:34:25.038185 | localhost | # Node Information
2026-04-18 16:34:25.038295 | localhost | Inventory Hostname: rockylinux-9
2026-04-18 16:34:25.038322 | localhost | Hostname: np0000167337
2026-04-18 16:34:25.038343 | localhost | Username: zuul
2026-04-18 16:34:25.038371 | localhost | Distro: Rocky 9.7
2026-04-18 16:34:25.038392 | localhost | Provider: yul1
2026-04-18 16:34:25.038411 | localhost | Region: ca-ymq-1
2026-04-18 16:34:25.038430 | localhost | Label: rockylinux-9
2026-04-18 16:34:25.038449 | localhost | Product Name: OpenStack Nova
2026-04-18 16:34:25.038467 | localhost | Interface IP: 199.19.213.104
2026-04-18 16:34:25.053832 | 
2026-04-18 16:34:25.053953 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-04-18 16:34:25.561692 | localhost -> localhost | changed
2026-04-18 16:34:25.566444 | 
2026-04-18 16:34:25.566509 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-04-18 16:34:26.746482 | localhost -> localhost | changed
2026-04-18 16:34:26.756590 | 
2026-04-18 16:34:26.756718 | PLAY [all]
2026-04-18 16:34:26.771037 | 
2026-04-18 16:34:26.771344 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-04-18 16:34:27.012981 | rockylinux-9 -> localhost | ok
2026-04-18 16:34:27.020798 | 
2026-04-18 16:34:27.020893 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-04-18 16:34:27.044642 | rockylinux-9 | ok
2026-04-18 16:34:27.060015 | rockylinux-9 | included: /var/lib/zuul/builds/2c42838baf9f443b9a824babaca7db5f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-04-18 16:34:27.065554 | 
2026-04-18 16:34:27.065615 | TASK [add-build-sshkey : Create Temp SSH key]
2026-04-18 16:34:28.223305 | rockylinux-9 -> localhost | Generating public/private rsa key pair.
2026-04-18 16:34:28.223504 | rockylinux-9 -> localhost | Your identification has been saved in /var/lib/zuul/builds/2c42838baf9f443b9a824babaca7db5f/work/2c42838baf9f443b9a824babaca7db5f_id_rsa
2026-04-18 16:34:28.223546 | rockylinux-9 -> localhost | Your public key has been saved in /var/lib/zuul/builds/2c42838baf9f443b9a824babaca7db5f/work/2c42838baf9f443b9a824babaca7db5f_id_rsa.pub
2026-04-18 16:34:28.223580 | rockylinux-9 -> localhost | The key fingerprint is:
2026-04-18 16:34:28.223611 | rockylinux-9 -> localhost | SHA256:UR2iEqIfNZvmqhH0X0a9WHWOBj/AxtSVI6A4Bgv6MY8 zuul-build-sshkey
2026-04-18 16:34:28.223653 | rockylinux-9 -> localhost | The key's randomart image is:
2026-04-18 16:34:28.223683 | rockylinux-9 -> localhost | +---[RSA 3072]----+
2026-04-18 16:34:28.223720 | rockylinux-9 -> localhost | |  . o +  +B+ooo. |
2026-04-18 16:34:28.223750 | rockylinux-9 -> localhost | | . o = * =+*++o  |
2026-04-18 16:34:28.223779 | rockylinux-9 -> localhost | |. = o O =.o =... |
2026-04-18 16:34:28.223808 | rockylinux-9 -> localhost | | o B = + + o .   |
2026-04-18 16:34:28.223836 | rockylinux-9 -> localhost | |  E + . S .      |
2026-04-18 16:34:28.223864 | rockylinux-9 -> localhost | |   . o o         |
2026-04-18 16:34:28.223892 | rockylinux-9 -> localhost | |  . . .          |
2026-04-18 16:34:28.223920 | rockylinux-9 -> localhost | |   o             |
2026-04-18 16:34:28.223952 | rockylinux-9 -> localhost | |  .              |
2026-04-18 16:34:28.223981 | rockylinux-9 -> localhost | +----[SHA256]-----+
2026-04-18 16:34:28.224048 | rockylinux-9 -> localhost | ok: Runtime: 0:00:00.700458
2026-04-18 16:34:28.233386 | 
2026-04-18 16:34:28.233483 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-04-18 16:34:28.279147 | rockylinux-9 | ok
2026-04-18 16:34:28.287332 | rockylinux-9 | included: /var/lib/zuul/builds/2c42838baf9f443b9a824babaca7db5f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-04-18 16:34:28.295503 | 
2026-04-18 16:34:28.295595 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-04-18 16:34:28.327596 | rockylinux-9 | skipping: Conditional result was False
2026-04-18 16:34:28.336068 | 
2026-04-18 16:34:28.336165 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-04-18 16:34:28.843415 | rockylinux-9 | changed
2026-04-18 16:34:28.848493 | 
2026-04-18 16:34:28.848571 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-04-18 16:34:29.119693 | rockylinux-9 | ok
2026-04-18 16:34:29.127897 | 
2026-04-18 16:34:29.127981 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-04-18 16:34:30.074082 | rockylinux-9 | changed
2026-04-18 16:34:30.079967 | 
2026-04-18 16:34:30.080036 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-04-18 16:34:30.985025 | rockylinux-9 | changed
2026-04-18 16:34:30.989737 | 
2026-04-18 16:34:30.989816 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-04-18 16:34:31.013916 | rockylinux-9 | skipping: Conditional result was False
2026-04-18 16:34:31.026215 | 
2026-04-18 16:34:31.026433 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-04-18 16:34:31.459576 | rockylinux-9 -> localhost | changed
2026-04-18 16:34:31.473849 | 
2026-04-18 16:34:31.473952 | TASK [add-build-sshkey : Add back temp key]
2026-04-18 16:34:31.767434 | rockylinux-9 -> localhost | Identity added: /var/lib/zuul/builds/2c42838baf9f443b9a824babaca7db5f/work/2c42838baf9f443b9a824babaca7db5f_id_rsa (zuul-build-sshkey)
2026-04-18 16:34:31.767686 | rockylinux-9 -> localhost | ok: Runtime: 0:00:00.014867
2026-04-18 16:34:31.775475 | 
2026-04-18 16:34:31.775604 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-04-18 16:34:32.160048 | rockylinux-9 | ok
2026-04-18 16:34:32.165619 | 
2026-04-18 16:34:32.165685 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-04-18 16:34:32.190230 | rockylinux-9 | skipping: Conditional result was False
2026-04-18 16:34:32.204777 | 
2026-04-18 16:34:32.204923 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-04-18 16:34:32.615535 | rockylinux-9 | ok
2026-04-18 16:34:32.623828 | 
2026-04-18 16:34:32.623985 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-04-18 16:34:33.595152 | rockylinux-9 | Output suppressed because no_log was given
2026-04-18 16:34:33.607791 | 
2026-04-18 16:34:33.607892 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-04-18 16:34:33.861293 | rockylinux-9 | ok: "logs"
2026-04-18 16:34:33.861684 | rockylinux-9 | ok: All items complete
2026-04-18 16:34:33.861732 | 
2026-04-18 16:34:34.078655 | rockylinux-9 | ok: "artifacts"
2026-04-18 16:34:34.323510 | rockylinux-9 | ok: "docs"
2026-04-18 16:34:34.336800 | 
2026-04-18 16:34:34.337090 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-04-18 16:34:34.599241 | rockylinux-9 | changed: "logs"
2026-04-18 16:34:34.829197 | rockylinux-9 | changed: "artifacts"
2026-04-18 16:34:35.088940 | rockylinux-9 | changed: "docs"
2026-04-18 16:34:35.109300 | 
2026-04-18 16:34:35.109471 | PLAY RECAP
2026-04-18 16:34:35.109540 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-04-18 16:34:35.109586 | rockylinux-9 | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2026-04-18 16:34:35.109620 | 
2026-04-18 16:34:35.303935 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-04-18 16:34:35.305882 | PRE-RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-04-18 16:34:35.959930 | 
2026-04-18 16:34:35.960440 | PLAY [all]
2026-04-18 16:34:35.973825 | 
2026-04-18 16:34:35.973934 | TASK [setup-uv : Extract archive]
2026-04-18 16:34:38.877121 | rockylinux-9 | changed
2026-04-18 16:34:38.883612 | 
2026-04-18 16:34:38.883691 | TASK [setup-uv : Print version]
2026-04-18 16:34:38.907646 | [rockylinux-9] Waiting on logger
2026-04-18 16:34:39.423242 | rockylinux-9 | ok: Runtime: 0:00:00.014113
2026-04-18 16:34:39.433405 | 
2026-04-18 16:34:39.433496 | PLAY RECAP
2026-04-18 16:34:39.433552 | rockylinux-9 | ok: 2 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-04-18 16:34:39.433577 | 
2026-04-18 16:34:39.614593 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/pre.yaml@main]
2026-04-18 16:34:39.617385 | RUN START: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-04-18 16:34:40.242203 | 
2026-04-18 16:34:40.242334 | PLAY [all]
2026-04-18 16:34:40.253189 | 
2026-04-18 16:34:40.253279 | TASK [Copy inventory file for Zuul]
2026-04-18 16:34:41.699767 | rockylinux-9 | changed
2026-04-18 16:34:41.706665 | 
2026-04-18 16:34:41.706764 | TASK [Switch "ansible_host" to private IP]
2026-04-18 16:34:42.080598 | rockylinux-9 | changed: 1 replacements made
2026-04-18 16:34:42.087760 | 
2026-04-18 16:34:42.087861 | TASK [Run Molecule scenario]
2026-04-18 16:34:42.109483 | [rockylinux-9] Waiting on logger
2026-04-18 16:34:50.245873 | [rockylinux-9] Waiting on logger
2026-04-18 16:35:00.425867 | [rockylinux-9] Waiting on logger
2026-04-18 16:35:10.601838 | [rockylinux-9] Waiting on logger
2026-04-18 16:35:20.777962 | [rockylinux-9] Waiting on logger
2026-04-18 16:35:29.931121 | [rockylinux-9] Waiting on logger
2026-04-18 16:35:40.102119 | [rockylinux-9] Waiting on logger
2026-04-18 16:35:50.282007 | [rockylinux-9] Waiting on logger
2026-04-18 16:36:00.453783 | [rockylinux-9] Waiting on logger
2026-04-18 16:36:10.825777 | [rockylinux-9] Waiting on logger
2026-04-18 16:36:19.983494 | [rockylinux-9] Waiting on logger
2026-04-18 16:36:30.150415 | [rockylinux-9] Waiting on logger
2026-04-18 16:36:40.329989 | [rockylinux-9] Waiting on logger
2026-04-18 16:36:50.501856 | [rockylinux-9] Waiting on logger
2026-04-18 16:36:55.086579 | rockylinux-9 | ERROR
2026-04-18 16:36:55.086875 | rockylinux-9 | {
2026-04-18 16:36:55.086926 | rockylinux-9 |   "delta": "0:02:11.862303",
2026-04-18 16:36:55.086959 | rockylinux-9 |   "end": "2026-04-18 16:36:54.650648",
2026-04-18 16:36:55.086988 | rockylinux-9 |   "msg": "non-zero return code",
2026-04-18 16:36:55.087066 | rockylinux-9 |   "rc": 2,
2026-04-18 16:36:55.087099 | rockylinux-9 |   "start": "2026-04-18 16:34:42.788345"
2026-04-18 16:36:55.087127 | rockylinux-9 | }
failure
2026-04-18 16:36:55.095315 | 
2026-04-18 16:36:55.095367 | PLAY RECAP
2026-04-18 16:36:55.095437 | rockylinux-9 | ok: 2 changed: 2 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0
2026-04-18 16:36:55.095474 | 
2026-04-18 16:36:55.285790 | RUN END RESULT_NORMAL: [untrusted : github.com/vexxhost/zuul-jobs/playbooks/molecule/run.yaml@main]
2026-04-18 16:36:55.288552 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-04-18 16:36:55.935188 | 
2026-04-18 16:36:55.935396 | PLAY [all]
2026-04-18 16:36:55.948760 | 
2026-04-18 16:36:55.948874 | TASK [fetch-output : Set log path for multiple nodes]
2026-04-18 16:36:55.994870 | rockylinux-9 | skipping: Conditional result was False
2026-04-18 16:36:55.999939 | 
2026-04-18 16:36:56.000023 | TASK [fetch-output : Set log path for single node]
2026-04-18 16:36:56.042102 | rockylinux-9 | ok
2026-04-18 16:36:56.050042 | 
2026-04-18 16:36:56.050120 | LOOP [fetch-output : Ensure local output dirs]
2026-04-18 16:36:56.433226 | rockylinux-9 -> localhost | ok: "/var/lib/zuul/builds/2c42838baf9f443b9a824babaca7db5f/work/logs"
2026-04-18 16:36:56.639779 | rockylinux-9 -> localhost | changed: "/var/lib/zuul/builds/2c42838baf9f443b9a824babaca7db5f/work/artifacts"
2026-04-18 16:36:56.847096 | rockylinux-9 -> localhost | changed: "/var/lib/zuul/builds/2c42838baf9f443b9a824babaca7db5f/work/docs"
2026-04-18 16:36:56.871451 | 
2026-04-18 16:36:56.871594 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-04-18 16:36:57.614813 | rockylinux-9 | changed: .d..t...... ./
2026-04-18 16:36:57.615763 | rockylinux-9 | changed: All items complete
2026-04-18 16:36:57.615950 | 
2026-04-18 16:36:59.538715 | rockylinux-9 | changed: .d..t...... ./
2026-04-18 16:37:00.066133 | rockylinux-9 | changed: .d..t...... ./
2026-04-18 16:37:00.083810 | 
2026-04-18 16:37:00.083989 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-04-18 16:37:00.582184 | rockylinux-9 -> localhost | ok: Item: artifacts Runtime: 0:00:00.008701
2026-04-18 16:37:00.806835 | rockylinux-9 -> localhost | ok: Item: docs Runtime: 0:00:00.007425
2026-04-18 16:37:00.816332 | 
2026-04-18 16:37:00.816464 | PLAY [all]
2026-04-18 16:37:00.822143 | 
2026-04-18 16:37:00.822213 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-04-18 16:37:01.278634 | rockylinux-9 | changed
2026-04-18 16:37:01.284032 | 
2026-04-18 16:37:01.284083 | PLAY RECAP
2026-04-18 16:37:01.284132 | rockylinux-9 | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-04-18 16:37:01.284154 | 
2026-04-18 16:37:01.403810 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-04-18 16:37:01.405269 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main]
2026-04-18 16:37:02.422854 | 
2026-04-18 16:37:02.917048 | PLAY [localhost]
2026-04-18 16:37:02.935914 | 
2026-04-18 16:37:02.937039 | TASK [Generate Zuul manifest]
2026-04-18 16:37:02.958649 | localhost | ok
2026-04-18 16:37:02.986469 | 
2026-04-18 16:37:02.986597 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-04-18 16:37:03.348419 | localhost | changed
2026-04-18 16:37:03.359408 | 
2026-04-18 16:37:03.359511 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-04-18 16:37:03.864806 | localhost | ok
2026-04-18 16:37:03.871376 | 
2026-04-18 16:37:03.871443 | TASK [Upload logs]
2026-04-18 16:37:03.890040 | localhost | ok
2026-04-18 16:37:03.958712 | 
2026-04-18 16:37:03.959339 | TASK [Set zuul-log-path fact]
2026-04-18 16:37:03.981129 | localhost | ok
2026-04-18 16:37:03.993464 | 
2026-04-18 16:37:03.993560 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-04-18 16:37:04.024931 | localhost | ok
2026-04-18 16:37:04.035301 | 
2026-04-18 16:37:04.035391 | TASK [upload-logs : Create log directories]
2026-04-18 16:37:04.496798 | localhost | changed
2026-04-18 16:37:04.504892 | 
2026-04-18 16:37:04.505011 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-04-18 16:37:05.335850 | localhost -> localhost | ok: Runtime: 0:00:00.005694
2026-04-18 16:37:05.343175 | 
2026-04-18 16:37:05.343277 | TASK [upload-logs : Upload logs to log server]
2026-04-18 16:37:05.842275 | localhost | Output suppressed because no_log was given
2026-04-18 16:37:05.849679 | 
2026-04-18 16:37:05.849784 | LOOP [upload-logs : Compress console log and json output]
2026-04-18 16:37:05.901671 | localhost | skipping: Conditional result was False
2026-04-18 16:37:05.911603 | localhost | skipping: Conditional result was False
2026-04-18 16:37:05.921647 | 
2026-04-18 16:37:05.921848 | LOOP [upload-logs : Upload compressed console log and json output]
2026-04-18 16:37:05.977694 | localhost | skipping: Conditional result was False
2026-04-18 16:37:05.977986 | 
2026-04-18 16:37:05.981976 | localhost | skipping: Conditional result was False
2026-04-18 16:37:06.001757 | 
2026-04-18 16:37:06.001948 | LOOP [upload-logs : Upload console log and json output]