2026-02-19 02:38:09.511680 | Job console starting
2026-02-19 02:38:09.520015 | Updating git repos
2026-02-19 02:38:12.157977 | Cloning repos into workspace
2026-02-19 02:38:17.105777 | Restoring repo states
2026-02-19 02:38:19.885376 | Merging changes
2026-02-19 02:38:20.363059 | Checking out repos
2026-02-19 02:38:23.352319 | Preparing playbooks
2026-02-19 02:38:25.554998 | Running Ansible setup
2026-02-19 02:38:29.098494 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-02-19 02:38:29.683230 | 
2026-02-19 02:38:29.683357 | PLAY [localhost]
2026-02-19 02:38:29.691140 | 
2026-02-19 02:38:29.691208 | TASK [Gathering Facts]
2026-02-19 02:38:30.566650 | localhost | ok
2026-02-19 02:38:30.577694 | 
2026-02-19 02:38:30.577801 | TASK [Setup log path fact]
2026-02-19 02:38:30.598397 | localhost | ok
2026-02-19 02:38:30.611518 | 
2026-02-19 02:38:30.611583 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-19 02:38:30.640711 | localhost | ok
2026-02-19 02:38:30.649913 | 
2026-02-19 02:38:30.650001 | TASK [emit-job-header : Print job information]
2026-02-19 02:38:30.690770 | # Job Information
2026-02-19 02:38:30.690973 | Ansible Version: 2.16.16
2026-02-19 02:38:30.691042 | Job: manila-tempest-plugin-lvm-fips-py311
2026-02-19 02:38:30.691090 | Pipeline: check
2026-02-19 02:38:30.691133 | Executor: 0a8996d2b663
2026-02-19 02:38:30.691175 | Triggered by: https://github.com/vexxhost/manila/pull/1
2026-02-19 02:38:30.691228 | Event ID: d42d6dc0-0d39-11f1-9818-0dbc046261a0
2026-02-19 02:38:30.695136 | 
2026-02-19 02:38:30.695224 | LOOP [emit-job-header : Print node information]
2026-02-19 02:38:30.777427 | localhost | ok:
2026-02-19 02:38:30.777724 | localhost | # Node Information
2026-02-19 02:38:30.777786 | localhost | Inventory Hostname: controller
2026-02-19 02:38:30.777833 | localhost | Hostname: np0000156500
2026-02-19 02:38:30.777877 | localhost | Username: zuul
2026-02-19 02:38:30.777925 | localhost | Distro: CentOS 9
2026-02-19 02:38:30.777969 | localhost | Provider: yul1
2026-02-19 02:38:30.778012 | localhost | Region: ca-ymq-1
2026-02-19 02:38:30.778052 | localhost | Label: centos-9-stream
2026-02-19 02:38:30.778092 | localhost | Product Name: OpenStack Nova
2026-02-19 02:38:30.778133 | localhost | Interface IP: 162.253.55.227
2026-02-19 02:38:30.795238 | 
2026-02-19 02:38:30.795370 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-02-19 02:38:31.205578 | localhost -> localhost | changed
2026-02-19 02:38:31.215376 | 
2026-02-19 02:38:31.215506 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-02-19 02:38:32.058817 | localhost -> localhost | changed
2026-02-19 02:38:32.070221 | 
2026-02-19 02:38:32.070300 | PLAY [all]
2026-02-19 02:38:32.079406 | 
2026-02-19 02:38:32.079472 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-19 02:38:32.320698 | controller -> localhost | ok
2026-02-19 02:38:32.330485 | 
2026-02-19 02:38:32.330621 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-19 02:38:32.361264 | controller | ok
2026-02-19 02:38:32.376338 | controller | included: /var/lib/zuul/builds/8651091a3118458781c09e8890a2cb21/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-19 02:38:32.381153 | 
2026-02-19 02:38:32.381215 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-19 02:38:33.634055 | controller -> localhost | Generating public/private rsa key pair.
2026-02-19 02:38:33.634473 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/8651091a3118458781c09e8890a2cb21/work/8651091a3118458781c09e8890a2cb21_id_rsa
2026-02-19 02:38:33.634636 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/8651091a3118458781c09e8890a2cb21/work/8651091a3118458781c09e8890a2cb21_id_rsa.pub
2026-02-19 02:38:33.634717 | controller -> localhost | The key fingerprint is:
2026-02-19 02:38:33.634793 | controller -> localhost | SHA256:RnpEEjSkYj71SKARD8eIRXQvDKC7cqv3fy1msDQripA zuul-build-sshkey
2026-02-19 02:38:33.634882 | controller -> localhost | The key's randomart image is:
2026-02-19 02:38:33.635080 | controller -> localhost | +---[RSA 3072]----+
2026-02-19 02:38:33.635160 | controller -> localhost | |*OB .o*..        |
2026-02-19 02:38:33.635238 | controller -> localhost | |+*.= o +         |
2026-02-19 02:38:33.635301 | controller -> localhost | |o + * . o        |
2026-02-19 02:38:33.635332 | controller -> localhost | | + + + +         |
2026-02-19 02:38:33.635358 | controller -> localhost | |. o . o S        |
2026-02-19 02:38:33.635384 | controller -> localhost | | o .  +o         |
2026-02-19 02:38:33.635410 | controller -> localhost | |E .  . = .       |
2026-02-19 02:38:33.635435 | controller -> localhost | |oo... o = .      |
2026-02-19 02:38:33.635463 | controller -> localhost | |oooo.o.+ .       |
2026-02-19 02:38:33.635489 | controller -> localhost | +----[SHA256]-----+
2026-02-19 02:38:33.635549 | controller -> localhost | ok: Runtime: 0:00:00.829085
2026-02-19 02:38:33.639776 | 
2026-02-19 02:38:33.639840 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-19 02:38:33.672276 | controller | ok
2026-02-19 02:38:33.682144 | controller | included: /var/lib/zuul/builds/8651091a3118458781c09e8890a2cb21/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-19 02:38:33.688624 | 
2026-02-19 02:38:33.688682 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-19 02:38:33.713802 | controller | skipping: Conditional result was False
2026-02-19 02:38:33.721605 | 
2026-02-19 02:38:33.721691 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-19 02:38:34.158308 | controller | changed
2026-02-19 02:38:34.201040 | 
2026-02-19 02:38:34.201142 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-19 02:38:34.427036 | controller | ok
2026-02-19 02:38:34.432915 | 
2026-02-19 02:38:34.433026 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-19 02:38:35.159203 | controller | changed
2026-02-19 02:38:35.164698 | 
2026-02-19 02:38:35.164790 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-19 02:38:35.861742 | controller | changed
2026-02-19 02:38:35.867782 | 
2026-02-19 02:38:35.867868 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-19 02:38:35.893841 | controller | skipping: Conditional result was False
2026-02-19 02:38:35.901611 | 
2026-02-19 02:38:35.901700 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-19 02:38:36.272174 | controller -> localhost | changed
2026-02-19 02:38:36.285224 | 
2026-02-19 02:38:36.285315 | TASK [add-build-sshkey : Add back temp key]
2026-02-19 02:38:36.583782 | controller -> localhost | Identity added: /var/lib/zuul/builds/8651091a3118458781c09e8890a2cb21/work/8651091a3118458781c09e8890a2cb21_id_rsa (zuul-build-sshkey)
2026-02-19 02:38:36.584206 | controller -> localhost | ok: Runtime: 0:00:00.014394
2026-02-19 02:38:36.590189 | 
2026-02-19 02:38:36.590274 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-19 02:38:36.961179 | controller | ok
2026-02-19 02:38:36.965060 | 
2026-02-19 02:38:36.965129 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-19 02:38:36.990775 | controller | skipping: Conditional result was False
2026-02-19 02:38:37.003964 | 
2026-02-19 02:38:37.004031 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-02-19 02:38:37.370463 | controller | ok
2026-02-19 02:38:37.376903 | 
2026-02-19 02:38:37.377015 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-02-19 02:38:59.293240 | controller | Output suppressed because no_log was given
2026-02-19 02:38:59.300790 | 
2026-02-19 02:38:59.300861 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-02-19 02:38:59.534542 | controller | ok: "logs"
2026-02-19 02:38:59.534813 | controller | ok: All items complete
2026-02-19 02:38:59.534841 | 
2026-02-19 02:38:59.712686 | controller | ok: "artifacts"
2026-02-19 02:38:59.899771 | controller | ok: "docs"
2026-02-19 02:38:59.912234 | 
2026-02-19 02:38:59.912427 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-02-19 02:39:00.151635 | controller | changed: "logs"
2026-02-19 02:39:00.339808 | controller | changed: "artifacts"
2026-02-19 02:39:00.546771 | controller | changed: "docs"
2026-02-19 02:39:00.566906 | 
2026-02-19 02:39:00.567096 | PLAY RECAP
2026-02-19 02:39:00.567265 | controller | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2026-02-19 02:39:00.567377 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-19 02:39:00.567517 | 
2026-02-19 02:39:00.711678 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-02-19 02:39:00.720473 | PRE-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2026-02-19 02:39:01.401177 | 
2026-02-19 02:39:01.401345 | PLAY [all]
2026-02-19 02:39:01.418360 | 
2026-02-19 02:39:01.418445 | TASK [Fix the permissions of the zuul home directory]
2026-02-19 02:39:01.795549 | controller | changed
2026-02-19 02:39:01.802145 | 
2026-02-19 02:39:01.802257 | TASK [Gather minimum local MTU]
2026-02-19 02:39:01.867461 | controller | ok
2026-02-19 02:39:01.872902 | 
2026-02-19 02:39:01.873145 | TASK [Calculate external_bridge_mtu]
2026-02-19 02:39:01.925143 | controller | ok
2026-02-19 02:39:01.930205 | 
2026-02-19 02:39:01.930392 | TASK [configure-swap : Set ephemeral device if /dev/xvde exists]
2026-02-19 02:39:01.956599 | controller | skipping: Conditional result was False
2026-02-19 02:39:01.965711 | 
2026-02-19 02:39:01.965802 | TASK [configure-swap : Get ephemeral0 device node]
2026-02-19 02:39:02.502491 | controller | ok: Runtime: 0:00:00.005888
2026-02-19 02:39:02.512032 | 
2026-02-19 02:39:02.512179 | TASK [configure-swap : Set ephemeral device if LABEL exists]
2026-02-19 02:39:02.538813 | controller | skipping: Conditional result was False
2026-02-19 02:39:02.547113 | 
2026-02-19 02:39:02.547216 | TASK [configure-swap : Setup swap on ephemeral storage]
2026-02-19 02:39:02.570736 | controller | skipping: Conditional result was False
2026-02-19 02:39:02.579769 | 
2026-02-19 02:39:02.579848 | TASK [configure-swap : Setup swap file on root device]
2026-02-19 02:39:02.642074 | controller | ok
2026-02-19 02:39:02.652248 | controller | included: /var/lib/zuul/builds/8651091a3118458781c09e8890a2cb21/untrusted/project_1/opendev.org/openstack/openstack-zuul-jobs/roles/configure-swap/tasks/root.yaml
2026-02-19 02:39:02.656934 | 
2026-02-19 02:39:02.657042 | TASK [configure-swap : Calculate required swap]
2026-02-19 02:39:02.707358 | controller | ok
2026-02-19 02:39:02.715481 | 
2026-02-19 02:39:02.715575 | TASK [configure-swap : Get root filesystem]
2026-02-19 02:39:02.180273 | controller | ext4
2026-02-19 02:39:03.245292 | controller | ok: Runtime: 0:00:00.013245
2026-02-19 02:39:03.251709 | 
2026-02-19 02:39:03.251772 | TASK [configure-swap : Save root filesystem]
2026-02-19 02:39:03.284205 | controller | ok
2026-02-19 02:39:03.293190 | 
2026-02-19 02:39:03.293396 | TASK [configure-swap : Debug the root_filesystem variable]
2026-02-19 02:39:03.327963 | controller | ok:
2026-02-19 02:39:03.328186 | controller | {
2026-02-19 02:39:03.328239 | controller |   "root_filesystem": "ext4"
2026-02-19 02:39:03.328269 | controller | }
2026-02-19 02:39:03.333319 | 
2026-02-19 02:39:03.333409 | TASK [configure-swap : Create swap backing file]
2026-02-19 02:39:21.753261 | controller | 4096+0 records in
2026-02-19 02:39:21.753513 | controller | 4096+0 records out
2026-02-19 02:39:21.753546 | controller | 4294967296 bytes (4.3 GB, 4.0 GiB) copied, 18.8297 s, 228 MB/s
2026-02-19 02:39:22.888033 | controller | ok: Runtime: 0:00:18.872551
2026-02-19 02:39:22.931162 | 
2026-02-19 02:39:22.931337 | TASK [configure-swap : Ensure swapfile perms]
2026-02-19 02:39:23.168639 | controller | changed
2026-02-19 02:39:23.174699 | 
2026-02-19 02:39:23.174768 | TASK [configure-swap : Make swapfile]
2026-02-19 02:39:34.738105 | controller | Setting up swapspace version 1, size = 4 GiB (4294963200 bytes)
2026-02-19 02:39:34.738849 | controller | no label, UUID=e9ffb633-beb8-4015-8552-3ab65fd4d68f
2026-02-19 02:39:35.729161 | controller | ok: Runtime: 0:00:12.089745
2026-02-19 02:39:35.733784 | 
2026-02-19 02:39:35.733856 | TASK [configure-swap : Write swap to fstab]
2026-02-19 02:39:36.077566 | controller | changed
2026-02-19 02:39:36.084534 | 
2026-02-19 02:39:36.084601 | TASK [configure-swap : Add all swap]
2026-02-19 02:39:36.614123 | controller | ok: Runtime: 0:00:00.012143
2026-02-19 02:39:36.619187 | 
2026-02-19 02:39:36.619253 | TASK [configure-swap : Debug the swap_required variable]
2026-02-19 02:39:36.651237 | controller | ok:
2026-02-19 02:39:36.651424 | controller | {
2026-02-19 02:39:36.651510 | controller |   "swap_required": "4096"
2026-02-19 02:39:36.651540 | controller | }
2026-02-19 02:39:36.656590 | 
2026-02-19 02:39:36.656651 | TASK [configure-swap : Set swappiness]
2026-02-19 02:39:37.004744 | controller | changed
2026-02-19 02:39:37.008900 | 
2026-02-19 02:39:37.008984 | TASK [configure-swap : Debug the ephemeral_device variable]
2026-02-19 02:39:37.042189 | controller | ok:
2026-02-19 02:39:37.042440 | controller | {
2026-02-19 02:39:37.042499 | controller |   "ephemeral_device": "VARIABLE IS NOT DEFINED!: 'ephemeral_device' is undefined. 'ephemeral_device' is undefined"
2026-02-19 02:39:37.042551 | controller | }
2026-02-19 02:39:37.051857 | 
2026-02-19 02:39:37.051923 | TASK [setup-stack-user : Create stack group]
2026-02-19 02:39:37.450185 | controller | changed
2026-02-19 02:39:37.455745 | 
2026-02-19 02:39:37.455833 | TASK [setup-stack-user : Create the stack user home folder]
2026-02-19 02:39:37.691436 | controller | changed
2026-02-19 02:39:37.697351 | 
2026-02-19 02:39:37.697443 | TASK [setup-stack-user : Create stack user]
2026-02-19 02:39:38.273998 | controller | changed
2026-02-19 02:39:38.280051 | 
2026-02-19 02:39:38.280120 | TASK [setup-stack-user : Set stack user home directory permissions and ownership]
2026-02-19 02:39:38.529277 | controller | changed
2026-02-19 02:39:38.536751 | 
2026-02-19 02:39:38.536817 | TASK [setup-stack-user : Copy 50_stack_sh file to /etc/sudoers.d]
2026-02-19 02:39:39.655206 | controller | changed
2026-02-19 02:39:39.659459 | 
2026-02-19 02:39:39.659528 | TASK [setup-stack-user : Create .cache folder within BASE]
2026-02-19 02:39:39.905667 | controller | changed
2026-02-19 02:39:39.913410 | 
2026-02-19 02:39:39.913479 | TASK [setup-tempest-user : Create tempest group]
2026-02-19 02:39:40.221833 | controller | changed
2026-02-19 02:39:40.226122 | 
2026-02-19 02:39:40.226187 | TASK [setup-tempest-user : Create tempest user]
2026-02-19 02:39:40.594464 | controller | changed
2026-02-19 02:39:40.599351 | 
2026-02-19 02:39:40.599415 | TASK [setup-tempest-user : Copy 51_tempest_sh to /etc/sudoers.d]
2026-02-19 02:39:41.464575 | controller | changed
2026-02-19 02:39:41.473193 | 
2026-02-19 02:39:41.473278 | TASK [setup-devstack-source-dirs : Find all OpenStack source repos used by this job]
2026-02-19 02:39:41.848199 | controller | ok: Not all paths examined, check warnings for details
2026-02-19 02:39:41.858427 | 
2026-02-19 02:39:41.858494 | LOOP [setup-devstack-source-dirs : Copy Zuul repos into devstack working directory]
2026-02-19 02:39:42.485235 | controller | ok: Item: Runtime: 0:00:00.362210
2026-02-19 02:39:43.935289 | controller | ok: Item: Runtime: 0:00:01.232024
2026-02-19 02:39:44.389702 | controller | ok: Item: Runtime: 0:00:00.235236
2026-02-19 02:39:44.749646 | controller | ok: Item: Runtime: 0:00:00.130010
2026-02-19 02:39:45.399357 | controller | ok: Item: Runtime: 0:00:00.435296
2026-02-19 02:39:45.700627 | controller | ok: Item: Runtime: 0:00:00.081288
2026-02-19 02:39:46.203421 | controller | ok: Item: Runtime: 0:00:00.288776
2026-02-19 02:39:46.574242 | controller | ok: Item: Runtime: 0:00:00.151548
2026-02-19 02:39:47.293584 | controller | ok: Item: Runtime: 0:00:00.497506
2026-02-19 02:39:47.656609 | controller | ok: Item: Runtime: 0:00:00.148856
2026-02-19 02:39:47.932634 | controller | ok: Item: Runtime: 0:00:00.054851
2026-02-19 02:39:51.851393 | controller | ok: Item: Runtime: 0:00:03.702242
2026-02-19 02:39:52.614441 | controller | ok: Item: Runtime: 0:00:00.543752
2026-02-19 02:39:54.075291 | controller | ok: Item: Runtime: 0:00:01.241531
2026-02-19 02:39:54.109509 | 
2026-02-19 02:39:54.109701 | TASK [setup-devstack-source-dirs : Find top level github projects]
2026-02-19 02:39:54.323748 | controller | ok: All paths examined
2026-02-19 02:39:54.330357 | 
2026-02-19 02:39:54.330456 | TASK [setup-devstack-source-dirs : Find actual github repos]
2026-02-19 02:39:54.565503 | controller | ok: All paths examined
2026-02-19 02:39:54.572817 | 
2026-02-19 02:39:54.572985 | LOOP [setup-devstack-source-dirs : Copy github repos into devstack working directory]
2026-02-19 02:39:59.418365 | controller | ok: Item: Runtime: 0:00:04.575699
2026-02-19 02:39:59.418703 | controller | changed: All items complete
2026-02-19 02:39:59.418753 | 
2026-02-19 02:39:59.775337 | controller | ok: Item: Runtime: 0:00:00.130304
2026-02-19 02:39:59.789372 | 
2026-02-19 02:39:59.789511 | LOOP [setup-devstack-source-dirs : Setup refspec for repos into devstack working directory]
2026-02-19 02:39:59.823697 | controller | skipping: Conditional result was False
2026-02-19 02:39:59.826203 | controller | skipping: Conditional result was False
2026-02-19 02:39:59.828897 | controller | skipping: Conditional result was False
2026-02-19 02:39:59.832415 | controller | skipping: Conditional result was False
2026-02-19 02:39:59.835924 | controller | skipping: Conditional result was False
2026-02-19 02:39:59.839612 | controller | skipping: Conditional result was False
2026-02-19 02:39:59.843109 | controller | skipping: Conditional result was False
2026-02-19 02:39:59.846455 | controller | skipping: Conditional result was False
2026-02-19 02:39:59.849846 | controller | skipping: Conditional result was False
2026-02-19 02:39:59.853251 | controller | skipping: Conditional result was False
2026-02-19 02:39:59.856607 | controller | skipping: Conditional result was False
2026-02-19 02:39:59.860285 | controller | skipping: Conditional result was False
2026-02-19 02:39:59.863681 | controller | skipping: Conditional result was False
2026-02-19 02:39:59.867163 | controller | skipping: Conditional result was False
2026-02-19 02:39:59.891718 | 
2026-02-19 02:39:59.891870 | TASK [setup-devstack-source-dirs : Set ownership of repos]
2026-02-19 02:40:11.689708 | controller | changed
2026-02-19 02:40:11.699105 | 
2026-02-19 02:40:11.699172 | TASK [setup-devstack-log-dir : Create logs directory]
2026-02-19 02:40:11.945822 | controller | changed
2026-02-19 02:40:12.001949 | 
2026-02-19 02:40:12.002102 | TASK [setup-devstack-cache : Copy cached devstack files]
2026-02-19 02:40:11.492307 | controller | find: ‘/opt/cache/files’: No such file or directory
2026-02-19 02:40:12.533062 | controller | ERROR
2026-02-19 02:40:12.533372 | controller | {
2026-02-19 02:40:12.533415 | controller |   "delta": "0:00:00.031521",
2026-02-19 02:40:12.533442 | controller |   "end": "2026-02-19 02:40:11.492684",
2026-02-19 02:40:12.533467 | controller |   "msg": "non-zero return code",
2026-02-19 02:40:12.533492 | controller |   "rc": 1,
2026-02-19 02:40:12.533516 | controller |   "start": "2026-02-19 02:40:11.461163"
2026-02-19 02:40:12.533616 | controller | }
2026-02-19 02:40:12.533664 | controller | ERROR: Ignoring Errors
2026-02-19 02:40:12.539307 | 
2026-02-19 02:40:12.539399 | TASK [setup-devstack-cache : Set ownership of cached files]
2026-02-19 02:40:12.806813 | controller | ok
2026-02-19 02:40:12.815374 | 
2026-02-19 02:40:12.815449 | TASK [start-fresh-logging : Check for /bin/journalctl file]
2026-02-19 02:40:12.521573 | controller | /usr/bin/journalctl
2026-02-19 02:40:13.347521 | controller | ok: Runtime: 0:00:00.264034
2026-02-19 02:40:13.353025 | 
2026-02-19 02:40:13.353116 | TASK [start-fresh-logging : Get current date]
2026-02-19 02:40:12.828146 | controller | 2026-02-19 02:40:12
2026-02-19 02:40:13.884499 | controller | ok: Runtime: 0:00:00.007942
2026-02-19 02:40:13.890438 | 
2026-02-19 02:40:13.890530 | TASK [start-fresh-logging : Copy current date to log-start-timestamp.txt]
2026-02-19 02:40:14.563406 | controller | changed
2026-02-19 02:40:14.570039 | 
2026-02-19 02:40:14.570115 | TASK [start-fresh-logging : Stop rsyslog]
2026-02-19 02:40:14.596016 | controller | skipping: Conditional result was False
2026-02-19 02:40:14.605748 | 
2026-02-19 02:40:14.605897 | TASK [start-fresh-logging : Save syslog file prior to devstack run]
2026-02-19 02:40:15.130657 | controller | skipping: Conditional result was False
2026-02-19 02:40:15.140196 | 
2026-02-19 02:40:15.140384 | TASK [start-fresh-logging : Save kern.log file prior to devstack run]
2026-02-19 02:40:15.664317 | controller | skipping: Conditional result was False
2026-02-19 02:40:15.673294 | 
2026-02-19 02:40:15.673392 | TASK [start-fresh-logging : Recreate syslog file]
2026-02-19 02:40:15.699457 | controller | skipping: Conditional result was False
2026-02-19 02:40:15.707449 | 
2026-02-19 02:40:15.707542 | TASK [start-fresh-logging : Recreate syslog file owner and group]
2026-02-19 02:40:16.231647 | controller | skipping: Conditional result was False
2026-02-19 02:40:16.240801 | 
2026-02-19 02:40:16.240896 | TASK [start-fresh-logging : Recreate syslog file permissions]
2026-02-19 02:40:16.764474 | controller | skipping: Conditional result was False
2026-02-19 02:40:16.773736 | 
2026-02-19 02:40:16.773831 | TASK [start-fresh-logging : Add read permissions to all on syslog file]
2026-02-19 02:40:16.799356 | controller | skipping: Conditional result was False
2026-02-19 02:40:16.807199 | 
2026-02-19 02:40:16.807290 | TASK [start-fresh-logging : Recreate kern.log file]
2026-02-19 02:40:16.831954 | controller | skipping: Conditional result was False
2026-02-19 02:40:16.840280 | 
2026-02-19 02:40:16.840366 | TASK [start-fresh-logging : Recreate kern.log file owner and group]
2026-02-19 02:40:17.366540 | controller | skipping: Conditional result was False
2026-02-19 02:40:17.374906 | 
2026-02-19 02:40:17.374997 | TASK [start-fresh-logging : Recreate kern.log file permissions]
2026-02-19 02:40:17.898927 | controller | skipping: Conditional result was False
2026-02-19 02:40:17.908546 | 
2026-02-19 02:40:17.908666 | TASK [start-fresh-logging : Add read permissions to all on kern.log file]
2026-02-19 02:40:17.934882 | controller | skipping: Conditional result was False
2026-02-19 02:40:17.941348 | 
2026-02-19 02:40:17.941414 | TASK [start-fresh-logging : Start rsyslog]
2026-02-19 02:40:17.965714 | controller | skipping: Conditional result was False
2026-02-19 02:40:17.978879 | 
2026-02-19 02:40:17.978969 | TASK [write-devstack-local-conf : Write a job-specific local_conf file]
2026-02-19 02:40:18.425943 | controller | ok
2026-02-19 02:40:18.435658 | 
2026-02-19 02:40:18.435706 | PLAY RECAP
2026-02-19 02:40:18.435753 | controller | ok: 39 changed: 24 unreachable: 0 failed: 0 skipped: 16 rescued: 0 ignored: 1
2026-02-19 02:40:18.435775 | 
2026-02-19 02:40:18.584236 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2026-02-19 02:40:18.594676 | PRE-RUN START: [untrusted : opendev.org/openstack/manila-tempest-plugin/playbooks/enable-fips.yaml@master]
2026-02-19 02:40:19.199335 | 
2026-02-19 02:40:19.199479 | PLAY [all]
2026-02-19 02:40:19.209962 | 
2026-02-19 02:40:19.210037 | TASK [enable-fips : Make sure this role is run on RHEL/CentOS/Ubuntu systems]
2026-02-19 02:40:19.256033 | controller | skipping: Conditional result was False
2026-02-19 02:40:19.265090 | 
2026-02-19 02:40:19.265202 | TASK [enable-fips : Do tasks for RHEL/Centos systems]
2026-02-19 02:40:19.317144 | controller | ok
2026-02-19 02:40:19.331866 | controller | included: /var/lib/zuul/builds/8651091a3118458781c09e8890a2cb21/untrusted/project_3/opendev.org/zuul/zuul-jobs/roles/enable-fips/tasks/rhel.yaml
2026-02-19 02:40:19.336354 | 
2026-02-19 02:40:19.336419 | TASK [enable-fips : Install fips-mode-setup]
2026-02-19 02:40:22.060113 | controller | changed
2026-02-19 02:40:22.066450 | 
2026-02-19 02:40:22.066520 | TASK [enable-fips : Enable FIPS mode]
2026-02-19 02:40:21.696693 | controller | *****************************************************************
2026-02-19 02:40:21.696845 | controller | * PRESS CONTROL-C WITHIN 15 SECONDS TO ABORT...                 *
2026-02-19 02:40:21.696859 | controller | *                                                               *
2026-02-19 02:40:21.696896 | controller | * ENABLING FIPS MODE AFTER THE INSTALLATION IS NOT RECOMMENDED. *
2026-02-19 02:40:21.696907 | controller | * THIS OPERATION CANNOT BE UNDONE.                              *
2026-02-19 02:40:21.696916 | controller | * REINSTALL WITH fips=1 INSTEAD.                                *
2026-02-19 02:40:21.696928 | controller | *****************************************************************
2026-02-19 02:40:36.742617 | controller | 15... 14... 13... 12... 11... 10... 9... 8... 7... 6... 5... 4... 3... 2... 1...
2026-02-19 02:40:36.753155 | controller | Kernel initramdisks are being regenerated. This might take some time.
2026-02-19 02:41:05.593992 | controller | Setting system policy to FIPS
2026-02-19 02:41:05.594060 | controller | Note: System-wide crypto policies are applied on application start-up.
2026-02-19 02:41:05.594072 | controller | It is recommended to restart the system for the change of policies
2026-02-19 02:41:05.594082 | controller | to fully take place.
2026-02-19 02:41:05.605793 | controller | FIPS mode will be enabled.
2026-02-19 02:41:05.694504 | controller | Please reboot the system for the setting to take effect.
2026-02-19 02:41:06.665834 | controller | ok: Runtime: 0:00:44.012450
2026-02-19 02:41:06.672207 | 
2026-02-19 02:41:06.672302 | TASK [enable-fips : Check if GRUB_CMDLINE_LINUX_DEFAULT exists in /etc/default/grub]
2026-02-19 02:41:06.147703 | controller | GRUB_CMDLINE_LINUX_DEFAULT="console=tty0 console=ttyS0,115200 no_timer_check nofb nomodeset gfxpayload=text"
2026-02-19 02:41:07.206379 | controller | ok: Runtime: 0:00:00.006911
2026-02-19 02:41:07.212553 | 
2026-02-19 02:41:07.212653 | TASK [enable-fips : Add GRUB_CMDLINE_LINUX_DEFAULT in /etc/default/grub]
2026-02-19 02:41:07.238304 | controller | skipping: Conditional result was False
2026-02-19 02:41:07.247395 | 
2026-02-19 02:41:07.247459 | TASK [enable-fips : Replace GRUB_CMDLINE_LINUX_DEFAULT in /etc/default/grub]
2026-02-19 02:41:07.643823 | controller | changed: line replaced
2026-02-19 02:41:07.649504 | 
2026-02-19 02:41:07.649594 | TASK [enable-fips : Rebuild grub.cfg file]
2026-02-19 02:41:07.475487 | controller | Generating grub configuration file ...
2026-02-19 02:41:09.054599 | controller | Adding boot menu entry for UEFI Firmware Settings ...
2026-02-19 02:41:09.078257 | controller | done
2026-02-19 02:41:10.186623 | controller | ok: Runtime: 0:00:01.964787
2026-02-19 02:41:10.193214 | 
2026-02-19 02:41:10.193324 | TASK [enable-fips : Reboot server for FIPS mode]
2026-02-19 02:42:05.337190 | controller | changed
2026-02-19 02:42:05.342581 | 
2026-02-19 02:42:05.342665 | TASK [Run post-boot tasks]
2026-02-19 02:42:05.364514 | controller | ok
2026-02-19 02:42:05.382787 | 
2026-02-19 02:42:05.382853 | TASK [post-reboot-tasks : Check if node is available for ssh]
2026-02-19 02:42:06.057399 | controller | ok
2026-02-19 02:42:06.061906 | 
2026-02-19 02:42:06.061967 | TASK [Run start-zuul-console role]
2026-02-19 02:42:06.081561 | controller | ok
2026-02-19 02:42:06.099628 | 
2026-02-19 02:42:06.099692 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-02-19 02:42:07.005191 | controller | ok
2026-02-19 02:42:07.050528 | 
2026-02-19 02:42:07.050677 | TASK [post-reboot-tasks : Confirm that dns is up]
2026-02-19 02:42:07.578345 | controller | ERROR
2026-02-19 02:42:07.578746 | controller | {
2026-02-19 02:42:07.578819 | controller |   "msg": "[Errno 2] No such file or directory: b'nslookup'",
2026-02-19 02:42:07.578873 | controller |   "rc": 2
2026-02-19 02:42:07.578918 | controller | }
failure
2026-02-19 02:42:07.581502 | 
2026-02-19 02:42:07.581597 | PLAY RECAP
2026-02-19 02:42:07.581699 | controller | ok: 9 changed: 6 unreachable: 0 failed: 1 skipped: 2 rescued: 0 ignored: 0
2026-02-19 02:42:07.581750 | 
2026-02-19 02:42:07.751385 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/manila-tempest-plugin/playbooks/enable-fips.yaml@master]
2026-02-19 02:42:07.761715 | POST-RUN START: [untrusted : opendev.org/openstack/tempest/playbooks/post-tempest.yaml@master]
2026-02-19 02:42:08.392809 | 
2026-02-19 02:42:08.392948 | PLAY [tempest]
2026-02-19 02:42:08.406352 | 
2026-02-19 02:42:08.406427 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-02-19 02:42:09.005288 | controller | changed: non-zero return code
2026-02-19 02:42:09.010042 | 
2026-02-19 02:42:09.010120 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-02-19 02:42:09.035907 | controller | skipping: Conditional result was False
2026-02-19 02:42:09.045027 | 
2026-02-19 02:42:09.045178 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-02-19 02:42:09.079841 | 
2026-02-19 02:42:09.079995 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-02-19 02:42:09.110078 | 
2026-02-19 02:42:09.110256 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-02-19 02:42:09.134788 | controller | skipping: Conditional result was False
2026-02-19 02:42:09.141975 | 
2026-02-19 02:42:09.142065 | LOOP [fetch-subunit-output : Generate subunit file]
2026-02-19 02:42:09.175113 | 
2026-02-19 02:42:09.175267 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-02-19 02:42:09.199594 | controller | skipping: Conditional result was False
2026-02-19 02:42:09.207735 | 
2026-02-19 02:42:09.207832 | TASK [fetch-subunit-output : Remove the temporary file]
2026-02-19 02:42:09.232485 | controller | skipping: Conditional result was False
2026-02-19 02:42:09.238185 | 
2026-02-19 02:42:09.238299 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-02-19 02:42:09.262877 | controller | skipping: Conditional result was False
2026-02-19 02:42:09.274593 | 
2026-02-19 02:42:09.274703 | TASK [process-stackviz : Devstack checks if stackviz archive exists]
2026-02-19 02:42:09.733296 | controller | ok
2026-02-19 02:42:09.738988 | 
2026-02-19 02:42:09.739068 | TASK [process-stackviz : debug]
2026-02-19 02:42:09.770638 | Stackviz archive could not be found in /opt/cache/files/stackviz-latest.tar.gz
2026-02-19 02:42:09.776575 | 
2026-02-19 02:42:09.776639 | TASK [process-stackviz : Check if subunit data exists]
2026-02-19 02:42:10.063784 | controller | ok
2026-02-19 02:42:10.067733 | 
2026-02-19 02:42:10.067816 | TASK [process-stackviz : debug]
2026-02-19 02:42:10.099586 | Subunit file could not be found at /opt/stack/tempest/testrepository.subunit
2026-02-19 02:42:10.105108 | 
2026-02-19 02:42:10.105203 | TASK [include_role : ensure-pip]
2026-02-19 02:42:10.130393 | controller | skipping: Conditional result was False
2026-02-19 02:42:10.139479 | 
2026-02-19 02:42:10.139548 | TASK [process-stackviz : pip]
2026-02-19 02:42:10.163898 | controller | skipping: Conditional result was False
2026-02-19 02:42:10.175385 | 
2026-02-19 02:42:10.175527 | TASK [process-stackviz : Deploy stackviz static html+js]
2026-02-19 02:42:10.703134 | controller | skipping: Conditional result was False
2026-02-19 02:42:10.713065 | 
2026-02-19 02:42:10.713148 | TASK [process-stackviz : Check if dstat data exists]
2026-02-19 02:42:10.737628 | controller | skipping: Conditional result was False
2026-02-19 02:42:10.746644 | 
2026-02-19 02:42:10.746784 | TASK [process-stackviz : Run stackviz with dstat]
2026-02-19 02:42:11.270681 | controller | skipping: Conditional result was False
2026-02-19 02:42:11.280092 | 
2026-02-19 02:42:11.280227 | TASK [process-stackviz : Run stackviz without dstat]
2026-02-19 02:42:11.807862 | controller | skipping: Conditional result was False
2026-02-19 02:42:11.817687 | 
2026-02-19 02:42:11.817764 | PLAY RECAP
2026-02-19 02:42:11.817824 | controller | ok: 5 changed: 1 unreachable: 0 failed: 0 skipped: 14 rescued: 0 ignored: 0
2026-02-19 02:42:11.817868 | 
2026-02-19 02:42:11.984675 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/tempest/playbooks/post-tempest.yaml@master]
2026-02-19 02:42:11.995956 | POST-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2026-02-19 02:42:12.659151 | 
2026-02-19 02:42:12.659302 | PLAY [all]
2026-02-19 02:42:12.676301 | 
2026-02-19 02:42:12.676383 | TASK [export-devstack-journal : Ensure /home/zuul/logs exists]
2026-02-19 02:42:13.367637 | controller | changed
2026-02-19 02:42:13.374131 | 
2026-02-19 02:42:13.374212 | TASK [export-devstack-journal : Export legacy stack screen log files]
2026-02-19 02:42:14.404463 | controller | ok: Runtime: 0:00:00.358333
2026-02-19 02:42:14.410596 | 
2026-02-19 02:42:14.410695 | TASK [export-devstack-journal : Export legacy syslog.txt]
2026-02-19 02:42:14.941849 | controller | ok: Runtime: 0:00:00.066250
2026-02-19 02:42:14.946746 | 
2026-02-19 02:42:14.946815 | TASK [export-devstack-journal : Export journal]
2026-02-19 02:42:15.474166 | controller | ok: Runtime: 0:00:00.083154
2026-02-19 02:42:15.480678 | 
2026-02-19 02:42:15.480750 | TASK [export-devstack-journal : Save journal README]
2026-02-19 02:42:16.542965 | controller | changed
2026-02-19 02:42:16.555635 | 
2026-02-19 02:42:16.555708 | TASK [apache-logs-conf : Ensure /home/zuul/apache exists]
2026-02-19 02:42:16.862200 | controller | changed
2026-02-19 02:42:16.868120 | 
2026-02-19 02:42:16.868208 | TASK [apache-logs-conf : Find logs]
2026-02-19 02:42:16.903486 | 
2026-02-19 02:42:16.903851 | LOOP [apache-logs-conf : Dereference files]
2026-02-19 02:42:16.941757 | 
2026-02-19 02:42:16.941894 | LOOP [apache-logs-conf : Create hard links]
2026-02-19 02:42:16.974713 | 
2026-02-19 02:42:16.974879 | TASK [apache-logs-conf : Find logs]
2026-02-19 02:42:17.404807 | controller | Output suppressed because no_log was given
2026-02-19 02:42:17.410349 | 
2026-02-19 02:42:17.410447 | LOOP [apache-logs-conf : Dereference files]
2026-02-19 02:42:17.432631 | 
2026-02-19 02:42:17.432753 | LOOP [apache-logs-conf : Create hard links]
2026-02-19 02:42:17.465592 | 
2026-02-19 02:42:17.465775 | TASK [apache-logs-conf : Ensure /home/zuul/apache_config apache_config exists]
2026-02-19 02:42:17.751915 | controller | changed
2026-02-19 02:42:17.758528 | 
2026-02-19 02:42:17.758643 | TASK [apache-logs-conf : Define config paths]
2026-02-19 02:42:17.790955 | controller | ok
2026-02-19 02:42:17.839999 | 
2026-02-19 02:42:17.840168 | TASK [apache-logs-conf : Discover configurations]
2026-02-19 02:42:18.135417 | controller | Output suppressed because no_log was given
2026-02-19 02:42:18.140893 | 
2026-02-19 02:42:18.140978 | LOOP [apache-logs-conf : Dereference configurations]
2026-02-19 02:42:18.172735 | 
2026-02-19 02:42:18.173000 | LOOP [apache-logs-conf : Link configurations]
2026-02-19 02:42:18.211498 | 
2026-02-19 02:42:18.211673 | TASK [capture-performance-data : Generate statistics]
2026-02-19 02:42:18.081727 | controller | /opt/stack/devstack//inc/python: line 43: -m: command not found
2026-02-19 02:42:18.092450 | controller | Using python 3.9 to install setuptools
2026-02-19 02:42:18.133247 | controller | /bin/python3.9: No module named pip
2026-02-19 02:42:18.141869 | controller | /bin/bash: line 4: /opt/stack/data/venv/bin/python3: No such file or directory
2026-02-19 02:42:19.245529 | controller | ERROR
2026-02-19 02:42:19.245863 | controller | {
2026-02-19 02:42:19.245934 | controller |   "delta": "0:00:00.304860",
2026-02-19 02:42:19.245981 | controller |   "end": "2026-02-19 02:42:18.143424",
2026-02-19 02:42:19.246022 | controller |   "msg": "non-zero return code",
2026-02-19 02:42:19.246070 | controller |   "rc": 127,
2026-02-19 02:42:19.246110 | controller |   "start": "2026-02-19 02:42:17.838564"
2026-02-19 02:42:19.246150 | controller | }
2026-02-19 02:42:19.246205 | controller | ERROR: Ignoring Errors
2026-02-19 02:42:19.255859 | 
2026-02-19 02:42:19.255928 | TASK [devstack-project-conf : Ensure /home/zuul/etc exists]
2026-02-19 02:42:19.530870 | controller | changed
2026-02-19 02:42:19.535468 | 
2026-02-19 02:42:19.535534 | LOOP [devstack-project-conf : Check which projects have a config folder]
2026-02-19 02:42:23.538859 | controller | Output suppressed because no_log was given
2026-02-19 02:42:23.545664 | 
2026-02-19 02:42:23.545790 | LOOP [devstack-project-conf : Copy configuration files]
2026-02-19 02:42:23.571466 | controller | skipping: Conditional result was False
2026-02-19 02:42:23.572007 | 
2026-02-19 02:42:23.574027 | controller | skipping: Conditional result was False
2026-02-19 02:42:23.575643 | controller | skipping: Conditional result was False
2026-02-19 02:42:23.577978 | controller | skipping: Conditional result was False
2026-02-19 02:42:23.580729 | controller | skipping: Conditional result was False
2026-02-19 02:42:23.583988 | controller | skipping: Conditional result was False
2026-02-19 02:42:23.598653 | controller | skipping: Conditional result was False
2026-02-19 02:42:23.599373 | controller | skipping: Conditional result was False
2026-02-19 02:42:23.600080 | controller | skipping: Conditional result was False
2026-02-19 02:42:23.600843 | controller | skipping: Conditional result was False
2026-02-19 02:42:23.601556 | controller | skipping: Conditional result was False
2026-02-19 02:42:23.602256 | controller | skipping: Conditional result was False
2026-02-19 02:42:23.603120 | controller | skipping: Conditional result was False
2026-02-19 02:42:23.605741 | controller | skipping: Conditional result was False
2026-02-19 02:42:23.609153 | controller | skipping: Conditional result was False
2026-02-19 02:42:23.611638 | controller | skipping: Conditional result was False
2026-02-19 02:42:23.644996 | 
2026-02-19 02:42:23.645171 | TASK [devstack-project-conf : Check if openstack has a config folder]
2026-02-19 02:42:23.911602 | controller | ok
2026-02-19 02:42:23.917779 | 
2026-02-19 02:42:23.917871 | TASK [devstack-project-conf : Copy configuration files]
2026-02-19 02:42:24.441608 | controller | skipping: Conditional result was False
2026-02-19 02:42:24.457178 | 
2026-02-19 02:42:24.457275 | TASK [capture-system-logs : Stage various logs and reports]
2026-02-19 02:42:24.087633 | controller | sudo: iptables-save: command not found
2026-02-19 02:42:24.101810 | controller | which: no python2 in (/sbin:/bin:/usr/sbin:/usr/bin:/usr/local/bin/)
2026-02-19 02:42:24.130230 | controller | /bin/python3: No module named pip
2026-02-19 02:42:25.263333 | controller | grep: /home/zuul/apache/*.log: No such file or directory
2026-02-19 02:42:25.987506 | controller | ok: Runtime: 0:00:01.202404
2026-02-19 02:42:25.997305 | 
2026-02-19 02:42:25.997394 | LOOP [stage-output : Register sources]
2026-02-19 02:42:39.318133 | controller | Output suppressed because no_log was given
2026-02-19 02:42:39.330005 | 
2026-02-19 02:42:39.330077 | TASK [stage-output : Check sudo]
2026-02-19 02:42:39.865812 | controller | ok: Runtime: 0:00:00.023158
2026-02-19 02:42:39.874738 | 
2026-02-19 02:42:39.874803 | LOOP [stage-output : Set source and destination for files and folders]
2026-02-19 02:42:39.992239 | controller | Output suppressed because no_log was given
2026-02-19 02:42:39.992942 | 
2026-02-19 02:42:39.994170 | controller | Output suppressed because no_log was given
2026-02-19 02:42:39.996109 | controller | Output suppressed because no_log was given
2026-02-19 02:42:39.998746 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.037131 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.038097 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.039380 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.041991 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.044340 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.047176 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.049898 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.052522 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.055396 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.058150 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.060861 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.063625 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.066677 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.069548 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.087123 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.087613 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.088619 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.091359 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.094087 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.096746 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.099708 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.102504 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.105608 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.138844 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.161563 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.215860 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.248162 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.248850 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.251427 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.259112 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.275437 | controller | Output suppressed because no_log was given
2026-02-19 02:42:40.293738 | 
2026-02-19 02:42:40.293824 | TASK [stage-output : Build a list of source, dest dictionaries]
2026-02-19 02:42:40.355729 | controller | ok
2026-02-19 02:42:40.364778 | 
2026-02-19 02:42:40.364870 | LOOP [stage-output : Ensure target folders exist]
2026-02-19 02:42:40.649565 | controller | changed: "docs"
2026-02-19 02:42:40.906744 | controller | changed: "artifacts"
2026-02-19 02:42:41.173914 | controller | ok: "logs"
2026-02-19 02:42:41.181156 | 
2026-02-19 02:42:41.181326 | LOOP [stage-output : Copy files and folders to staging folder]
2026-02-19 02:42:41.491251 | controller | ok: Item: Runtime: 0:00:00.005850
2026-02-19 02:42:41.491564 | controller | changed: All items complete
2026-02-19 02:42:41.491630 | 
2026-02-19 02:42:41.764723 | controller | ok: Item: Runtime: 0:00:00.006021
2026-02-19 02:42:42.039323 | controller | ok: Item: Runtime: 0:00:00.005830
2026-02-19 02:42:42.304856 | controller | ok: Item: Runtime: 0:00:00.005474
2026-02-19 02:42:42.562483 | controller | ok: Item: Runtime: 0:00:00.006230
2026-02-19 02:42:42.833799 | controller | ok: Item: Runtime: 0:00:00.005762
2026-02-19 02:42:43.096164 | controller | ok: Item: Runtime: 0:00:00.006779
2026-02-19 02:42:43.359667 | controller | ok: Item: Runtime: 0:00:00.005551
2026-02-19 02:42:43.625358 | controller | ok: Item: Runtime: 0:00:00.005696
2026-02-19 02:42:43.900627 | controller | ok: Item: Runtime: 0:00:00.005686
2026-02-19 02:42:44.191351 | controller | ok: Item: Runtime: 0:00:00.006698
2026-02-19 02:42:44.481124 | controller | ok: Item: Runtime: 0:00:00.007227
2026-02-19 02:42:44.770954 | controller | ok: Item: Runtime: 0:00:00.004902
2026-02-19 02:42:45.035001 | controller | ok: Item: Runtime: 0:00:00.005552
2026-02-19 02:42:45.300023 | controller | ok: Item: Runtime: 0:00:00.005613
2026-02-19 02:42:45.559604 | controller | ok: Item: Runtime: 0:00:00.004950
2026-02-19 02:42:45.814001 | controller | ok: Item: Runtime: 0:00:00.004855
2026-02-19 02:42:45.834343 | 
2026-02-19 02:42:45.834426 | TASK [stage-output : Make all log files readable]
2026-02-19 02:42:46.131097 | controller | changed
2026-02-19 02:42:46.140906 | 
2026-02-19 02:42:46.141076 | TASK [stage-output : Rename log files that match extensions_to_txt]
2026-02-19 02:42:46.608556 | controller | changed: Renamed files for staging.
2026-02-19 02:42:46.612760 | 
2026-02-19 02:42:46.612826 | TASK [stage-output : Discover log files for compression]
2026-02-19 02:42:46.637493 | controller | skipping: Conditional result was False
2026-02-19 02:42:46.648861 | 
2026-02-19 02:42:46.649071 | LOOP [stage-output : Archive everything from logs]
2026-02-19 02:42:46.689648 | 
2026-02-19 02:42:46.689765 | TASK [fetch-devstack-log-dir : Collect devstack logs]
2026-02-19 02:42:47.410688 | controller | changed:
2026-02-19 02:42:47.411069 | controller | created directory /var/lib/zuul/builds/8651091a3118458781c09e8890a2cb21/work/logs/controller
2026-02-19 02:42:47.411143 | controller | cd+++++++++ logs/
2026-02-19 02:42:47.411192 | controller | >f+++++++++ logs/audit_log.txt
2026-02-19 02:42:47.411236 | controller | >f+++++++++ logs/deprecations_log.txt
2026-02-19 02:42:47.411275 | controller | >f+++++++++ logs/devstack.journal.README.txt
2026-02-19 02:42:47.411294 | controller | >f+++++++++ logs/devstack.journal.gz
2026-02-19 02:42:47.411313 | controller | >f+++++++++ logs/df.txt
2026-02-19 02:42:47.411331 | controller | >f+++++++++ logs/iptables.txt
2026-02-19 02:42:47.411351 | controller | >f+++++++++ logs/listen53.txt
2026-02-19 02:42:47.411370 | controller | >f+++++++++ logs/local_conf.txt
2026-02-19 02:42:47.411388 | controller | >f+++++++++ logs/mount.txt
2026-02-19 02:42:47.411407 | controller | >f+++++++++ logs/performance.json
2026-02-19 02:42:47.411426 | controller | >f+++++++++ logs/pip3-freeze.txt
2026-02-19 02:42:47.411444 | controller | >f+++++++++ logs/resolv_conf.txt
2026-02-19 02:42:47.411462 | controller | >f+++++++++ logs/rpm-qa.txt
2026-02-19 02:42:47.411481 | controller | >f+++++++++ logs/services.txt
2026-02-19 02:42:47.411499 | controller | >f+++++++++ logs/sudoers
2026-02-19 02:42:47.411518 | controller | >f+++++++++ logs/syslog.txt
2026-02-19 02:42:47.411536 | controller | cd+++++++++ logs/apache/
2026-02-19 02:42:47.411554 | controller | cd+++++++++ logs/apache_config/
2026-02-19 02:42:47.411572 | controller | cd+++++++++ logs/etc/
2026-02-19 02:42:47.411590 | controller | cd+++++++++ logs/sudoers.d/
2026-02-19 02:42:47.411608 | controller | >f+++++++++ logs/sudoers.d/50_stack_sh
2026-02-19 02:42:47.411627 | controller | >f+++++++++ logs/sudoers.d/51_tempest_sh
2026-02-19 02:42:47.411646 | controller | >f+++++++++ logs/sudoers.d/90-cloud-init-users
2026-02-19 02:42:47.411665 | controller | >f+++++++++ logs/sudoers.d/zuul
2026-02-19 02:42:47.418857 | 
2026-02-19 02:42:47.418919 | TASK [Check if a tempest log exits]
2026-02-19 02:42:47.715852 | controller | ok
2026-02-19 02:42:47.721478 | 
2026-02-19 02:42:47.721538 | TASK [Link post-devstack tempest.log]
2026-02-19 02:42:47.737734 | controller | skipping: Conditional result was False
2026-02-19 02:42:47.746179 | 
2026-02-19 02:42:47.746312 | TASK [Capture most recent qemu crash dump, if any]
2026-02-19 02:42:47.424317 | controller | No match found.
2026-02-19 02:42:48.276893 | controller | ERROR
2026-02-19 02:42:48.277163 | controller | {
2026-02-19 02:42:48.277227 | controller |   "delta": "0:00:00.054581",
2026-02-19 02:42:48.277275 | controller |   "end": "2026-02-19 02:42:47.424993",
2026-02-19 02:42:48.277316 | controller |   "msg": "non-zero return code",
2026-02-19 02:42:48.277357 | controller |   "rc": 1,
2026-02-19 02:42:48.277400 | controller |   "start": "2026-02-19 02:42:47.370412"
2026-02-19 02:42:48.277439 | controller | }
2026-02-19 02:42:48.277493 | controller | ERROR: Ignoring Errors
2026-02-19 02:42:48.279839 | 
2026-02-19 02:42:48.279910 | PLAY RECAP
2026-02-19 02:42:48.279971 | controller | ok: 26 changed: 17 unreachable: 0 failed: 0 skipped: 12 rescued: 0 ignored: 2
2026-02-19 02:42:48.280003 | 
2026-02-19 02:42:48.435399 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2026-02-19 02:42:48.442046 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-02-19 02:42:49.040178 | 
2026-02-19 02:42:49.040321 | PLAY [all]
2026-02-19 02:42:49.050537 | 
2026-02-19 02:42:49.050610 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-19 02:42:49.085663 | controller | skipping: Conditional result was False
2026-02-19 02:42:49.092730 | 
2026-02-19 02:42:49.092831 | TASK [fetch-output : Set log path for single node]
2026-02-19 02:42:49.134511 | controller | ok
2026-02-19 02:42:49.140151 | 
2026-02-19 02:42:49.140217 | LOOP [fetch-output : Ensure local output dirs]
2026-02-19 02:42:49.537180 | controller -> localhost | ok: "/var/lib/zuul/builds/8651091a3118458781c09e8890a2cb21/work/logs"
2026-02-19 02:42:49.778717 | controller -> localhost | changed: "/var/lib/zuul/builds/8651091a3118458781c09e8890a2cb21/work/artifacts"
2026-02-19 02:42:50.002558 | controller -> localhost | changed: "/var/lib/zuul/builds/8651091a3118458781c09e8890a2cb21/work/docs"
2026-02-19 02:42:50.019694 | 
2026-02-19 02:42:50.019893 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-19 02:42:50.776269 | controller | changed: .d..t...... ./
2026-02-19 02:42:50.776597 | controller | changed: All items complete
2026-02-19 02:42:50.776644 | 
2026-02-19 02:42:51.326348 | controller | changed: .d..t...... ./
2026-02-19 02:42:51.856769 | controller | changed: .d..t...... ./
2026-02-19 02:42:51.873231 | 
2026-02-19 02:42:51.873417 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-02-19 02:42:52.289029 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007918
2026-02-19 02:42:52.526237 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.009034
2026-02-19 02:42:52.545999 | 
2026-02-19 02:42:52.546169 | PLAY [all]
2026-02-19 02:42:52.552124 | 
2026-02-19 02:42:52.552187 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-02-19 02:42:53.313717 | controller | changed
2026-02-19 02:42:53.320148 | 
2026-02-19 02:42:53.320198 | PLAY RECAP
2026-02-19 02:42:53.320244 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-02-19 02:42:53.320266 | 
2026-02-19 02:42:53.503979 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-02-19 02:42:53.513830 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main]
2026-02-19 02:42:54.118496 | 
2026-02-19 02:42:54.118630 | PLAY [localhost]
2026-02-19 02:42:54.128519 | 
2026-02-19 02:42:54.128608 | TASK [Generate Zuul manifest]
2026-02-19 02:42:54.160750 | localhost | ok
2026-02-19 02:42:54.177649 | 
2026-02-19 02:42:54.177727 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-02-19 02:42:54.563501 | localhost | changed
2026-02-19 02:42:54.575362 | 
2026-02-19 02:42:54.575443 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-02-19 02:42:54.606809 | localhost | ok
2026-02-19 02:42:54.616529 | 
2026-02-19 02:42:54.616616 | TASK [Upload logs]
2026-02-19 02:42:54.638964 | localhost | ok
2026-02-19 02:42:54.697438 | 
2026-02-19 02:42:54.697565 | TASK [Set zuul-log-path fact]
2026-02-19 02:42:54.718744 | localhost | ok
2026-02-19 02:42:54.774806 | 
2026-02-19 02:42:54.774948 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-19 02:42:54.807668 | localhost | ok
2026-02-19 02:42:54.816769 | 
2026-02-19 02:42:54.816858 | TASK [upload-logs : Create log directories]
2026-02-19 02:42:55.175760 | localhost | changed
2026-02-19 02:42:55.182214 | 
2026-02-19 02:42:55.182288 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-02-19 02:42:55.541926 | localhost -> localhost | ok: Runtime: 0:00:00.003431
2026-02-19 02:42:55.549032 | 
2026-02-19 02:42:55.549130 | TASK [upload-logs : Upload logs to log server]
2026-02-19 02:42:56.001405 | localhost | Output suppressed because no_log was given
2026-02-19 02:42:56.007531 | 
2026-02-19 02:42:56.007600 | LOOP [upload-logs : Compress console log and json output]
2026-02-19 02:42:56.058636 | localhost | skipping: Conditional result was False
2026-02-19 02:42:56.066935 | localhost | skipping: Conditional result was False
2026-02-19 02:42:56.083454 | 
2026-02-19 02:42:56.083651 | LOOP [upload-logs : Upload compressed console log and json output]
2026-02-19 02:42:56.127425 | localhost | skipping: Conditional result was False
2026-02-19 02:42:56.127841 | 
2026-02-19 02:42:56.131536 | localhost | skipping: Conditional result was False
2026-02-19 02:42:56.148872 | 
2026-02-19 02:42:56.149142 | LOOP [upload-logs : Upload console log and json output]