2026-02-19 02:33:22.685894 | Job console starting
2026-02-19 02:33:22.696678 | Updating git repos
2026-02-19 02:33:26.119543 | Cloning repos into workspace
2026-02-19 02:33:31.145284 | Restoring repo states
2026-02-19 02:33:34.438011 | Merging changes
2026-02-19 02:33:35.023126 | Checking out repos
2026-02-19 02:33:38.426969 | Preparing playbooks
2026-02-19 02:33:40.380764 | Running Ansible setup
2026-02-19 02:33:43.839566 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-02-19 02:33:44.423881 | 
2026-02-19 02:33:44.424001 | PLAY [localhost]
2026-02-19 02:33:44.431707 | 
2026-02-19 02:33:44.431774 | TASK [Gathering Facts]
2026-02-19 02:33:45.291627 | localhost | ok
2026-02-19 02:33:45.300885 | 
2026-02-19 02:33:45.300974 | TASK [Setup log path fact]
2026-02-19 02:33:45.321530 | localhost | ok
2026-02-19 02:33:45.332917 | 
2026-02-19 02:33:45.332996 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-19 02:33:45.366205 | localhost | ok
2026-02-19 02:33:45.374902 | 
2026-02-19 02:33:45.374991 | TASK [emit-job-header : Print job information]
2026-02-19 02:33:45.417136 | # Job Information
2026-02-19 02:33:45.417315 | Ansible Version: 2.16.16
2026-02-19 02:33:45.417363 | Job: manila-tempest-plugin-lvm-fips-py311
2026-02-19 02:33:45.417396 | Pipeline: check
2026-02-19 02:33:45.417426 | Executor: 0a8996d2b663
2026-02-19 02:33:45.417456 | Triggered by: https://github.com/vexxhost/manila/pull/1
2026-02-19 02:33:45.417490 | Event ID: d42d6dc0-0d39-11f1-9818-0dbc046261a0
2026-02-19 02:33:45.421783 | 
2026-02-19 02:33:45.421872 | LOOP [emit-job-header : Print node information]
2026-02-19 02:33:45.506040 | localhost | ok:
2026-02-19 02:33:45.506380 | localhost | # Node Information
2026-02-19 02:33:45.506443 | localhost | Inventory Hostname: controller
2026-02-19 02:33:45.506489 | localhost | Hostname: np0000156499
2026-02-19 02:33:45.506532 | localhost | Username: zuul
2026-02-19 02:33:45.506580 | localhost | Distro: CentOS 9
2026-02-19 02:33:45.506623 | localhost | Provider: yul1
2026-02-19 02:33:45.506663 | localhost | Region: ca-ymq-1
2026-02-19 02:33:45.506703 | localhost | Label: centos-9-stream
2026-02-19 02:33:45.506742 | localhost | Product Name: OpenStack Nova
2026-02-19 02:33:45.506782 | localhost | Interface IP: 162.253.55.207
2026-02-19 02:33:45.525927 | 
2026-02-19 02:33:45.526051 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-02-19 02:33:45.965684 | localhost -> localhost | changed
2026-02-19 02:33:45.976867 | 
2026-02-19 02:33:45.977038 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-02-19 02:33:46.844921 | localhost -> localhost | changed
2026-02-19 02:33:46.856665 | 
2026-02-19 02:33:46.856744 | PLAY [all]
2026-02-19 02:33:46.866791 | 
2026-02-19 02:33:46.866862 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-19 02:33:47.095433 | controller -> localhost | ok
2026-02-19 02:33:47.105336 | 
2026-02-19 02:33:47.105406 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-19 02:33:47.138718 | controller | ok
2026-02-19 02:33:47.152853 | controller | included: /var/lib/zuul/builds/de38641e2b224377a7d930c1a1afe872/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-19 02:33:47.158493 | 
2026-02-19 02:33:47.158556 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-19 02:33:48.042413 | controller -> localhost | Generating public/private rsa key pair.
2026-02-19 02:33:48.042753 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/de38641e2b224377a7d930c1a1afe872/work/de38641e2b224377a7d930c1a1afe872_id_rsa
2026-02-19 02:33:48.042813 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/de38641e2b224377a7d930c1a1afe872/work/de38641e2b224377a7d930c1a1afe872_id_rsa.pub
2026-02-19 02:33:48.042857 | controller -> localhost | The key fingerprint is:
2026-02-19 02:33:48.042900 | controller -> localhost | SHA256:GJEVJhFf8MHXgZ2ZmHqt5xy/Qa2vAoHTRoBzvAPyWKQ zuul-build-sshkey
2026-02-19 02:33:48.042958 | controller -> localhost | The key's randomart image is:
2026-02-19 02:33:48.042999 | controller -> localhost | +---[RSA 3072]----+
2026-02-19 02:33:48.043045 | controller -> localhost | |     .*B*=o  *.= |
2026-02-19 02:33:48.043095 | controller -> localhost | |    ..*=ooo.= *  |
2026-02-19 02:33:48.043136 | controller -> localhost | |    E=.+.=.o .   |
2026-02-19 02:33:48.043175 | controller -> localhost | |    . .o= = . . .|
2026-02-19 02:33:48.043212 | controller -> localhost | |      . S+ o . ..|
2026-02-19 02:33:48.043248 | controller -> localhost | |          . . +. |
2026-02-19 02:33:48.043284 | controller -> localhost | |           . +.+ |
2026-02-19 02:33:48.043321 | controller -> localhost | |            . o.o|
2026-02-19 02:33:48.043360 | controller -> localhost | |             ..oo|
2026-02-19 02:33:48.043397 | controller -> localhost | +----[SHA256]-----+
2026-02-19 02:33:48.043472 | controller -> localhost | ok: Runtime: 0:00:00.441966
2026-02-19 02:33:48.049330 | 
2026-02-19 02:33:48.049418 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-19 02:33:48.082925 | controller | ok
2026-02-19 02:33:48.092919 | controller | included: /var/lib/zuul/builds/de38641e2b224377a7d930c1a1afe872/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-19 02:33:48.099336 | 
2026-02-19 02:33:48.099393 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-19 02:33:48.124828 | controller | skipping: Conditional result was False
2026-02-19 02:33:48.133188 | 
2026-02-19 02:33:48.133283 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-19 02:33:48.562826 | controller | changed
2026-02-19 02:33:48.568394 | 
2026-02-19 02:33:48.568464 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-19 02:33:48.773968 | controller | ok
2026-02-19 02:33:48.778854 | 
2026-02-19 02:33:48.778920 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-19 02:33:49.430321 | controller | changed
2026-02-19 02:33:49.434607 | 
2026-02-19 02:33:49.434676 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-19 02:33:50.079815 | controller | changed
2026-02-19 02:33:50.086126 | 
2026-02-19 02:33:50.086226 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-19 02:33:50.112767 | controller | skipping: Conditional result was False
2026-02-19 02:33:50.121477 | 
2026-02-19 02:33:50.121573 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-19 02:33:50.463059 | controller -> localhost | changed
2026-02-19 02:33:50.477568 | 
2026-02-19 02:33:50.477637 | TASK [add-build-sshkey : Add back temp key]
2026-02-19 02:33:50.752922 | controller -> localhost | Identity added: /var/lib/zuul/builds/de38641e2b224377a7d930c1a1afe872/work/de38641e2b224377a7d930c1a1afe872_id_rsa (zuul-build-sshkey)
2026-02-19 02:33:50.753351 | controller -> localhost | ok: Runtime: 0:00:00.014219
2026-02-19 02:33:50.759152 | 
2026-02-19 02:33:50.759246 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-19 02:33:51.110780 | controller | ok
2026-02-19 02:33:51.115018 | 
2026-02-19 02:33:51.115088 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-19 02:33:51.141301 | controller | skipping: Conditional result was False
2026-02-19 02:33:51.154832 | 
2026-02-19 02:33:51.154922 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-02-19 02:33:51.491383 | controller | ok
2026-02-19 02:33:51.497788 | 
2026-02-19 02:33:51.497880 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-02-19 02:34:12.194143 | controller | Output suppressed because no_log was given
2026-02-19 02:34:12.203520 | 
2026-02-19 02:34:12.203604 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-02-19 02:34:12.422777 | controller | ok: "logs"
2026-02-19 02:34:12.423126 | controller | ok: All items complete
2026-02-19 02:34:12.423167 | 
2026-02-19 02:34:12.607212 | controller | ok: "artifacts"
2026-02-19 02:34:12.792750 | controller | ok: "docs"
2026-02-19 02:34:12.809366 | 
2026-02-19 02:34:12.809539 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-02-19 02:34:13.038331 | controller | changed: "logs"
2026-02-19 02:34:13.225614 | controller | changed: "artifacts"
2026-02-19 02:34:13.411524 | controller | changed: "docs"
2026-02-19 02:34:13.429590 | 
2026-02-19 02:34:13.429660 | PLAY RECAP
2026-02-19 02:34:13.429716 | controller | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2026-02-19 02:34:13.429755 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-19 02:34:13.429785 | 
2026-02-19 02:34:13.556284 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-02-19 02:34:13.566726 | PRE-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2026-02-19 02:34:14.195373 | 
2026-02-19 02:34:14.195526 | PLAY [all]
2026-02-19 02:34:14.211578 | 
2026-02-19 02:34:14.211689 | TASK [Fix the permissions of the zuul home directory]
2026-02-19 02:34:14.567508 | controller | changed
2026-02-19 02:34:14.573369 | 
2026-02-19 02:34:14.573443 | TASK [Gather minimum local MTU]
2026-02-19 02:34:14.636077 | controller | ok
2026-02-19 02:34:14.641411 | 
2026-02-19 02:34:14.641474 | TASK [Calculate external_bridge_mtu]
2026-02-19 02:34:14.690996 | controller | ok
2026-02-19 02:34:14.696180 | 
2026-02-19 02:34:14.696269 | TASK [configure-swap : Set ephemeral device if /dev/xvde exists]
2026-02-19 02:34:14.719781 | controller | skipping: Conditional result was False
2026-02-19 02:34:14.729871 | 
2026-02-19 02:34:14.729970 | TASK [configure-swap : Get ephemeral0 device node]
2026-02-19 02:34:15.263028 | controller | ok: Runtime: 0:00:00.006996
2026-02-19 02:34:15.271654 | 
2026-02-19 02:34:15.271722 | TASK [configure-swap : Set ephemeral device if LABEL exists]
2026-02-19 02:34:15.296038 | controller | skipping: Conditional result was False
2026-02-19 02:34:15.305170 | 
2026-02-19 02:34:15.305314 | TASK [configure-swap : Setup swap on ephemeral storage]
2026-02-19 02:34:15.329604 | controller | skipping: Conditional result was False
2026-02-19 02:34:15.339204 | 
2026-02-19 02:34:15.339352 | TASK [configure-swap : Setup swap file on root device]
2026-02-19 02:34:15.390074 | controller | ok
2026-02-19 02:34:15.406986 | controller | included: /var/lib/zuul/builds/de38641e2b224377a7d930c1a1afe872/untrusted/project_1/opendev.org/openstack/openstack-zuul-jobs/roles/configure-swap/tasks/root.yaml
2026-02-19 02:34:15.414539 | 
2026-02-19 02:34:15.418242 | TASK [configure-swap : Calculate required swap]
2026-02-19 02:34:15.480740 | controller | ok
2026-02-19 02:34:15.486508 | 
2026-02-19 02:34:15.486571 | TASK [configure-swap : Get root filesystem]
2026-02-19 02:34:15.172050 | controller | ext4
2026-02-19 02:34:16.014900 | controller | ok: Runtime: 0:00:00.010557
2026-02-19 02:34:16.021401 | 
2026-02-19 02:34:16.021488 | TASK [configure-swap : Save root filesystem]
2026-02-19 02:34:16.052206 | controller | ok
2026-02-19 02:34:16.057188 | 
2026-02-19 02:34:16.057253 | TASK [configure-swap : Debug the root_filesystem variable]
2026-02-19 02:34:16.085798 | controller | ok:
2026-02-19 02:34:16.085940 | controller | {
2026-02-19 02:34:16.085975 | controller |   "root_filesystem": "ext4"
2026-02-19 02:34:16.086002 | controller | }
2026-02-19 02:34:16.090913 | 
2026-02-19 02:34:16.090998 | TASK [configure-swap : Create swap backing file]
2026-02-19 02:34:30.568659 | controller | 4096+0 records in
2026-02-19 02:34:30.568751 | controller | 4096+0 records out
2026-02-19 02:34:30.568767 | controller | 4294967296 bytes (4.3 GB, 4.0 GiB) copied, 14.7168 s, 292 MB/s
2026-02-19 02:34:32.031936 | controller | ok: Runtime: 0:00:14.723069
2026-02-19 02:34:32.067984 | 
2026-02-19 02:34:32.068133 | TASK [configure-swap : Ensure swapfile perms]
2026-02-19 02:34:32.303962 | controller | changed
2026-02-19 02:34:32.309040 | 
2026-02-19 02:34:32.309108 | TASK [configure-swap : Make swapfile]
2026-02-19 02:34:40.740143 | controller | Setting up swapspace version 1, size = 4 GiB (4294963200 bytes)
2026-02-19 02:34:40.740243 | controller | no label, UUID=88ebff9a-250f-45bc-be88-c522f3ac91c0
2026-02-19 02:34:41.344105 | controller | ok: Runtime: 0:00:08.730965
2026-02-19 02:34:41.348299 | 
2026-02-19 02:34:41.348364 | TASK [configure-swap : Write swap to fstab]
2026-02-19 02:34:41.674261 | controller | changed
2026-02-19 02:34:41.679548 | 
2026-02-19 02:34:41.679606 | TASK [configure-swap : Add all swap]
2026-02-19 02:34:42.206632 | controller | ok: Runtime: 0:00:00.011045
2026-02-19 02:34:42.212811 | 
2026-02-19 02:34:42.212901 | TASK [configure-swap : Debug the swap_required variable]
2026-02-19 02:34:42.245339 | controller | ok:
2026-02-19 02:34:42.245568 | controller | {
2026-02-19 02:34:42.245622 | controller |   "swap_required": "4096"
2026-02-19 02:34:42.245665 | controller | }
2026-02-19 02:34:42.250936 | 
2026-02-19 02:34:42.251001 | TASK [configure-swap : Set swappiness]
2026-02-19 02:34:42.577564 | controller | changed
2026-02-19 02:34:42.584744 | 
2026-02-19 02:34:42.584806 | TASK [configure-swap : Debug the ephemeral_device variable]
2026-02-19 02:34:42.618421 | controller | ok:
2026-02-19 02:34:42.618636 | controller | {
2026-02-19 02:34:42.618691 | controller |   "ephemeral_device": "VARIABLE IS NOT DEFINED!: 'ephemeral_device' is undefined. 'ephemeral_device' is undefined"
2026-02-19 02:34:42.618740 | controller | }
2026-02-19 02:34:42.629757 | 
2026-02-19 02:34:42.629841 | TASK [setup-stack-user : Create stack group]
2026-02-19 02:34:43.019572 | controller | changed
2026-02-19 02:34:43.024780 | 
2026-02-19 02:34:43.024843 | TASK [setup-stack-user : Create the stack user home folder]
2026-02-19 02:34:43.261067 | controller | changed
2026-02-19 02:34:43.267288 | 
2026-02-19 02:34:43.267353 | TASK [setup-stack-user : Create stack user]
2026-02-19 02:34:43.819013 | controller | changed
2026-02-19 02:34:43.825321 | 
2026-02-19 02:34:43.825381 | TASK [setup-stack-user : Set stack user home directory permissions and ownership]
2026-02-19 02:34:44.069738 | controller | changed
2026-02-19 02:34:44.076938 | 
2026-02-19 02:34:44.077023 | TASK [setup-stack-user : Copy 50_stack_sh file to /etc/sudoers.d]
2026-02-19 02:34:45.191380 | controller | changed
2026-02-19 02:34:45.197153 | 
2026-02-19 02:34:45.197228 | TASK [setup-stack-user : Create .cache folder within BASE]
2026-02-19 02:34:45.436056 | controller | changed
2026-02-19 02:34:45.446477 | 
2026-02-19 02:34:45.446542 | TASK [setup-tempest-user : Create tempest group]
2026-02-19 02:34:45.730034 | controller | changed
2026-02-19 02:34:45.735361 | 
2026-02-19 02:34:45.735446 | TASK [setup-tempest-user : Create tempest user]
2026-02-19 02:34:46.110505 | controller | changed
2026-02-19 02:34:46.115472 | 
2026-02-19 02:34:46.115549 | TASK [setup-tempest-user : Copy 51_tempest_sh to /etc/sudoers.d]
2026-02-19 02:34:46.979333 | controller | changed
2026-02-19 02:34:46.986316 | 
2026-02-19 02:34:46.986376 | TASK [setup-devstack-source-dirs : Find all OpenStack source repos used by this job]
2026-02-19 02:34:47.337581 | controller | ok: Not all paths examined, check warnings for details
2026-02-19 02:34:47.346656 | 
2026-02-19 02:34:47.346720 | LOOP [setup-devstack-source-dirs : Copy Zuul repos into devstack working directory]
2026-02-19 02:34:47.954148 | controller | ok: Item: Runtime: 0:00:00.333294
2026-02-19 02:34:49.360393 | controller | ok: Item: Runtime: 0:00:01.191289
2026-02-19 02:34:49.805622 | controller | ok: Item: Runtime: 0:00:00.228986
2026-02-19 02:34:50.166597 | controller | ok: Item: Runtime: 0:00:00.118209
2026-02-19 02:34:50.816420 | controller | ok: Item: Runtime: 0:00:00.426486
2026-02-19 02:34:51.125868 | controller | ok: Item: Runtime: 0:00:00.085734
2026-02-19 02:34:51.660396 | controller | ok: Item: Runtime: 0:00:00.304377
2026-02-19 02:34:52.025619 | controller | ok: Item: Runtime: 0:00:00.155353
2026-02-19 02:34:52.733614 | controller | ok: Item: Runtime: 0:00:00.495744
2026-02-19 02:34:53.088175 | controller | ok: Item: Runtime: 0:00:00.133682
2026-02-19 02:34:53.360278 | controller | ok: Item: Runtime: 0:00:00.053088
2026-02-19 02:34:56.908281 | controller | ok: Item: Runtime: 0:00:03.334390
2026-02-19 02:34:57.672631 | controller | ok: Item: Runtime: 0:00:00.548966
2026-02-19 02:34:59.104551 | controller | ok: Item: Runtime: 0:00:01.213298
2026-02-19 02:34:59.129896 | 
2026-02-19 02:34:59.130087 | TASK [setup-devstack-source-dirs : Find top level github projects]
2026-02-19 02:34:59.334950 | controller | ok: All paths examined
2026-02-19 02:34:59.340930 | 
2026-02-19 02:34:59.341025 | TASK [setup-devstack-source-dirs : Find actual github repos]
2026-02-19 02:34:59.577188 | controller | ok: All paths examined
2026-02-19 02:34:59.583562 | 
2026-02-19 02:34:59.583643 | LOOP [setup-devstack-source-dirs : Copy github repos into devstack working directory]
2026-02-19 02:35:01.161707 | controller | ok: Item: Runtime: 0:00:01.314930
2026-02-19 02:35:01.161948 | controller | changed: All items complete
2026-02-19 02:35:01.161976 | 
2026-02-19 02:35:01.492947 | controller | ok: Item: Runtime: 0:00:00.119702
2026-02-19 02:35:01.512477 | 
2026-02-19 02:35:01.512704 | LOOP [setup-devstack-source-dirs : Setup refspec for repos into devstack working directory]
2026-02-19 02:35:01.552666 | controller | skipping: Conditional result was False
2026-02-19 02:35:01.555725 | controller | skipping: Conditional result was False
2026-02-19 02:35:01.559645 | controller | skipping: Conditional result was False
2026-02-19 02:35:01.563793 | controller | skipping: Conditional result was False
2026-02-19 02:35:01.568530 | controller | skipping: Conditional result was False
2026-02-19 02:35:01.571993 | controller | skipping: Conditional result was False
2026-02-19 02:35:01.575580 | controller | skipping: Conditional result was False
2026-02-19 02:35:01.579143 | controller | skipping: Conditional result was False
2026-02-19 02:35:01.582643 | controller | skipping: Conditional result was False
2026-02-19 02:35:01.586098 | controller | skipping: Conditional result was False
2026-02-19 02:35:01.589725 | controller | skipping: Conditional result was False
2026-02-19 02:35:01.593116 | controller | skipping: Conditional result was False
2026-02-19 02:35:01.596280 | controller | skipping: Conditional result was False
2026-02-19 02:35:01.599938 | controller | skipping: Conditional result was False
2026-02-19 02:35:01.629064 | 
2026-02-19 02:35:01.629186 | TASK [setup-devstack-source-dirs : Set ownership of repos]
2026-02-19 02:35:13.090740 | controller | changed
2026-02-19 02:35:13.100763 | 
2026-02-19 02:35:13.100851 | TASK [setup-devstack-log-dir : Create logs directory]
2026-02-19 02:35:13.336611 | controller | changed
2026-02-19 02:35:13.401994 | 
2026-02-19 02:35:13.402138 | TASK [setup-devstack-cache : Copy cached devstack files]
2026-02-19 02:35:13.105375 | controller | find: ‘/opt/cache/files’: No such file or directory
2026-02-19 02:35:13.930147 | controller | ERROR
2026-02-19 02:35:13.930391 | controller | {
2026-02-19 02:35:13.930420 | controller |   "delta": "0:00:00.007569",
2026-02-19 02:35:13.930439 | controller |   "end": "2026-02-19 02:35:13.105703",
2026-02-19 02:35:13.930457 | controller |   "msg": "non-zero return code",
2026-02-19 02:35:13.930475 | controller |   "rc": 1,
2026-02-19 02:35:13.930492 | controller |   "start": "2026-02-19 02:35:13.098134"
2026-02-19 02:35:13.930508 | controller | }
2026-02-19 02:35:13.930531 | controller | ERROR: Ignoring Errors
2026-02-19 02:35:13.934728 | 
2026-02-19 02:35:13.934794 | TASK [setup-devstack-cache : Set ownership of cached files]
2026-02-19 02:35:14.201287 | controller | ok
2026-02-19 02:35:14.209794 | 
2026-02-19 02:35:14.209858 | TASK [start-fresh-logging : Check for /bin/journalctl file]
2026-02-19 02:35:13.908258 | controller | /usr/bin/journalctl
2026-02-19 02:35:14.741097 | controller | ok: Runtime: 0:00:00.006027
2026-02-19 02:35:14.746569 | 
2026-02-19 02:35:14.746630 | TASK [start-fresh-logging : Get current date]
2026-02-19 02:35:14.447787 | controller | 2026-02-19 02:35:14
2026-02-19 02:35:15.274348 | controller | ok: Runtime: 0:00:00.006696
2026-02-19 02:35:15.279887 | 
2026-02-19 02:35:15.279951 | TASK [start-fresh-logging : Copy current date to log-start-timestamp.txt]
2026-02-19 02:35:15.930025 | controller | changed
2026-02-19 02:35:15.936932 | 
2026-02-19 02:35:15.937080 | TASK [start-fresh-logging : Stop rsyslog]
2026-02-19 02:35:15.962744 | controller | skipping: Conditional result was False
2026-02-19 02:35:15.972444 | 
2026-02-19 02:35:15.972588 | TASK [start-fresh-logging : Save syslog file prior to devstack run]
2026-02-19 02:35:16.498088 | controller | skipping: Conditional result was False
2026-02-19 02:35:16.507585 | 
2026-02-19 02:35:16.507656 | TASK [start-fresh-logging : Save kern.log file prior to devstack run]
2026-02-19 02:35:17.031753 | controller | skipping: Conditional result was False
2026-02-19 02:35:17.040625 | 
2026-02-19 02:35:17.040717 | TASK [start-fresh-logging : Recreate syslog file]
2026-02-19 02:35:17.066308 | controller | skipping: Conditional result was False
2026-02-19 02:35:17.075474 | 
2026-02-19 02:35:17.075608 | TASK [start-fresh-logging : Recreate syslog file owner and group]
2026-02-19 02:35:17.599602 | controller | skipping: Conditional result was False
2026-02-19 02:35:17.608258 | 
2026-02-19 02:35:17.608325 | TASK [start-fresh-logging : Recreate syslog file permissions]
2026-02-19 02:35:18.130840 | controller | skipping: Conditional result was False
2026-02-19 02:35:18.140403 | 
2026-02-19 02:35:18.140540 | TASK [start-fresh-logging : Add read permissions to all on syslog file]
2026-02-19 02:35:18.165271 | controller | skipping: Conditional result was False
2026-02-19 02:35:18.174675 | 
2026-02-19 02:35:18.174805 | TASK [start-fresh-logging : Recreate kern.log file]
2026-02-19 02:35:18.200705 | controller | skipping: Conditional result was False
2026-02-19 02:35:18.208893 | 
2026-02-19 02:35:18.209019 | TASK [start-fresh-logging : Recreate kern.log file owner and group]
2026-02-19 02:35:18.735433 | controller | skipping: Conditional result was False
2026-02-19 02:35:18.744706 | 
2026-02-19 02:35:18.744799 | TASK [start-fresh-logging : Recreate kern.log file permissions]
2026-02-19 02:35:19.272739 | controller | skipping: Conditional result was False
2026-02-19 02:35:19.282866 | 
2026-02-19 02:35:19.283001 | TASK [start-fresh-logging : Add read permissions to all on kern.log file]
2026-02-19 02:35:19.298977 | controller | skipping: Conditional result was False
2026-02-19 02:35:19.306348 | 
2026-02-19 02:35:19.306445 | TASK [start-fresh-logging : Start rsyslog]
2026-02-19 02:35:19.333309 | controller | skipping: Conditional result was False
2026-02-19 02:35:19.343671 | 
2026-02-19 02:35:19.343761 | TASK [write-devstack-local-conf : Write a job-specific local_conf file]
2026-02-19 02:35:19.832001 | controller | ok
2026-02-19 02:35:19.842780 | 
2026-02-19 02:35:19.842851 | PLAY RECAP
2026-02-19 02:35:19.842918 | controller | ok: 39 changed: 24 unreachable: 0 failed: 0 skipped: 16 rescued: 0 ignored: 1
2026-02-19 02:35:19.842948 | 
2026-02-19 02:35:20.005008 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2026-02-19 02:35:20.016591 | PRE-RUN START: [untrusted : opendev.org/openstack/manila-tempest-plugin/playbooks/enable-fips.yaml@master]
2026-02-19 02:35:20.620225 | 
2026-02-19 02:35:20.620405 | PLAY [all]
2026-02-19 02:35:20.630487 | 
2026-02-19 02:35:20.630565 | TASK [enable-fips : Make sure this role is run on RHEL/CentOS/Ubuntu systems]
2026-02-19 02:35:20.676171 | controller | skipping: Conditional result was False
2026-02-19 02:35:20.685994 | 
2026-02-19 02:35:20.686075 | TASK [enable-fips : Do tasks for RHEL/Centos systems]
2026-02-19 02:35:20.749213 | controller | ok
2026-02-19 02:35:20.759504 | controller | included: /var/lib/zuul/builds/de38641e2b224377a7d930c1a1afe872/untrusted/project_3/opendev.org/zuul/zuul-jobs/roles/enable-fips/tasks/rhel.yaml
2026-02-19 02:35:20.763958 | 
2026-02-19 02:35:20.764022 | TASK [enable-fips : Install fips-mode-setup]
2026-02-19 02:35:23.950540 | controller | changed
2026-02-19 02:35:23.957594 | 
2026-02-19 02:35:23.957690 | TASK [enable-fips : Enable FIPS mode]
2026-02-19 02:35:23.804035 | controller | *****************************************************************
2026-02-19 02:35:23.804208 | controller | * PRESS CONTROL-C WITHIN 15 SECONDS TO ABORT...                 *
2026-02-19 02:35:23.804231 | controller | *                                                               *
2026-02-19 02:35:23.804241 | controller | * ENABLING FIPS MODE AFTER THE INSTALLATION IS NOT RECOMMENDED. *
2026-02-19 02:35:23.804251 | controller | * THIS OPERATION CANNOT BE UNDONE.                              *
2026-02-19 02:35:23.804259 | controller | * REINSTALL WITH fips=1 INSTEAD.                                *
2026-02-19 02:35:23.804272 | controller | *****************************************************************
2026-02-19 02:35:38.839854 | controller | 15... 14... 13... 12... 11... 10... 9... 8... 7... 6... 5... 4... 3... 2... 1...
2026-02-19 02:35:38.848287 | controller | Kernel initramdisks are being regenerated. This might take some time.
2026-02-19 02:36:06.225395 | controller | Setting system policy to FIPS
2026-02-19 02:36:06.225461 | controller | Note: System-wide crypto policies are applied on application start-up.
2026-02-19 02:36:06.225474 | controller | It is recommended to restart the system for the change of policies
2026-02-19 02:36:06.225484 | controller | to fully take place.
2026-02-19 02:36:06.236609 | controller | FIPS mode will be enabled.
2026-02-19 02:36:06.324583 | controller | Please reboot the system for the setting to take effect.
2026-02-19 02:36:07.051941 | controller | ok: Runtime: 0:00:42.534042
2026-02-19 02:36:07.058299 | 
2026-02-19 02:36:07.058365 | TASK [enable-fips : Check if GRUB_CMDLINE_LINUX_DEFAULT exists in /etc/default/grub]
2026-02-19 02:36:06.745286 | controller | GRUB_CMDLINE_LINUX_DEFAULT="console=tty0 console=ttyS0,115200 no_timer_check nofb nomodeset gfxpayload=text"
2026-02-19 02:36:07.587114 | controller | ok: Runtime: 0:00:00.006308
2026-02-19 02:36:07.592753 | 
2026-02-19 02:36:07.592851 | TASK [enable-fips : Add GRUB_CMDLINE_LINUX_DEFAULT in /etc/default/grub]
2026-02-19 02:36:07.619182 | controller | skipping: Conditional result was False
2026-02-19 02:36:07.627529 | 
2026-02-19 02:36:07.627599 | TASK [enable-fips : Replace GRUB_CMDLINE_LINUX_DEFAULT in /etc/default/grub]
2026-02-19 02:36:07.995169 | controller | changed: line replaced
2026-02-19 02:36:07.999602 | 
2026-02-19 02:36:07.999675 | TASK [enable-fips : Rebuild grub.cfg file]
2026-02-19 02:36:08.060203 | controller | Generating grub configuration file ...
2026-02-19 02:36:09.498325 | controller | Adding boot menu entry for UEFI Firmware Settings ...
2026-02-19 02:36:09.519199 | controller | done
2026-02-19 02:36:10.537403 | controller | ok: Runtime: 0:00:01.826788
2026-02-19 02:36:10.544305 | 
2026-02-19 02:36:10.544368 | TASK [enable-fips : Reboot server for FIPS mode]
2026-02-19 02:36:28.901804 | controller | changed
2026-02-19 02:36:28.907436 | 
2026-02-19 02:36:28.907542 | TASK [Run post-boot tasks]
2026-02-19 02:36:28.929910 | controller | ok
2026-02-19 02:36:28.948637 | 
2026-02-19 02:36:28.948702 | TASK [post-reboot-tasks : Check if node is available for ssh]
2026-02-19 02:36:29.629207 | controller | ok
2026-02-19 02:36:29.634255 | 
2026-02-19 02:36:29.634339 | TASK [Run start-zuul-console role]
2026-02-19 02:36:29.656565 | controller | ok
2026-02-19 02:36:29.671609 | 
2026-02-19 02:36:29.671671 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-02-19 02:36:30.049094 | controller | ok
2026-02-19 02:36:30.098131 | 
2026-02-19 02:36:30.098296 | TASK [post-reboot-tasks : Confirm that dns is up]
2026-02-19 02:36:30.641050 | controller | ERROR
2026-02-19 02:36:30.641499 | controller | {
2026-02-19 02:36:30.641558 | controller |   "msg": "[Errno 2] No such file or directory: b'nslookup'",
2026-02-19 02:36:30.641588 | controller |   "rc": 2
2026-02-19 02:36:30.641616 | controller | }
failure
2026-02-19 02:36:30.643198 | 
2026-02-19 02:36:30.643260 | PLAY RECAP
2026-02-19 02:36:30.643330 | controller | ok: 9 changed: 6 unreachable: 0 failed: 1 skipped: 2 rescued: 0 ignored: 0
2026-02-19 02:36:30.643361 | 
2026-02-19 02:36:30.759800 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/manila-tempest-plugin/playbooks/enable-fips.yaml@master]
2026-02-19 02:36:30.767264 | POST-RUN START: [untrusted : opendev.org/openstack/tempest/playbooks/post-tempest.yaml@master]
2026-02-19 02:36:31.361632 | 
2026-02-19 02:36:31.361771 | PLAY [tempest]
2026-02-19 02:36:31.374419 | 
2026-02-19 02:36:31.374493 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-02-19 02:36:31.953893 | controller | changed: non-zero return code
2026-02-19 02:36:31.960452 | 
2026-02-19 02:36:31.960528 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-02-19 02:36:31.985289 | controller | skipping: Conditional result was False
2026-02-19 02:36:31.992608 | 
2026-02-19 02:36:31.992700 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-02-19 02:36:32.025232 | 
2026-02-19 02:36:32.025383 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-02-19 02:36:32.058314 | 
2026-02-19 02:36:32.058553 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-02-19 02:36:32.082752 | controller | skipping: Conditional result was False
2026-02-19 02:36:32.091075 | 
2026-02-19 02:36:32.091143 | LOOP [fetch-subunit-output : Generate subunit file]
2026-02-19 02:36:32.126307 | 
2026-02-19 02:36:32.126547 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-02-19 02:36:32.150823 | controller | skipping: Conditional result was False
2026-02-19 02:36:32.158897 | 
2026-02-19 02:36:32.158985 | TASK [fetch-subunit-output : Remove the temporary file]
2026-02-19 02:36:32.183662 | controller | skipping: Conditional result was False
2026-02-19 02:36:32.191638 | 
2026-02-19 02:36:32.191727 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-02-19 02:36:32.216366 | controller | skipping: Conditional result was False
2026-02-19 02:36:32.228098 | 
2026-02-19 02:36:32.228180 | TASK [process-stackviz : Devstack checks if stackviz archive exists]
2026-02-19 02:36:32.623618 | controller | ok
2026-02-19 02:36:32.629270 | 
2026-02-19 02:36:32.629358 | TASK [process-stackviz : debug]
2026-02-19 02:36:32.661558 | Stackviz archive could not be found in /opt/cache/files/stackviz-latest.tar.gz
2026-02-19 02:36:32.665695 | 
2026-02-19 02:36:32.665757 | TASK [process-stackviz : Check if subunit data exists]
2026-02-19 02:36:32.943794 | controller | ok
2026-02-19 02:36:32.948752 | 
2026-02-19 02:36:32.948821 | TASK [process-stackviz : debug]
2026-02-19 02:36:32.989764 | Subunit file could not be found at /opt/stack/tempest/testrepository.subunit
2026-02-19 02:36:32.994481 | 
2026-02-19 02:36:32.994546 | TASK [include_role : ensure-pip]
2026-02-19 02:36:33.019830 | controller | skipping: Conditional result was False
2026-02-19 02:36:33.028826 | 
2026-02-19 02:36:33.028896 | TASK [process-stackviz : pip]
2026-02-19 02:36:33.054091 | controller | skipping: Conditional result was False
2026-02-19 02:36:33.064051 | 
2026-02-19 02:36:33.064114 | TASK [process-stackviz : Deploy stackviz static html+js]
2026-02-19 02:36:33.589461 | controller | skipping: Conditional result was False
2026-02-19 02:36:33.599239 | 
2026-02-19 02:36:33.599382 | TASK [process-stackviz : Check if dstat data exists]
2026-02-19 02:36:33.624604 | controller | skipping: Conditional result was False
2026-02-19 02:36:33.632922 | 
2026-02-19 02:36:33.633089 | TASK [process-stackviz : Run stackviz with dstat]
2026-02-19 02:36:34.157338 | controller | skipping: Conditional result was False
2026-02-19 02:36:34.165020 | 
2026-02-19 02:36:34.165086 | TASK [process-stackviz : Run stackviz without dstat]
2026-02-19 02:36:34.691903 | controller | skipping: Conditional result was False
2026-02-19 02:36:34.701077 | 
2026-02-19 02:36:34.701120 | PLAY RECAP
2026-02-19 02:36:34.701164 | controller | ok: 5 changed: 1 unreachable: 0 failed: 0 skipped: 14 rescued: 0 ignored: 0
2026-02-19 02:36:34.701195 | 
2026-02-19 02:36:34.818048 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/tempest/playbooks/post-tempest.yaml@master]
2026-02-19 02:36:34.829709 | POST-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2026-02-19 02:36:35.469882 | 
2026-02-19 02:36:35.470042 | PLAY [all]
2026-02-19 02:36:35.487539 | 
2026-02-19 02:36:35.487624 | TASK [export-devstack-journal : Ensure /home/zuul/logs exists]
2026-02-19 02:36:36.168128 | controller | changed
2026-02-19 02:36:36.172718 | 
2026-02-19 02:36:36.172798 | TASK [export-devstack-journal : Export legacy stack screen log files]
2026-02-19 02:36:37.208617 | controller | ok: Runtime: 0:00:00.341295
2026-02-19 02:36:37.214807 | 
2026-02-19 02:36:37.214913 | TASK [export-devstack-journal : Export legacy syslog.txt]
2026-02-19 02:36:37.747391 | controller | ok: Runtime: 0:00:00.059495
2026-02-19 02:36:37.753069 | 
2026-02-19 02:36:37.753140 | TASK [export-devstack-journal : Export journal]
2026-02-19 02:36:38.278366 | controller | ok: Runtime: 0:00:00.077561
2026-02-19 02:36:38.284474 | 
2026-02-19 02:36:38.284565 | TASK [export-devstack-journal : Save journal README]
2026-02-19 02:36:39.332348 | controller | changed
2026-02-19 02:36:39.341573 | 
2026-02-19 02:36:39.341649 | TASK [apache-logs-conf : Ensure /home/zuul/apache exists]
2026-02-19 02:36:39.619576 | controller | changed
2026-02-19 02:36:39.625942 | 
2026-02-19 02:36:39.626018 | TASK [apache-logs-conf : Find logs]
2026-02-19 02:36:39.661286 | 
2026-02-19 02:36:39.661444 | LOOP [apache-logs-conf : Dereference files]
2026-02-19 02:36:39.695544 | 
2026-02-19 02:36:39.695711 | LOOP [apache-logs-conf : Create hard links]
2026-02-19 02:36:39.726229 | 
2026-02-19 02:36:39.726361 | TASK [apache-logs-conf : Find logs]
2026-02-19 02:36:40.133802 | controller | Output suppressed because no_log was given
2026-02-19 02:36:40.141888 | 
2026-02-19 02:36:40.141975 | LOOP [apache-logs-conf : Dereference files]
2026-02-19 02:36:40.177659 | 
2026-02-19 02:36:40.177789 | LOOP [apache-logs-conf : Create hard links]
2026-02-19 02:36:40.214403 | 
2026-02-19 02:36:40.214662 | TASK [apache-logs-conf : Ensure /home/zuul/apache_config apache_config exists]
2026-02-19 02:36:40.492761 | controller | changed
2026-02-19 02:36:40.501210 | 
2026-02-19 02:36:40.501299 | TASK [apache-logs-conf : Define config paths]
2026-02-19 02:36:40.537058 | controller | ok
2026-02-19 02:36:40.596303 | 
2026-02-19 02:36:40.596468 | TASK [apache-logs-conf : Discover configurations]
2026-02-19 02:36:40.865112 | controller | Output suppressed because no_log was given
2026-02-19 02:36:40.869305 | 
2026-02-19 02:36:40.869371 | LOOP [apache-logs-conf : Dereference configurations]
2026-02-19 02:36:40.903212 | 
2026-02-19 02:36:40.903370 | LOOP [apache-logs-conf : Link configurations]
2026-02-19 02:36:40.937331 | 
2026-02-19 02:36:40.937565 | TASK [capture-performance-data : Generate statistics]
2026-02-19 02:36:41.148102 | controller | /opt/stack/devstack//inc/python: line 43: -m: command not found
2026-02-19 02:36:41.159026 | controller | Using python 3.9 to install setuptools
2026-02-19 02:36:41.197271 | controller | /bin/python3.9: No module named pip
2026-02-19 02:36:41.204390 | controller | /bin/bash: line 4: /opt/stack/data/venv/bin/python3: No such file or directory
2026-02-19 02:36:41.971160 | controller | ERROR
2026-02-19 02:36:41.971461 | controller | {
2026-02-19 02:36:41.971535 | controller |   "delta": "0:00:00.272824",
2026-02-19 02:36:41.971584 | controller |   "end": "2026-02-19 02:36:41.205603",
2026-02-19 02:36:41.971627 | controller |   "msg": "non-zero return code",
2026-02-19 02:36:41.971676 | controller |   "rc": 127,
2026-02-19 02:36:41.971718 | controller |   "start": "2026-02-19 02:36:40.932779"
2026-02-19 02:36:41.971760 | controller | }
2026-02-19 02:36:41.971817 | controller | ERROR: Ignoring Errors
2026-02-19 02:36:41.983248 | 
2026-02-19 02:36:41.983318 | TASK [devstack-project-conf : Ensure /home/zuul/etc exists]
2026-02-19 02:36:42.257824 | controller | changed
2026-02-19 02:36:42.263355 | 
2026-02-19 02:36:42.263440 | LOOP [devstack-project-conf : Check which projects have a config folder]
2026-02-19 02:36:46.166827 | controller | Output suppressed because no_log was given
2026-02-19 02:36:46.178040 | 
2026-02-19 02:36:46.178109 | LOOP [devstack-project-conf : Copy configuration files]
2026-02-19 02:36:46.213093 | controller | skipping: Conditional result was False
2026-02-19 02:36:46.213584 | 
2026-02-19 02:36:46.215535 | controller | skipping: Conditional result was False
2026-02-19 02:36:46.217686 | controller | skipping: Conditional result was False
2026-02-19 02:36:46.220240 | controller | skipping: Conditional result was False
2026-02-19 02:36:46.223213 | controller | skipping: Conditional result was False
2026-02-19 02:36:46.227045 | controller | skipping: Conditional result was False
2026-02-19 02:36:46.230698 | controller | skipping: Conditional result was False
2026-02-19 02:36:46.234162 | controller | skipping: Conditional result was False
2026-02-19 02:36:46.238955 | controller | skipping: Conditional result was False
2026-02-19 02:36:46.245145 | controller | skipping: Conditional result was False
2026-02-19 02:36:46.249805 | controller | skipping: Conditional result was False
2026-02-19 02:36:46.252862 | controller | skipping: Conditional result was False
2026-02-19 02:36:46.255330 | controller | skipping: Conditional result was False
2026-02-19 02:36:46.257995 | controller | skipping: Conditional result was False
2026-02-19 02:36:46.260891 | controller | skipping: Conditional result was False
2026-02-19 02:36:46.263498 | controller | skipping: Conditional result was False
2026-02-19 02:36:46.290871 | 
2026-02-19 02:36:46.291220 | TASK [devstack-project-conf : Check if openstack has a config folder]
2026-02-19 02:36:46.566214 | controller | ok
2026-02-19 02:36:46.572432 | 
2026-02-19 02:36:46.572496 | TASK [devstack-project-conf : Copy configuration files]
2026-02-19 02:36:47.095384 | controller | skipping: Conditional result was False
2026-02-19 02:36:47.109077 | 
2026-02-19 02:36:47.109162 | TASK [capture-system-logs : Stage various logs and reports]
2026-02-19 02:36:47.121466 | controller | sudo: iptables-save: command not found
2026-02-19 02:36:47.134948 | controller | which: no python2 in (/sbin:/bin:/usr/sbin:/usr/bin:/usr/local/bin/)
2026-02-19 02:36:47.162078 | controller | /bin/python3: No module named pip
2026-02-19 02:36:48.231762 | controller | grep: /home/zuul/apache/*.log: No such file or directory
2026-02-19 02:36:48.640745 | controller | ok: Runtime: 0:00:01.130224
2026-02-19 02:36:48.651561 | 
2026-02-19 02:36:48.651649 | LOOP [stage-output : Register sources]
2026-02-19 02:37:02.521138 | controller | Output suppressed because no_log was given
2026-02-19 02:37:02.534187 | 
2026-02-19 02:37:02.534257 | TASK [stage-output : Check sudo]
2026-02-19 02:37:03.062919 | controller | ok: Runtime: 0:00:00.020194
2026-02-19 02:37:03.068468 | 
2026-02-19 02:37:03.068543 | LOOP [stage-output : Set source and destination for files and folders]
2026-02-19 02:37:03.173833 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.174169 | 
2026-02-19 02:37:03.175612 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.177849 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.180452 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.218595 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.219418 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.222236 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.224829 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.227432 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.230067 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.232576 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.235208 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.238149 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.240736 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.243379 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.245923 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.248594 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.251028 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.267807 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.268398 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.268875 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.270976 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.273591 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.276135 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.278595 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.281234 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.283921 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.317811 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.348376 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.401418 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.434032 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.434999 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.437608 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.441322 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.455218 | controller | Output suppressed because no_log was given
2026-02-19 02:37:03.467521 | 
2026-02-19 02:37:03.467613 | TASK [stage-output : Build a list of source, dest dictionaries]
2026-02-19 02:37:03.531397 | controller | ok
2026-02-19 02:37:03.539286 | 
2026-02-19 02:37:03.539373 | LOOP [stage-output : Ensure target folders exist]
2026-02-19 02:37:03.826455 | controller | changed: "docs"
2026-02-19 02:37:04.082431 | controller | changed: "artifacts"
2026-02-19 02:37:04.339127 | controller | ok: "logs"
2026-02-19 02:37:04.352945 | 
2026-02-19 02:37:04.353129 | LOOP [stage-output : Copy files and folders to staging folder]
2026-02-19 02:37:04.652844 | controller | ok: Item: Runtime: 0:00:00.005234
2026-02-19 02:37:04.653152 | controller | changed: All items complete
2026-02-19 02:37:04.653181 | 
2026-02-19 02:37:04.912876 | controller | ok: Item: Runtime: 0:00:00.004974
2026-02-19 02:37:05.163776 | controller | ok: Item: Runtime: 0:00:00.005528
2026-02-19 02:37:05.421513 | controller | ok: Item: Runtime: 0:00:00.005240
2026-02-19 02:37:05.677528 | controller | ok: Item: Runtime: 0:00:00.005131
2026-02-19 02:37:05.939281 | controller | ok: Item: Runtime: 0:00:00.005481
2026-02-19 02:37:06.200194 | controller | ok: Item: Runtime: 0:00:00.005119
2026-02-19 02:37:06.450824 | controller | ok: Item: Runtime: 0:00:00.005060
2026-02-19 02:37:06.709203 | controller | ok: Item: Runtime: 0:00:00.004662
2026-02-19 02:37:06.963233 | controller | ok: Item: Runtime: 0:00:00.005080
2026-02-19 02:37:07.221995 | controller | ok: Item: Runtime: 0:00:00.005105
2026-02-19 02:37:07.473324 | controller | ok: Item: Runtime: 0:00:00.004822
2026-02-19 02:37:07.729407 | controller | ok: Item: Runtime: 0:00:00.004924
2026-02-19 02:37:07.985005 | controller | ok: Item: Runtime: 0:00:00.004632
2026-02-19 02:37:08.246075 | controller | ok: Item: Runtime: 0:00:00.004655
2026-02-19 02:37:08.500424 | controller | ok: Item: Runtime: 0:00:00.004752
2026-02-19 02:37:08.756283 | controller | ok: Item: Runtime: 0:00:00.004782
2026-02-19 02:37:08.780478 | 
2026-02-19 02:37:08.780641 | TASK [stage-output : Make all log files readable]
2026-02-19 02:37:09.066320 | controller | changed
2026-02-19 02:37:09.072663 | 
2026-02-19 02:37:09.072731 | TASK [stage-output : Rename log files that match extensions_to_txt]
2026-02-19 02:37:09.489448 | controller | changed: Renamed files for staging.
2026-02-19 02:37:09.495077 | 
2026-02-19 02:37:09.495137 | TASK [stage-output : Discover log files for compression]
2026-02-19 02:37:09.519563 | controller | skipping: Conditional result was False
2026-02-19 02:37:09.530003 | 
2026-02-19 02:37:09.530071 | LOOP [stage-output : Archive everything from logs]
2026-02-19 02:37:09.569566 | 
2026-02-19 02:37:09.569724 | TASK [fetch-devstack-log-dir : Collect devstack logs]
2026-02-19 02:37:10.322557 | controller | changed:
2026-02-19 02:37:10.322848 | controller | created directory /var/lib/zuul/builds/de38641e2b224377a7d930c1a1afe872/work/logs/controller
2026-02-19 02:37:10.322886 | controller | cd+++++++++ logs/
2026-02-19 02:37:10.322916 | controller | >f+++++++++ logs/audit_log.txt
2026-02-19 02:37:10.322943 | controller | >f+++++++++ logs/deprecations_log.txt
2026-02-19 02:37:10.322970 | controller | >f+++++++++ logs/devstack.journal.README.txt
2026-02-19 02:37:10.322997 | controller | >f+++++++++ logs/devstack.journal.gz
2026-02-19 02:37:10.323023 | controller | >f+++++++++ logs/df.txt
2026-02-19 02:37:10.323049 | controller | >f+++++++++ logs/iptables.txt
2026-02-19 02:37:10.323080 | controller | >f+++++++++ logs/listen53.txt
2026-02-19 02:37:10.323107 | controller | >f+++++++++ logs/local_conf.txt
2026-02-19 02:37:10.323133 | controller | >f+++++++++ logs/mount.txt
2026-02-19 02:37:10.323159 | controller | >f+++++++++ logs/performance.json
2026-02-19 02:37:10.323185 | controller | >f+++++++++ logs/pip3-freeze.txt
2026-02-19 02:37:10.323210 | controller | >f+++++++++ logs/resolv_conf.txt
2026-02-19 02:37:10.323236 | controller | >f+++++++++ logs/rpm-qa.txt
2026-02-19 02:37:10.323261 | controller | >f+++++++++ logs/services.txt
2026-02-19 02:37:10.323286 | controller | >f+++++++++ logs/sudoers
2026-02-19 02:37:10.323312 | controller | >f+++++++++ logs/syslog.txt
2026-02-19 02:37:10.323337 | controller | cd+++++++++ logs/apache/
2026-02-19 02:37:10.323362 | controller | cd+++++++++ logs/apache_config/
2026-02-19 02:37:10.323387 | controller | cd+++++++++ logs/etc/
2026-02-19 02:37:10.323412 | controller | cd+++++++++ logs/sudoers.d/
2026-02-19 02:37:10.323438 | controller | >f+++++++++ logs/sudoers.d/50_stack_sh
2026-02-19 02:37:10.323463 | controller | >f+++++++++ logs/sudoers.d/51_tempest_sh
2026-02-19 02:37:10.323489 | controller | >f+++++++++ logs/sudoers.d/90-cloud-init-users
2026-02-19 02:37:10.323514 | controller | >f+++++++++ logs/sudoers.d/zuul
2026-02-19 02:37:10.333416 | 
2026-02-19 02:37:10.333497 | TASK [Check if a tempest log exits]
2026-02-19 02:37:10.619365 | controller | ok
2026-02-19 02:37:10.626521 | 
2026-02-19 02:37:10.626584 | TASK [Link post-devstack tempest.log]
2026-02-19 02:37:10.651030 | controller | skipping: Conditional result was False
2026-02-19 02:37:10.660500 | 
2026-02-19 02:37:10.660739 | TASK [Capture most recent qemu crash dump, if any]
2026-02-19 02:37:10.716196 | controller | No match found.
2026-02-19 02:37:11.193805 | controller | ERROR
2026-02-19 02:37:11.194027 | controller | {
2026-02-19 02:37:11.194066 | controller |   "delta": "0:00:00.051454",
2026-02-19 02:37:11.194095 | controller |   "end": "2026-02-19 02:37:10.716753",
2026-02-19 02:37:11.194121 | controller |   "msg": "non-zero return code",
2026-02-19 02:37:11.194146 | controller |   "rc": 1,
2026-02-19 02:37:11.194171 | controller |   "start": "2026-02-19 02:37:10.665299"
2026-02-19 02:37:11.194195 | controller | }
2026-02-19 02:37:11.194227 | controller | ERROR: Ignoring Errors
2026-02-19 02:37:11.196117 | 
2026-02-19 02:37:11.196181 | PLAY RECAP
2026-02-19 02:37:11.196242 | controller | ok: 26 changed: 17 unreachable: 0 failed: 0 skipped: 12 rescued: 0 ignored: 2
2026-02-19 02:37:11.196272 | 
2026-02-19 02:37:11.346148 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2026-02-19 02:37:11.356219 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-02-19 02:37:11.945184 | 
2026-02-19 02:37:11.945304 | PLAY [all]
2026-02-19 02:37:11.955492 | 
2026-02-19 02:37:11.955564 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-19 02:37:12.000597 | controller | skipping: Conditional result was False
2026-02-19 02:37:12.009496 | 
2026-02-19 02:37:12.009663 | TASK [fetch-output : Set log path for single node]
2026-02-19 02:37:12.052328 | controller | ok
2026-02-19 02:37:12.058834 | 
2026-02-19 02:37:12.058900 | LOOP [fetch-output : Ensure local output dirs]
2026-02-19 02:37:12.424239 | controller -> localhost | ok: "/var/lib/zuul/builds/de38641e2b224377a7d930c1a1afe872/work/logs"
2026-02-19 02:37:12.641368 | controller -> localhost | changed: "/var/lib/zuul/builds/de38641e2b224377a7d930c1a1afe872/work/artifacts"
2026-02-19 02:37:12.844017 | controller -> localhost | changed: "/var/lib/zuul/builds/de38641e2b224377a7d930c1a1afe872/work/docs"
2026-02-19 02:37:12.859646 | 
2026-02-19 02:37:12.859819 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-19 02:37:13.588063 | controller | changed: .d..t...... ./
2026-02-19 02:37:13.588348 | controller | changed: All items complete
2026-02-19 02:37:13.588385 | 
2026-02-19 02:37:14.136271 | controller | changed: .d..t...... ./
2026-02-19 02:37:14.685524 | controller | changed: .d..t...... ./
2026-02-19 02:37:14.710007 | 
2026-02-19 02:37:14.710214 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-02-19 02:37:15.135085 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007592
2026-02-19 02:37:15.378005 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.006059
2026-02-19 02:37:15.391770 | 
2026-02-19 02:37:15.391903 | PLAY [all]
2026-02-19 02:37:15.397048 | 
2026-02-19 02:37:15.397131 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-02-19 02:37:16.134630 | controller | changed
2026-02-19 02:37:16.141318 | 
2026-02-19 02:37:16.141366 | PLAY RECAP
2026-02-19 02:37:16.141412 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-02-19 02:37:16.141434 | 
2026-02-19 02:37:16.259068 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-02-19 02:37:16.271360 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main]
2026-02-19 02:37:16.884082 | 
2026-02-19 02:37:16.884234 | PLAY [localhost]
2026-02-19 02:37:16.894436 | 
2026-02-19 02:37:16.894514 | TASK [Generate Zuul manifest]
2026-02-19 02:37:16.929382 | localhost | ok
2026-02-19 02:37:16.947205 | 
2026-02-19 02:37:16.947299 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-02-19 02:37:17.334780 | localhost | changed
2026-02-19 02:37:17.349000 | 
2026-02-19 02:37:17.349081 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-02-19 02:37:17.381858 | localhost | ok
2026-02-19 02:37:17.392085 | 
2026-02-19 02:37:17.392175 | TASK [Upload logs]
2026-02-19 02:37:17.412467 | localhost | ok
2026-02-19 02:37:17.476059 | 
2026-02-19 02:37:17.476210 | TASK [Set zuul-log-path fact]
2026-02-19 02:37:17.498247 | localhost | ok
2026-02-19 02:37:17.555479 | 
2026-02-19 02:37:17.555674 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-19 02:37:17.583938 | localhost | ok
2026-02-19 02:37:17.590766 | 
2026-02-19 02:37:17.590833 | TASK [upload-logs : Create log directories]
2026-02-19 02:37:17.951458 | localhost | changed
2026-02-19 02:37:17.956645 | 
2026-02-19 02:37:17.956719 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-02-19 02:37:18.323888 | localhost -> localhost | ok: Runtime: 0:00:00.005656
2026-02-19 02:37:18.331170 | 
2026-02-19 02:37:18.331260 | TASK [upload-logs : Upload logs to log server]
2026-02-19 02:37:18.760034 | localhost | Output suppressed because no_log was given
2026-02-19 02:37:18.763933 | 
2026-02-19 02:37:18.764043 | LOOP [upload-logs : Compress console log and json output]
2026-02-19 02:37:18.811538 | localhost | skipping: Conditional result was False
2026-02-19 02:37:18.818488 | localhost | skipping: Conditional result was False
2026-02-19 02:37:18.829378 | 
2026-02-19 02:37:18.829520 | LOOP [upload-logs : Upload compressed console log and json output]
2026-02-19 02:37:18.872112 | localhost | skipping: Conditional result was False
2026-02-19 02:37:18.872459 | 
2026-02-19 02:37:18.876125 | localhost | skipping: Conditional result was False
2026-02-19 02:37:18.886674 | 
2026-02-19 02:37:18.886810 | LOOP [upload-logs : Upload console log and json output]