2026-02-19 02:23:40.752718 | Job console starting
2026-02-19 02:23:40.780665 | Updating git repos
2026-02-19 02:23:43.626702 | Cloning repos into workspace
2026-02-19 02:23:56.573665 | Restoring repo states
2026-02-19 02:23:56.729777 | Merging changes
2026-02-19 02:23:58.395300 | Checking out repos
2026-02-19 02:24:07.994559 | Preparing playbooks
2026-02-19 02:24:20.983353 | Running Ansible setup
2026-02-19 02:24:25.629845 | PRE-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-02-19 02:24:26.288033 | 
2026-02-19 02:24:26.288466 | PLAY [localhost]
2026-02-19 02:24:26.297160 | 
2026-02-19 02:24:26.297232 | TASK [Gathering Facts]
2026-02-19 02:24:27.233754 | localhost | ok
2026-02-19 02:24:27.250240 | 
2026-02-19 02:24:27.250374 | TASK [Setup log path fact]
2026-02-19 02:24:27.271375 | localhost | ok
2026-02-19 02:24:27.288491 | 
2026-02-19 02:24:27.288657 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-19 02:24:27.320433 | localhost | ok
2026-02-19 02:24:27.327856 | 
2026-02-19 02:24:27.327926 | TASK [emit-job-header : Print job information]
2026-02-19 02:24:27.368348 | # Job Information
2026-02-19 02:24:27.368745 | Ansible Version: 2.16.16
2026-02-19 02:24:27.368802 | Job: manila-tempest-plugin-lvm-fips-py311
2026-02-19 02:24:27.368835 | Pipeline: check
2026-02-19 02:24:27.368863 | Executor: 0a8996d2b663
2026-02-19 02:24:27.368892 | Triggered by: https://github.com/vexxhost/manila/pull/1
2026-02-19 02:24:27.368924 | Event ID: d42d6dc0-0d39-11f1-9818-0dbc046261a0
2026-02-19 02:24:27.380906 | 
2026-02-19 02:24:27.541520 | LOOP [emit-job-header : Print node information]
2026-02-19 02:24:27.639363 | localhost | ok:
2026-02-19 02:24:27.639624 | localhost | # Node Information
2026-02-19 02:24:27.639664 | localhost | Inventory Hostname: controller
2026-02-19 02:24:27.639694 | localhost | Hostname: np0000156488
2026-02-19 02:24:27.639722 | localhost | Username: zuul
2026-02-19 02:24:27.639754 | localhost | Distro: CentOS 9
2026-02-19 02:24:27.639781 | localhost | Provider: yul1
2026-02-19 02:24:27.639807 | localhost | Region: ca-ymq-1
2026-02-19 02:24:27.639833 | localhost | Label: centos-9-stream
2026-02-19 02:24:27.639859 | localhost | Product Name: OpenStack Nova
2026-02-19 02:24:27.639885 | localhost | Interface IP: 199.19.213.183
2026-02-19 02:24:27.656269 | 
2026-02-19 02:24:27.656757 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-02-19 02:24:28.166669 | localhost -> localhost | changed
2026-02-19 02:24:28.172106 | 
2026-02-19 02:24:28.172202 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-02-19 02:24:29.197904 | localhost -> localhost | changed
2026-02-19 02:24:29.206593 | 
2026-02-19 02:24:29.206654 | PLAY [all]
2026-02-19 02:24:29.216395 | 
2026-02-19 02:24:29.216465 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-19 02:24:29.515098 | controller -> localhost | ok
2026-02-19 02:24:29.524135 | 
2026-02-19 02:24:29.524223 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-19 02:24:29.556000 | controller | ok
2026-02-19 02:24:29.582858 | controller | included: /var/lib/zuul/builds/4cebc7b81db9434eb093395a987be4d8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-19 02:24:29.591330 | 
2026-02-19 02:24:29.591393 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-19 02:24:30.494176 | controller -> localhost | Generating public/private rsa key pair.
2026-02-19 02:24:30.494392 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/4cebc7b81db9434eb093395a987be4d8/work/4cebc7b81db9434eb093395a987be4d8_id_rsa
2026-02-19 02:24:30.494434 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/4cebc7b81db9434eb093395a987be4d8/work/4cebc7b81db9434eb093395a987be4d8_id_rsa.pub
2026-02-19 02:24:30.494465 | controller -> localhost | The key fingerprint is:
2026-02-19 02:24:30.494497 | controller -> localhost | SHA256:YhkRYKs6wJFDOZnbYtwH6kPm/mJZWJzeapmsTscmiCs zuul-build-sshkey
2026-02-19 02:24:30.494543 | controller -> localhost | The key's randomart image is:
2026-02-19 02:24:30.494574 | controller -> localhost | +---[RSA 3072]----+
2026-02-19 02:24:30.494608 | controller -> localhost | | .+ o.o.         |
2026-02-19 02:24:30.494644 | controller -> localhost | |.=.o . .         |
2026-02-19 02:24:30.494675 | controller -> localhost | |.+B + .          |
2026-02-19 02:24:30.494704 | controller -> localhost | |.OoB . o         |
2026-02-19 02:24:30.494732 | controller -> localhost | |B.* o + S        |
2026-02-19 02:24:30.494760 | controller -> localhost | |+*.o o .         |
2026-02-19 02:24:30.494788 | controller -> localhost | |*o=++            |
2026-02-19 02:24:30.494815 | controller -> localhost | |EB+*             |
2026-02-19 02:24:30.494846 | controller -> localhost | |=o=.             |
2026-02-19 02:24:30.494873 | controller -> localhost | +----[SHA256]-----+
2026-02-19 02:24:30.494923 | controller -> localhost | ok: Runtime: 0:00:00.409683
2026-02-19 02:24:30.498971 | 
2026-02-19 02:24:30.499033 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-19 02:24:30.537392 | controller | ok
2026-02-19 02:24:30.544498 | controller | included: /var/lib/zuul/builds/4cebc7b81db9434eb093395a987be4d8/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-19 02:24:30.557416 | 
2026-02-19 02:24:30.557596 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-19 02:24:30.583393 | controller | skipping: Conditional result was False
2026-02-19 02:24:30.592658 | 
2026-02-19 02:24:30.592763 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-19 02:24:31.081593 | controller | changed
2026-02-19 02:24:31.087619 | 
2026-02-19 02:24:31.087714 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-19 02:24:31.315685 | controller | ok
2026-02-19 02:24:31.410770 | 
2026-02-19 02:24:31.410885 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-19 02:24:32.266271 | controller | changed
2026-02-19 02:24:32.272639 | 
2026-02-19 02:24:32.272721 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-19 02:24:32.975330 | controller | changed
2026-02-19 02:24:32.995958 | 
2026-02-19 02:24:32.996108 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-19 02:24:33.020816 | controller | skipping: Conditional result was False
2026-02-19 02:24:33.043105 | 
2026-02-19 02:24:33.043279 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-19 02:24:33.582897 | controller -> localhost | changed
2026-02-19 02:24:33.599257 | 
2026-02-19 02:24:33.599465 | TASK [add-build-sshkey : Add back temp key]
2026-02-19 02:24:34.070531 | controller -> localhost | Identity added: /var/lib/zuul/builds/4cebc7b81db9434eb093395a987be4d8/work/4cebc7b81db9434eb093395a987be4d8_id_rsa (zuul-build-sshkey)
2026-02-19 02:24:34.478476 | controller -> localhost | ok: Runtime: 0:00:00.021470
2026-02-19 02:24:34.491172 | 
2026-02-19 02:24:34.491273 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-19 02:24:34.869704 | controller | ok
2026-02-19 02:24:34.876364 | 
2026-02-19 02:24:34.876435 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-19 02:24:34.937167 | controller | skipping: Conditional result was False
2026-02-19 02:24:34.946451 | 
2026-02-19 02:24:34.946554 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-02-19 02:24:35.340729 | controller | ok
2026-02-19 02:24:35.345705 | 
2026-02-19 02:24:35.345783 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-02-19 02:25:29.775121 | controller | Output suppressed because no_log was given
2026-02-19 02:25:29.784620 | 
2026-02-19 02:25:29.784872 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-02-19 02:25:30.426298 | controller | ok: "logs"
2026-02-19 02:25:30.426610 | controller | ok: All items complete
2026-02-19 02:25:30.426639 | 
2026-02-19 02:25:30.967424 | controller | ok: "artifacts"
2026-02-19 02:25:32.597069 | controller | ok: "docs"
2026-02-19 02:25:32.612404 | 
2026-02-19 02:25:32.612542 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-02-19 02:25:35.588511 | controller | changed: "logs"
2026-02-19 02:25:35.948575 | controller | changed: "artifacts"
2026-02-19 02:25:36.129035 | controller | changed: "docs"
2026-02-19 02:25:36.143907 | 
2026-02-19 02:25:36.144022 | PLAY RECAP
2026-02-19 02:25:36.144073 | controller | ok: 15 changed: 8 unreachable: 0 failed: 0 skipped: 3 rescued: 0 ignored: 0
2026-02-19 02:25:36.144102 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-19 02:25:36.144124 | 
2026-02-19 02:25:36.322122 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/pre.yaml@main]
2026-02-19 02:25:36.332354 | PRE-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2026-02-19 02:25:36.981706 | 
2026-02-19 02:25:36.981837 | PLAY [all]
2026-02-19 02:25:36.997820 | 
2026-02-19 02:25:36.997894 | TASK [Fix the permissions of the zuul home directory]
2026-02-19 02:25:39.413625 | controller | changed
2026-02-19 02:25:39.419682 | 
2026-02-19 02:25:39.419762 | TASK [Gather minimum local MTU]
2026-02-19 02:25:39.483960 | controller | ok
2026-02-19 02:25:39.490570 | 
2026-02-19 02:25:39.490635 | TASK [Calculate external_bridge_mtu]
2026-02-19 02:25:39.543940 | controller | ok
2026-02-19 02:25:39.549546 | 
2026-02-19 02:25:39.549641 | TASK [configure-swap : Set ephemeral device if /dev/xvde exists]
2026-02-19 02:25:39.573934 | controller | skipping: Conditional result was False
2026-02-19 02:25:39.583894 | 
2026-02-19 02:25:39.584044 | TASK [configure-swap : Get ephemeral0 device node]
2026-02-19 02:25:40.621325 | controller | ok: Runtime: 0:00:00.006164
2026-02-19 02:25:40.626837 | 
2026-02-19 02:25:40.626915 | TASK [configure-swap : Set ephemeral device if LABEL exists]
2026-02-19 02:25:40.655380 | controller | skipping: Conditional result was False
2026-02-19 02:25:40.665746 | 
2026-02-19 02:25:40.665870 | TASK [configure-swap : Setup swap on ephemeral storage]
2026-02-19 02:25:40.693395 | controller | skipping: Conditional result was False
2026-02-19 02:25:40.703178 | 
2026-02-19 02:25:40.703339 | TASK [configure-swap : Setup swap file on root device]
2026-02-19 02:25:40.762168 | controller | ok
2026-02-19 02:25:40.775424 | controller | included: /var/lib/zuul/builds/4cebc7b81db9434eb093395a987be4d8/untrusted/project_1/opendev.org/openstack/openstack-zuul-jobs/roles/configure-swap/tasks/root.yaml
2026-02-19 02:25:40.781414 | 
2026-02-19 02:25:40.781550 | TASK [configure-swap : Calculate required swap]
2026-02-19 02:25:40.838136 | controller | ok
2026-02-19 02:25:40.844854 | 
2026-02-19 02:25:40.845204 | TASK [configure-swap : Get root filesystem]
2026-02-19 02:25:41.155250 | controller | ext4
2026-02-19 02:25:41.907448 | controller | ok: Runtime: 0:00:00.426840
2026-02-19 02:25:41.914362 | 
2026-02-19 02:25:41.914436 | TASK [configure-swap : Save root filesystem]
2026-02-19 02:25:41.949818 | controller | ok
2026-02-19 02:25:41.960227 | 
2026-02-19 02:25:41.960382 | TASK [configure-swap : Debug the root_filesystem variable]
2026-02-19 02:25:41.998239 | controller | ok:
2026-02-19 02:25:41.998430 | controller | {
2026-02-19 02:25:41.998456 | controller |   "root_filesystem": "ext4"
2026-02-19 02:25:41.998475 | controller | }
2026-02-19 02:25:42.002808 | 
2026-02-19 02:25:42.002875 | TASK [configure-swap : Create swap backing file]
2026-02-19 02:26:52.903823 | controller | 4096+0 records in
2026-02-19 02:26:52.903944 | controller | 4096+0 records out
2026-02-19 02:26:52.903958 | controller | 4294967296 bytes (4.3 GB, 4.0 GiB) copied, 70.3879 s, 61.0 MB/s
2026-02-19 02:26:53.563451 | controller | ok: Runtime: 0:01:10.411460
2026-02-19 02:26:53.609743 | 
2026-02-19 02:26:53.609922 | TASK [configure-swap : Ensure swapfile perms]
2026-02-19 02:26:53.856002 | controller | changed
2026-02-19 02:26:53.861998 | 
2026-02-19 02:26:53.862104 | TASK [configure-swap : Make swapfile]
2026-02-19 02:27:28.436745 | controller | Setting up swapspace version 1, size = 4 GiB (4294963200 bytes)
2026-02-19 02:27:28.437609 | controller | no label, UUID=6defaa9a-661f-45aa-9e93-7b48fcdea830
2026-02-19 02:27:29.081560 | controller | ok: Runtime: 0:00:34.676169
2026-02-19 02:27:29.087943 | 
2026-02-19 02:27:29.088018 | TASK [configure-swap : Write swap to fstab]
2026-02-19 02:27:29.423314 | controller | changed
2026-02-19 02:27:29.427416 | 
2026-02-19 02:27:29.427481 | TASK [configure-swap : Add all swap]
2026-02-19 02:27:29.954586 | controller | ok: Runtime: 0:00:00.093329
2026-02-19 02:27:29.960396 | 
2026-02-19 02:27:29.960484 | TASK [configure-swap : Debug the swap_required variable]
2026-02-19 02:27:29.991200 | controller | ok:
2026-02-19 02:27:29.991347 | controller | {
2026-02-19 02:27:29.991382 | controller |   "swap_required": "4096"
2026-02-19 02:27:29.991409 | controller | }
2026-02-19 02:27:29.996337 | 
2026-02-19 02:27:29.996490 | TASK [configure-swap : Set swappiness]
2026-02-19 02:27:30.394298 | controller | changed
2026-02-19 02:27:30.399290 | 
2026-02-19 02:27:30.399356 | TASK [configure-swap : Debug the ephemeral_device variable]
2026-02-19 02:27:30.427961 | controller | ok:
2026-02-19 02:27:30.442993 | controller | {
2026-02-19 02:27:30.443368 | controller |   "ephemeral_device": "VARIABLE IS NOT DEFINED!: 'ephemeral_device' is undefined. 'ephemeral_device' is undefined"
2026-02-19 02:27:30.443440 | controller | }
2026-02-19 02:27:30.455928 | 
2026-02-19 02:27:30.456012 | TASK [setup-stack-user : Create stack group]
2026-02-19 02:27:32.788900 | controller | changed
2026-02-19 02:27:32.794363 | 
2026-02-19 02:27:32.794449 | TASK [setup-stack-user : Create the stack user home folder]
2026-02-19 02:27:33.038163 | controller | changed
2026-02-19 02:27:33.042267 | 
2026-02-19 02:27:33.042327 | TASK [setup-stack-user : Create stack user]
2026-02-19 02:27:37.956825 | controller | changed
2026-02-19 02:27:37.962949 | 
2026-02-19 02:27:37.963042 | TASK [setup-stack-user : Set stack user home directory permissions and ownership]
2026-02-19 02:27:38.206319 | controller | changed
2026-02-19 02:27:38.211417 | 
2026-02-19 02:27:38.211486 | TASK [setup-stack-user : Copy 50_stack_sh file to /etc/sudoers.d]
2026-02-19 02:27:39.424886 | controller | changed
2026-02-19 02:27:39.430535 | 
2026-02-19 02:27:39.430607 | TASK [setup-stack-user : Create .cache folder within BASE]
2026-02-19 02:27:39.667933 | controller | changed
2026-02-19 02:27:39.679482 | 
2026-02-19 02:27:39.679575 | TASK [setup-tempest-user : Create tempest group]
2026-02-19 02:27:42.071655 | controller | changed
2026-02-19 02:27:42.077402 | 
2026-02-19 02:27:42.077516 | TASK [setup-tempest-user : Create tempest user]
2026-02-19 02:27:46.883533 | controller | changed
2026-02-19 02:27:46.889615 | 
2026-02-19 02:27:46.889705 | TASK [setup-tempest-user : Copy 51_tempest_sh to /etc/sudoers.d]
2026-02-19 02:27:47.839595 | controller | changed
2026-02-19 02:27:47.848661 | 
2026-02-19 02:27:47.848725 | TASK [setup-devstack-source-dirs : Find all OpenStack source repos used by this job]
2026-02-19 02:27:48.227222 | controller | ok: Not all paths examined, check warnings for details
2026-02-19 02:27:48.238703 | 
2026-02-19 02:27:48.238783 | LOOP [setup-devstack-source-dirs : Copy Zuul repos into devstack working directory]
2026-02-19 02:27:48.845918 | controller | ok: Item: Runtime: 0:00:00.323734
2026-02-19 02:27:50.162128 | controller | ok: Item: Runtime: 0:00:01.091364
2026-02-19 02:27:50.670130 | controller | ok: Item: Runtime: 0:00:00.241547
2026-02-19 02:27:51.029008 | controller | ok: Item: Runtime: 0:00:00.127342
2026-02-19 02:27:51.703465 | controller | ok: Item: Runtime: 0:00:00.449948
2026-02-19 02:27:52.007223 | controller | ok: Item: Runtime: 0:00:00.083134
2026-02-19 02:27:52.569777 | controller | ok: Item: Runtime: 0:00:00.324230
2026-02-19 02:27:52.949619 | controller | ok: Item: Runtime: 0:00:00.169001
2026-02-19 02:27:53.624485 | controller | ok: Item: Runtime: 0:00:00.466917
2026-02-19 02:27:53.981786 | controller | ok: Item: Runtime: 0:00:00.131143
2026-02-19 02:27:54.256892 | controller | ok: Item: Runtime: 0:00:00.053817
2026-02-19 02:27:59.523535 | controller | ok: Item: Runtime: 0:00:03.448021
2026-02-19 02:28:00.614745 | controller | ok: Item: Runtime: 0:00:00.863631
2026-02-19 02:28:05.619551 | controller | ok: Item: Runtime: 0:00:02.885437
2026-02-19 02:28:05.653434 | 
2026-02-19 02:28:05.653576 | TASK [setup-devstack-source-dirs : Find top level github projects]
2026-02-19 02:28:05.870762 | controller | ok: All paths examined
2026-02-19 02:28:05.877654 | 
2026-02-19 02:28:05.877741 | TASK [setup-devstack-source-dirs : Find actual github repos]
2026-02-19 02:28:06.114554 | controller | ok: All paths examined
2026-02-19 02:28:06.120478 | 
2026-02-19 02:28:06.120547 | LOOP [setup-devstack-source-dirs : Copy github repos into devstack working directory]
2026-02-19 02:29:29.410764 | controller | ok: Item: Runtime: 0:01:23.001752
2026-02-19 02:29:29.410997 | controller | changed: All items complete
2026-02-19 02:29:29.411025 | 
2026-02-19 02:29:31.689960 | controller | ok: Item: Runtime: 0:00:00.133824
2026-02-19 02:29:31.707910 | 
2026-02-19 02:29:31.708295 | LOOP [setup-devstack-source-dirs : Setup refspec for repos into devstack working directory]
2026-02-19 02:29:31.753827 | controller | skipping: Conditional result was False
2026-02-19 02:29:31.756405 | controller | skipping: Conditional result was False
2026-02-19 02:29:31.759959 | controller | skipping: Conditional result was False
2026-02-19 02:29:31.763222 | controller | skipping: Conditional result was False
2026-02-19 02:29:31.767182 | controller | skipping: Conditional result was False
2026-02-19 02:29:31.770952 | controller | skipping: Conditional result was False
2026-02-19 02:29:31.774969 | controller | skipping: Conditional result was False
2026-02-19 02:29:31.778677 | controller | skipping: Conditional result was False
2026-02-19 02:29:31.781809 | controller | skipping: Conditional result was False
2026-02-19 02:29:31.785338 | controller | skipping: Conditional result was False
2026-02-19 02:29:31.789440 | controller | skipping: Conditional result was False
2026-02-19 02:29:31.792944 | controller | skipping: Conditional result was False
2026-02-19 02:29:31.797118 | controller | skipping: Conditional result was False
2026-02-19 02:29:31.800947 | controller | skipping: Conditional result was False
2026-02-19 02:29:31.832456 | 
2026-02-19 02:29:31.832630 | TASK [setup-devstack-source-dirs : Set ownership of repos]
2026-02-19 02:29:43.510409 | controller | changed
2026-02-19 02:29:43.521727 | 
2026-02-19 02:29:43.521798 | TASK [setup-devstack-log-dir : Create logs directory]
2026-02-19 02:29:43.769082 | controller | changed
2026-02-19 02:29:43.829070 | 
2026-02-19 02:29:43.829299 | TASK [setup-devstack-cache : Copy cached devstack files]
2026-02-19 02:29:43.711133 | controller | find: ‘/opt/cache/files’: No such file or directory
2026-02-19 02:29:44.360255 | controller | ERROR
2026-02-19 02:29:44.360562 | controller | {
2026-02-19 02:29:44.360626 | controller |   "delta": "0:00:00.007960",
2026-02-19 02:29:44.360671 | controller |   "end": "2026-02-19 02:29:43.711579",
2026-02-19 02:29:44.360712 | controller |   "msg": "non-zero return code",
2026-02-19 02:29:44.360750 | controller |   "rc": 1,
2026-02-19 02:29:44.360789 | controller |   "start": "2026-02-19 02:29:43.703619"
2026-02-19 02:29:44.360827 | controller | }
2026-02-19 02:29:44.360882 | controller | ERROR: Ignoring Errors
2026-02-19 02:29:44.366570 | 
2026-02-19 02:29:44.366642 | TASK [setup-devstack-cache : Set ownership of cached files]
2026-02-19 02:29:44.635306 | controller | ok
2026-02-19 02:29:44.642825 | 
2026-02-19 02:29:44.642896 | TASK [start-fresh-logging : Check for /bin/journalctl file]
2026-02-19 02:29:44.508328 | controller | /usr/bin/journalctl
2026-02-19 02:29:45.174765 | controller | ok: Runtime: 0:00:00.008932
2026-02-19 02:29:45.180237 | 
2026-02-19 02:29:45.180337 | TASK [start-fresh-logging : Get current date]
2026-02-19 02:29:45.749026 | controller | 2026-02-19 02:29:45
2026-02-19 02:29:46.226118 | controller | ok: Runtime: 0:00:00.672248
2026-02-19 02:29:46.231617 | 
2026-02-19 02:29:46.231705 | TASK [start-fresh-logging : Copy current date to log-start-timestamp.txt]
2026-02-19 02:29:46.932894 | controller | changed
2026-02-19 02:29:46.940433 | 
2026-02-19 02:29:46.940570 | TASK [start-fresh-logging : Stop rsyslog]
2026-02-19 02:29:46.965432 | controller | skipping: Conditional result was False
2026-02-19 02:29:46.973523 | 
2026-02-19 02:29:46.973587 | TASK [start-fresh-logging : Save syslog file prior to devstack run]
2026-02-19 02:29:47.495007 | controller | skipping: Conditional result was False
2026-02-19 02:29:47.503380 | 
2026-02-19 02:29:47.503469 | TASK [start-fresh-logging : Save kern.log file prior to devstack run]
2026-02-19 02:29:48.030817 | controller | skipping: Conditional result was False
2026-02-19 02:29:48.036051 | 
2026-02-19 02:29:48.036122 | TASK [start-fresh-logging : Recreate syslog file]
2026-02-19 02:29:48.059770 | controller | skipping: Conditional result was False
2026-02-19 02:29:48.064050 | 
2026-02-19 02:29:48.064113 | TASK [start-fresh-logging : Recreate syslog file owner and group]
2026-02-19 02:29:48.585768 | controller | skipping: Conditional result was False
2026-02-19 02:29:48.593379 | 
2026-02-19 02:29:48.593469 | TASK [start-fresh-logging : Recreate syslog file permissions]
2026-02-19 02:29:49.116607 | controller | skipping: Conditional result was False
2026-02-19 02:29:49.126091 | 
2026-02-19 02:29:49.126224 | TASK [start-fresh-logging : Add read permissions to all on syslog file]
2026-02-19 02:29:49.150960 | controller | skipping: Conditional result was False
2026-02-19 02:29:49.160740 | 
2026-02-19 02:29:49.160881 | TASK [start-fresh-logging : Recreate kern.log file]
2026-02-19 02:29:49.186789 | controller | skipping: Conditional result was False
2026-02-19 02:29:49.193489 | 
2026-02-19 02:29:49.193575 | TASK [start-fresh-logging : Recreate kern.log file owner and group]
2026-02-19 02:29:49.716275 | controller | skipping: Conditional result was False
2026-02-19 02:29:49.726628 | 
2026-02-19 02:29:49.726750 | TASK [start-fresh-logging : Recreate kern.log file permissions]
2026-02-19 02:29:50.249774 | controller | skipping: Conditional result was False
2026-02-19 02:29:50.257671 | 
2026-02-19 02:29:50.257763 | TASK [start-fresh-logging : Add read permissions to all on kern.log file]
2026-02-19 02:29:50.282287 | controller | skipping: Conditional result was False
2026-02-19 02:29:50.289891 | 
2026-02-19 02:29:50.289983 | TASK [start-fresh-logging : Start rsyslog]
2026-02-19 02:29:50.313026 | controller | skipping: Conditional result was False
2026-02-19 02:29:50.326808 | 
2026-02-19 02:29:50.326899 | TASK [write-devstack-local-conf : Write a job-specific local_conf file]
2026-02-19 02:29:50.749733 | controller | ok
2026-02-19 02:29:50.757647 | 
2026-02-19 02:29:50.757700 | PLAY RECAP
2026-02-19 02:29:50.757747 | controller | ok: 39 changed: 24 unreachable: 0 failed: 0 skipped: 16 rescued: 0 ignored: 1
2026-02-19 02:29:50.757770 | 
2026-02-19 02:29:50.895958 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2026-02-19 02:29:50.905447 | PRE-RUN START: [untrusted : opendev.org/openstack/manila-tempest-plugin/playbooks/enable-fips.yaml@master]
2026-02-19 02:29:51.534216 | 
2026-02-19 02:29:51.534384 | PLAY [all]
2026-02-19 02:29:51.545436 | 
2026-02-19 02:29:51.545512 | TASK [enable-fips : Make sure this role is run on RHEL/CentOS/Ubuntu systems]
2026-02-19 02:29:51.590516 | controller | skipping: Conditional result was False
2026-02-19 02:29:51.600561 | 
2026-02-19 02:29:51.600730 | TASK [enable-fips : Do tasks for RHEL/Centos systems]
2026-02-19 02:29:51.654480 | controller | ok
2026-02-19 02:29:51.665877 | controller | included: /var/lib/zuul/builds/4cebc7b81db9434eb093395a987be4d8/untrusted/project_3/opendev.org/zuul/zuul-jobs/roles/enable-fips/tasks/rhel.yaml
2026-02-19 02:29:51.670276 | 
2026-02-19 02:29:51.670341 | TASK [enable-fips : Install fips-mode-setup]
2026-02-19 02:29:57.548623 | controller | changed
2026-02-19 02:29:57.554799 | 
2026-02-19 02:29:57.554872 | TASK [enable-fips : Enable FIPS mode]
2026-02-19 02:29:57.630980 | controller | *****************************************************************
2026-02-19 02:29:57.631214 | controller | * PRESS CONTROL-C WITHIN 15 SECONDS TO ABORT...                 *
2026-02-19 02:29:57.631232 | controller | *                                                               *
2026-02-19 02:29:57.631242 | controller | * ENABLING FIPS MODE AFTER THE INSTALLATION IS NOT RECOMMENDED. *
2026-02-19 02:29:57.631254 | controller | * THIS OPERATION CANNOT BE UNDONE.                              *
2026-02-19 02:29:57.631263 | controller | * REINSTALL WITH fips=1 INSTEAD.                                *
2026-02-19 02:29:57.631278 | controller | *****************************************************************
2026-02-19 02:30:12.672482 | controller | 15... 14... 13... 12... 11... 10... 9... 8... 7... 6... 5... 4... 3... 2... 1...
2026-02-19 02:30:12.691025 | controller | Kernel initramdisks are being regenerated. This might take some time.
2026-02-19 02:30:56.407826 | controller | Setting system policy to FIPS
2026-02-19 02:30:56.407895 | controller | Note: System-wide crypto policies are applied on application start-up.
2026-02-19 02:30:56.407901 | controller | It is recommended to restart the system for the change of policies
2026-02-19 02:30:56.407906 | controller | to fully take place.
2026-02-19 02:30:56.423469 | controller | FIPS mode will be enabled.
2026-02-19 02:30:56.613442 | controller | Please reboot the system for the setting to take effect.
2026-02-19 02:30:57.183691 | controller | ok: Runtime: 0:00:59.009036
2026-02-19 02:30:57.189656 | 
2026-02-19 02:30:57.189750 | TASK [enable-fips : Check if GRUB_CMDLINE_LINUX_DEFAULT exists in /etc/default/grub]
2026-02-19 02:30:57.080633 | controller | GRUB_CMDLINE_LINUX_DEFAULT="console=tty0 console=ttyS0,115200 no_timer_check nofb nomodeset gfxpayload=text"
2026-02-19 02:30:57.720081 | controller | ok: Runtime: 0:00:00.007387
2026-02-19 02:30:57.726336 | 
2026-02-19 02:30:57.726432 | TASK [enable-fips : Add GRUB_CMDLINE_LINUX_DEFAULT in /etc/default/grub]
2026-02-19 02:30:57.753370 | controller | skipping: Conditional result was False
2026-02-19 02:30:57.760770 | 
2026-02-19 02:30:57.760873 | TASK [enable-fips : Replace GRUB_CMDLINE_LINUX_DEFAULT in /etc/default/grub]
2026-02-19 02:30:58.135474 | controller | changed: line replaced
2026-02-19 02:30:58.139734 | 
2026-02-19 02:30:58.139805 | TASK [enable-fips : Rebuild grub.cfg file]
2026-02-19 02:30:59.162302 | controller | Generating grub configuration file ...
2026-02-19 02:31:01.229393 | controller | Adding boot menu entry for UEFI Firmware Settings ...
2026-02-19 02:31:01.259906 | controller | done
2026-02-19 02:31:01.773876 | controller | ok: Runtime: 0:00:03.241914
2026-02-19 02:31:01.781212 | 
2026-02-19 02:31:01.781304 | TASK [enable-fips : Reboot server for FIPS mode]
2026-02-19 02:31:58.882272 | controller | changed
2026-02-19 02:31:58.890048 | 
2026-02-19 02:31:58.890183 | TASK [Run post-boot tasks]
2026-02-19 02:31:58.911674 | controller | ok
2026-02-19 02:31:58.937011 | 
2026-02-19 02:31:58.937109 | TASK [post-reboot-tasks : Check if node is available for ssh]
2026-02-19 02:31:59.737769 | controller | ok
2026-02-19 02:31:59.743025 | 
2026-02-19 02:31:59.743131 | TASK [Run start-zuul-console role]
2026-02-19 02:31:59.766293 | controller | ok
2026-02-19 02:31:59.783599 | 
2026-02-19 02:31:59.783670 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-02-19 02:32:00.169789 | controller | ok
2026-02-19 02:32:00.221348 | 
2026-02-19 02:32:00.221504 | TASK [post-reboot-tasks : Confirm that dns is up]
2026-02-19 02:32:00.749561 | controller | ERROR
2026-02-19 02:32:00.749856 | controller | {
2026-02-19 02:32:00.749901 | controller |   "msg": "[Errno 2] No such file or directory: b'nslookup'",
2026-02-19 02:32:00.749934 | controller |   "rc": 2
2026-02-19 02:32:00.749961 | controller | }
failure
2026-02-19 02:32:00.751963 | 
2026-02-19 02:32:00.752023 | PLAY RECAP
2026-02-19 02:32:00.752094 | controller | ok: 9 changed: 6 unreachable: 0 failed: 1 skipped: 2 rescued: 0 ignored: 0
2026-02-19 02:32:00.752125 | 
2026-02-19 02:32:00.884153 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/manila-tempest-plugin/playbooks/enable-fips.yaml@master]
2026-02-19 02:32:00.895326 | POST-RUN START: [untrusted : opendev.org/openstack/tempest/playbooks/post-tempest.yaml@master]
2026-02-19 02:32:01.511987 | 
2026-02-19 02:32:01.512128 | PLAY [tempest]
2026-02-19 02:32:01.524905 | 
2026-02-19 02:32:01.524998 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-02-19 02:32:02.136017 | controller | changed: non-zero return code
2026-02-19 02:32:02.140657 | 
2026-02-19 02:32:02.140745 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-02-19 02:32:02.164613 | controller | skipping: Conditional result was False
2026-02-19 02:32:02.172929 | 
2026-02-19 02:32:02.173044 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-02-19 02:32:02.208081 | 
2026-02-19 02:32:02.208248 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-02-19 02:32:02.243239 | 
2026-02-19 02:32:02.243386 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-02-19 02:32:02.269061 | controller | skipping: Conditional result was False
2026-02-19 02:32:02.279127 | 
2026-02-19 02:32:02.279281 | LOOP [fetch-subunit-output : Generate subunit file]
2026-02-19 02:32:02.315265 | 
2026-02-19 02:32:02.315439 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-02-19 02:32:02.340973 | controller | skipping: Conditional result was False
2026-02-19 02:32:02.348789 | 
2026-02-19 02:32:02.348882 | TASK [fetch-subunit-output : Remove the temporary file]
2026-02-19 02:32:02.374500 | controller | skipping: Conditional result was False
2026-02-19 02:32:02.383130 | 
2026-02-19 02:32:02.383200 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-02-19 02:32:02.408865 | controller | skipping: Conditional result was False
2026-02-19 02:32:02.423900 | 
2026-02-19 02:32:02.423964 | TASK [process-stackviz : Devstack checks if stackviz archive exists]
2026-02-19 02:32:02.852041 | controller | ok
2026-02-19 02:32:02.859791 | 
2026-02-19 02:32:02.859866 | TASK [process-stackviz : debug]
2026-02-19 02:32:02.892794 | Stackviz archive could not be found in /opt/cache/files/stackviz-latest.tar.gz
2026-02-19 02:32:02.899919 | 
2026-02-19 02:32:02.899983 | TASK [process-stackviz : Check if subunit data exists]
2026-02-19 02:32:03.179595 | controller | ok
2026-02-19 02:32:03.183454 | 
2026-02-19 02:32:03.183526 | TASK [process-stackviz : debug]
2026-02-19 02:32:03.217357 | Subunit file could not be found at /opt/stack/tempest/testrepository.subunit
2026-02-19 02:32:03.222239 | 
2026-02-19 02:32:03.222309 | TASK [include_role : ensure-pip]
2026-02-19 02:32:03.248053 | controller | skipping: Conditional result was False
2026-02-19 02:32:03.256117 | 
2026-02-19 02:32:03.256209 | TASK [process-stackviz : pip]
2026-02-19 02:32:03.283018 | controller | skipping: Conditional result was False
2026-02-19 02:32:03.292604 | 
2026-02-19 02:32:03.292698 | TASK [process-stackviz : Deploy stackviz static html+js]
2026-02-19 02:32:03.820232 | controller | skipping: Conditional result was False
2026-02-19 02:32:03.828687 | 
2026-02-19 02:32:03.828788 | TASK [process-stackviz : Check if dstat data exists]
2026-02-19 02:32:03.854061 | controller | skipping: Conditional result was False
2026-02-19 02:32:03.863409 | 
2026-02-19 02:32:03.863566 | TASK [process-stackviz : Run stackviz with dstat]
2026-02-19 02:32:04.397087 | controller | skipping: Conditional result was False
2026-02-19 02:32:04.406230 | 
2026-02-19 02:32:04.406327 | TASK [process-stackviz : Run stackviz without dstat]
2026-02-19 02:32:04.932280 | controller | skipping: Conditional result was False
2026-02-19 02:32:04.941596 | 
2026-02-19 02:32:04.941672 | PLAY RECAP
2026-02-19 02:32:04.941741 | controller | ok: 5 changed: 1 unreachable: 0 failed: 0 skipped: 14 rescued: 0 ignored: 0
2026-02-19 02:32:04.941792 | 
2026-02-19 02:32:05.132946 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/tempest/playbooks/post-tempest.yaml@master]
2026-02-19 02:32:05.149105 | POST-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2026-02-19 02:32:05.815619 | 
2026-02-19 02:32:05.815770 | PLAY [all]
2026-02-19 02:32:05.832642 | 
2026-02-19 02:32:05.832724 | TASK [export-devstack-journal : Ensure /home/zuul/logs exists]
2026-02-19 02:32:06.508252 | controller | changed
2026-02-19 02:32:06.513323 | 
2026-02-19 02:32:06.513404 | TASK [export-devstack-journal : Export legacy stack screen log files]
2026-02-19 02:32:07.544451 | controller | ok: Runtime: 0:00:00.438400
2026-02-19 02:32:07.550644 | 
2026-02-19 02:32:07.550719 | TASK [export-devstack-journal : Export legacy syslog.txt]
2026-02-19 02:32:08.080202 | controller | ok: Runtime: 0:00:00.074533
2026-02-19 02:32:08.086056 | 
2026-02-19 02:32:08.086149 | TASK [export-devstack-journal : Export journal]
2026-02-19 02:32:08.618333 | controller | ok: Runtime: 0:00:00.068753
2026-02-19 02:32:08.625844 | 
2026-02-19 02:32:08.625938 | TASK [export-devstack-journal : Save journal README]
2026-02-19 02:32:09.703003 | controller | changed
2026-02-19 02:32:09.716868 | 
2026-02-19 02:32:09.716989 | TASK [apache-logs-conf : Ensure /home/zuul/apache exists]
2026-02-19 02:32:10.003855 | controller | changed
2026-02-19 02:32:10.008167 | 
2026-02-19 02:32:10.008236 | TASK [apache-logs-conf : Find logs]
2026-02-19 02:32:10.042942 | 
2026-02-19 02:32:10.043192 | LOOP [apache-logs-conf : Dereference files]
2026-02-19 02:32:10.079995 | 
2026-02-19 02:32:10.080239 | LOOP [apache-logs-conf : Create hard links]
2026-02-19 02:32:10.113341 | 
2026-02-19 02:32:10.113505 | TASK [apache-logs-conf : Find logs]
2026-02-19 02:32:10.554085 | controller | Output suppressed because no_log was given
2026-02-19 02:32:10.560208 | 
2026-02-19 02:32:10.560314 | LOOP [apache-logs-conf : Dereference files]
2026-02-19 02:32:10.597334 | 
2026-02-19 02:32:10.597631 | LOOP [apache-logs-conf : Create hard links]
2026-02-19 02:32:10.634890 | 
2026-02-19 02:32:10.635142 | TASK [apache-logs-conf : Ensure /home/zuul/apache_config apache_config exists]
2026-02-19 02:32:10.920615 | controller | changed
2026-02-19 02:32:10.926620 | 
2026-02-19 02:32:10.926703 | TASK [apache-logs-conf : Define config paths]
2026-02-19 02:32:10.957235 | controller | ok
2026-02-19 02:32:11.024818 | 
2026-02-19 02:32:11.025010 | TASK [apache-logs-conf : Discover configurations]
2026-02-19 02:32:11.306889 | controller | Output suppressed because no_log was given
2026-02-19 02:32:11.310955 | 
2026-02-19 02:32:11.311026 | LOOP [apache-logs-conf : Dereference configurations]
2026-02-19 02:32:11.345752 | 
2026-02-19 02:32:11.346049 | LOOP [apache-logs-conf : Link configurations]
2026-02-19 02:32:11.373336 | 
2026-02-19 02:32:11.373483 | TASK [capture-performance-data : Generate statistics]
2026-02-19 02:32:12.763110 | controller | /opt/stack/devstack//inc/python: line 43: -m: command not found
2026-02-19 02:32:12.773448 | controller | Using python 3.9 to install setuptools
2026-02-19 02:32:12.813307 | controller | /bin/python3.9: No module named pip
2026-02-19 02:32:12.821613 | controller | /bin/bash: line 4: /opt/stack/data/venv/bin/python3: No such file or directory
2026-02-19 02:32:12.402761 | controller | ERROR
2026-02-19 02:32:12.403109 | controller | {
2026-02-19 02:32:12.403180 | controller |   "delta": "0:00:00.445256",
2026-02-19 02:32:12.403228 | controller |   "end": "2026-02-19 02:32:12.822727",
2026-02-19 02:32:12.403270 | controller |   "msg": "non-zero return code",
2026-02-19 02:32:12.403317 | controller |   "rc": 127,
2026-02-19 02:32:12.403365 | controller |   "start": "2026-02-19 02:32:12.377471"
2026-02-19 02:32:12.403423 | controller | }
2026-02-19 02:32:12.403505 | controller | ERROR: Ignoring Errors
2026-02-19 02:32:12.413771 | 
2026-02-19 02:32:12.413843 | TASK [devstack-project-conf : Ensure /home/zuul/etc exists]
2026-02-19 02:32:12.700350 | controller | changed
2026-02-19 02:32:12.706335 | 
2026-02-19 02:32:12.706425 | LOOP [devstack-project-conf : Check which projects have a config folder]
2026-02-19 02:32:16.740503 | controller | Output suppressed because no_log was given
2026-02-19 02:32:16.750702 | 
2026-02-19 02:32:16.750796 | LOOP [devstack-project-conf : Copy configuration files]
2026-02-19 02:32:16.787000 | controller | skipping: Conditional result was False
2026-02-19 02:32:16.787539 | 
2026-02-19 02:32:16.789506 | controller | skipping: Conditional result was False
2026-02-19 02:32:16.791071 | controller | skipping: Conditional result was False
2026-02-19 02:32:16.793545 | controller | skipping: Conditional result was False
2026-02-19 02:32:16.796355 | controller | skipping: Conditional result was False
2026-02-19 02:32:16.799702 | controller | skipping: Conditional result was False
2026-02-19 02:32:16.802437 | controller | skipping: Conditional result was False
2026-02-19 02:32:16.805319 | controller | skipping: Conditional result was False
2026-02-19 02:32:16.807982 | controller | skipping: Conditional result was False
2026-02-19 02:32:16.810747 | controller | skipping: Conditional result was False
2026-02-19 02:32:16.813404 | controller | skipping: Conditional result was False
2026-02-19 02:32:16.816281 | controller | skipping: Conditional result was False
2026-02-19 02:32:16.818912 | controller | skipping: Conditional result was False
2026-02-19 02:32:16.821546 | controller | skipping: Conditional result was False
2026-02-19 02:32:16.824156 | controller | skipping: Conditional result was False
2026-02-19 02:32:16.826861 | controller | skipping: Conditional result was False
2026-02-19 02:32:16.855045 | 
2026-02-19 02:32:16.855236 | TASK [devstack-project-conf : Check if openstack has a config folder]
2026-02-19 02:32:17.124028 | controller | ok
2026-02-19 02:32:17.128524 | 
2026-02-19 02:32:17.128587 | TASK [devstack-project-conf : Copy configuration files]
2026-02-19 02:32:17.653811 | controller | skipping: Conditional result was False
2026-02-19 02:32:17.665372 | 
2026-02-19 02:32:17.665477 | TASK [capture-system-logs : Stage various logs and reports]
2026-02-19 02:32:18.687133 | controller | sudo: iptables-save: command not found
2026-02-19 02:32:18.707249 | controller | which: no python2 in (/sbin:/bin:/usr/sbin:/usr/bin:/usr/local/bin/)
2026-02-19 02:32:18.732643 | controller | /bin/python3: No module named pip
2026-02-19 02:32:20.362932 | controller | grep: /home/zuul/apache/*.log: No such file or directory
2026-02-19 02:32:19.744828 | controller | ok: Runtime: 0:00:01.696328
2026-02-19 02:32:19.753749 | 
2026-02-19 02:32:19.753837 | LOOP [stage-output : Register sources]
2026-02-19 02:32:34.162261 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.173805 | 
2026-02-19 02:32:34.173894 | TASK [stage-output : Check sudo]
2026-02-19 02:32:34.707049 | controller | ok: Runtime: 0:00:00.023598
2026-02-19 02:32:34.712442 | 
2026-02-19 02:32:34.712506 | LOOP [stage-output : Set source and destination for files and folders]
2026-02-19 02:32:34.816034 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.816352 | 
2026-02-19 02:32:34.824184 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.827828 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.830611 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.869398 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.870839 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.873349 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.875996 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.878773 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.881568 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.884092 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.886769 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.889454 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.892089 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.894686 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.897461 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.900314 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.902877 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.919623 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.920105 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.921309 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.923847 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.926474 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.929136 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.931688 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.934230 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.936904 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.971391 | controller | Output suppressed because no_log was given
2026-02-19 02:32:34.994567 | controller | Output suppressed because no_log was given
2026-02-19 02:32:35.045244 | controller | Output suppressed because no_log was given
2026-02-19 02:32:35.076450 | controller | Output suppressed because no_log was given
2026-02-19 02:32:35.076936 | controller | Output suppressed because no_log was given
2026-02-19 02:32:35.079551 | controller | Output suppressed because no_log was given
2026-02-19 02:32:35.082871 | controller | Output suppressed because no_log was given
2026-02-19 02:32:35.099727 | controller | Output suppressed because no_log was given
2026-02-19 02:32:35.112224 | 
2026-02-19 02:32:35.112293 | TASK [stage-output : Build a list of source, dest dictionaries]
2026-02-19 02:32:35.175662 | controller | ok
2026-02-19 02:32:35.184548 | 
2026-02-19 02:32:35.184638 | LOOP [stage-output : Ensure target folders exist]
2026-02-19 02:32:35.470852 | controller | changed: "docs"
2026-02-19 02:32:35.717126 | controller | changed: "artifacts"
2026-02-19 02:32:35.974323 | controller | ok: "logs"
2026-02-19 02:32:35.992740 | 
2026-02-19 02:32:35.992902 | LOOP [stage-output : Copy files and folders to staging folder]
2026-02-19 02:32:36.303088 | controller | ok: Item: Runtime: 0:00:00.004978
2026-02-19 02:32:36.303348 | controller | changed: All items complete
2026-02-19 02:32:36.303376 | 
2026-02-19 02:32:36.565388 | controller | ok: Item: Runtime: 0:00:00.003984
2026-02-19 02:32:36.818130 | controller | ok: Item: Runtime: 0:00:00.005345
2026-02-19 02:32:37.086774 | controller | ok: Item: Runtime: 0:00:00.005310
2026-02-19 02:32:37.348553 | controller | ok: Item: Runtime: 0:00:00.004826
2026-02-19 02:32:37.622891 | controller | ok: Item: Runtime: 0:00:00.005234
2026-02-19 02:32:37.885762 | controller | ok: Item: Runtime: 0:00:00.005615
2026-02-19 02:32:38.148339 | controller | ok: Item: Runtime: 0:00:00.005230
2026-02-19 02:32:38.415967 | controller | ok: Item: Runtime: 0:00:00.005598
2026-02-19 02:32:38.696032 | controller | ok: Item: Runtime: 0:00:00.005461
2026-02-19 02:32:38.949387 | controller | ok: Item: Runtime: 0:00:00.005104
2026-02-19 02:32:39.193900 | controller | ok: Item: Runtime: 0:00:00.005325
2026-02-19 02:32:39.457045 | controller | ok: Item: Runtime: 0:00:00.005105
2026-02-19 02:32:39.724149 | controller | ok: Item: Runtime: 0:00:00.004633
2026-02-19 02:32:39.986107 | controller | ok: Item: Runtime: 0:00:00.005403
2026-02-19 02:32:40.254678 | controller | ok: Item: Runtime: 0:00:00.005592
2026-02-19 02:32:40.526450 | controller | ok: Item: Runtime: 0:00:00.004326
2026-02-19 02:32:40.541370 | 
2026-02-19 02:32:40.541509 | TASK [stage-output : Make all log files readable]
2026-02-19 02:32:40.823587 | controller | changed
2026-02-19 02:32:40.828885 | 
2026-02-19 02:32:40.828991 | TASK [stage-output : Rename log files that match extensions_to_txt]
2026-02-19 02:32:41.235984 | controller | changed: Renamed files for staging.
2026-02-19 02:32:41.241678 | 
2026-02-19 02:32:41.241765 | TASK [stage-output : Discover log files for compression]
2026-02-19 02:32:41.267053 | controller | skipping: Conditional result was False
2026-02-19 02:32:41.277390 | 
2026-02-19 02:32:41.277487 | LOOP [stage-output : Archive everything from logs]
2026-02-19 02:32:41.318281 | 
2026-02-19 02:32:41.318446 | TASK [fetch-devstack-log-dir : Collect devstack logs]
2026-02-19 02:32:42.111269 | controller | changed:
2026-02-19 02:32:42.111520 | controller | created directory /var/lib/zuul/builds/4cebc7b81db9434eb093395a987be4d8/work/logs/controller
2026-02-19 02:32:42.111560 | controller | cd+++++++++ logs/
2026-02-19 02:32:42.111591 | controller | >f+++++++++ logs/audit_log.txt
2026-02-19 02:32:42.111620 | controller | >f+++++++++ logs/deprecations_log.txt
2026-02-19 02:32:42.111648 | controller | >f+++++++++ logs/devstack.journal.README.txt
2026-02-19 02:32:42.111675 | controller | >f+++++++++ logs/devstack.journal.gz
2026-02-19 02:32:42.111702 | controller | >f+++++++++ logs/df.txt
2026-02-19 02:32:42.111728 | controller | >f+++++++++ logs/iptables.txt
2026-02-19 02:32:42.111757 | controller | >f+++++++++ logs/listen53.txt
2026-02-19 02:32:42.111784 | controller | >f+++++++++ logs/local_conf.txt
2026-02-19 02:32:42.111811 | controller | >f+++++++++ logs/mount.txt
2026-02-19 02:32:42.111837 | controller | >f+++++++++ logs/performance.json
2026-02-19 02:32:42.111864 | controller | >f+++++++++ logs/pip3-freeze.txt
2026-02-19 02:32:42.111891 | controller | >f+++++++++ logs/resolv_conf.txt
2026-02-19 02:32:42.111921 | controller | >f+++++++++ logs/rpm-qa.txt
2026-02-19 02:32:42.111960 | controller | >f+++++++++ logs/services.txt
2026-02-19 02:32:42.111989 | controller | >f+++++++++ logs/sudoers
2026-02-19 02:32:42.112016 | controller | >f+++++++++ logs/syslog.txt
2026-02-19 02:32:42.112047 | controller | cd+++++++++ logs/apache/
2026-02-19 02:32:42.112102 | controller | cd+++++++++ logs/apache_config/
2026-02-19 02:32:42.112133 | controller | cd+++++++++ logs/etc/
2026-02-19 02:32:42.112159 | controller | cd+++++++++ logs/sudoers.d/
2026-02-19 02:32:42.112186 | controller | >f+++++++++ logs/sudoers.d/50_stack_sh
2026-02-19 02:32:42.112213 | controller | >f+++++++++ logs/sudoers.d/51_tempest_sh
2026-02-19 02:32:42.112241 | controller | >f+++++++++ logs/sudoers.d/90-cloud-init-users
2026-02-19 02:32:42.112267 | controller | >f+++++++++ logs/sudoers.d/zuul
2026-02-19 02:32:42.122733 | 
2026-02-19 02:32:42.122833 | TASK [Check if a tempest log exits]
2026-02-19 02:32:42.417374 | controller | ok
2026-02-19 02:32:42.421360 | 
2026-02-19 02:32:42.421420 | TASK [Link post-devstack tempest.log]
2026-02-19 02:32:42.447634 | controller | skipping: Conditional result was False
2026-02-19 02:32:42.456386 | 
2026-02-19 02:32:42.456523 | TASK [Capture most recent qemu crash dump, if any]
2026-02-19 02:32:43.530781 | controller | No match found.
2026-02-19 02:32:42.991563 | controller | ERROR
2026-02-19 02:32:42.991901 | controller | {
2026-02-19 02:32:42.991946 | controller |   "delta": "0:00:00.058723",
2026-02-19 02:32:42.991976 | controller |   "end": "2026-02-19 02:32:43.531375",
2026-02-19 02:32:42.992004 | controller |   "msg": "non-zero return code",
2026-02-19 02:32:42.992031 | controller |   "rc": 1,
2026-02-19 02:32:42.992057 | controller |   "start": "2026-02-19 02:32:43.472652"
2026-02-19 02:32:42.992084 | controller | }
2026-02-19 02:32:42.992118 | controller | ERROR: Ignoring Errors
2026-02-19 02:32:42.994137 | 
2026-02-19 02:32:42.994205 | PLAY RECAP
2026-02-19 02:32:42.994271 | controller | ok: 26 changed: 17 unreachable: 0 failed: 0 skipped: 12 rescued: 0 ignored: 2
2026-02-19 02:32:42.994303 | 
2026-02-19 02:32:43.166752 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2026-02-19 02:32:43.176799 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-02-19 02:32:43.776807 | 
2026-02-19 02:32:43.776974 | PLAY [all]
2026-02-19 02:32:43.787984 | 
2026-02-19 02:32:43.788069 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-19 02:32:43.834096 | controller | skipping: Conditional result was False
2026-02-19 02:32:43.842989 | 
2026-02-19 02:32:43.843167 | TASK [fetch-output : Set log path for single node]
2026-02-19 02:32:43.886020 | controller | ok
2026-02-19 02:32:43.891038 | 
2026-02-19 02:32:43.891127 | LOOP [fetch-output : Ensure local output dirs]
2026-02-19 02:32:44.272405 | controller -> localhost | ok: "/var/lib/zuul/builds/4cebc7b81db9434eb093395a987be4d8/work/logs"
2026-02-19 02:32:44.506814 | controller -> localhost | changed: "/var/lib/zuul/builds/4cebc7b81db9434eb093395a987be4d8/work/artifacts"
2026-02-19 02:32:44.732518 | controller -> localhost | changed: "/var/lib/zuul/builds/4cebc7b81db9434eb093395a987be4d8/work/docs"
2026-02-19 02:32:44.751683 | 
2026-02-19 02:32:44.751857 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-19 02:32:45.526613 | controller | changed: .d..t...... ./
2026-02-19 02:32:45.526971 | controller | changed: All items complete
2026-02-19 02:32:45.527036 | 
2026-02-19 02:32:46.062160 | controller | changed: .d..t...... ./
2026-02-19 02:32:46.621078 | controller | changed: .d..t...... ./
2026-02-19 02:32:46.636546 | 
2026-02-19 02:32:46.636718 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-02-19 02:32:47.047276 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.006941
2026-02-19 02:32:47.272840 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.008697
2026-02-19 02:32:47.294060 | 
2026-02-19 02:32:47.294203 | PLAY [all]
2026-02-19 02:32:47.299284 | 
2026-02-19 02:32:47.299349 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-02-19 02:32:48.011941 | controller | changed
2026-02-19 02:32:48.019440 | 
2026-02-19 02:32:48.019514 | PLAY RECAP
2026-02-19 02:32:48.019578 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-02-19 02:32:48.019610 | 
2026-02-19 02:32:48.159278 | POST-RUN END RESULT_NORMAL: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post.yaml@main]
2026-02-19 02:32:48.169877 | POST-RUN START: [trusted : github.com/vexxhost/zuul-config/playbooks/base/post-logs.yaml@main]
2026-02-19 02:32:48.748853 | 
2026-02-19 02:32:48.749615 | PLAY [localhost]
2026-02-19 02:32:48.759791 | 
2026-02-19 02:32:48.759862 | TASK [Generate Zuul manifest]
2026-02-19 02:32:48.793775 | localhost | ok
2026-02-19 02:32:48.811085 | 
2026-02-19 02:32:48.811171 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-02-19 02:32:49.219089 | localhost | changed
2026-02-19 02:32:49.232674 | 
2026-02-19 02:32:49.232752 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-02-19 02:32:49.265882 | localhost | ok
2026-02-19 02:32:49.274257 | 
2026-02-19 02:32:49.274321 | TASK [Upload logs]
2026-02-19 02:32:49.297380 | localhost | ok
2026-02-19 02:32:49.358447 | 
2026-02-19 02:32:49.358579 | TASK [Set zuul-log-path fact]
2026-02-19 02:32:49.383464 | localhost | ok
2026-02-19 02:32:49.436762 | 
2026-02-19 02:32:49.436912 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-19 02:32:49.469417 | localhost | ok
2026-02-19 02:32:49.478975 | 
2026-02-19 02:32:49.479045 | TASK [upload-logs : Create log directories]
2026-02-19 02:32:49.837317 | localhost | changed
2026-02-19 02:32:49.845256 | 
2026-02-19 02:32:49.845336 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-02-19 02:32:50.224002 | localhost -> localhost | ok: Runtime: 0:00:00.007009
2026-02-19 02:32:50.232118 | 
2026-02-19 02:32:50.232209 | TASK [upload-logs : Upload logs to log server]
2026-02-19 02:32:50.744776 | localhost | Output suppressed because no_log was given
2026-02-19 02:32:50.749725 | 
2026-02-19 02:32:50.749818 | LOOP [upload-logs : Compress console log and json output]
2026-02-19 02:32:50.798439 | localhost | skipping: Conditional result was False
2026-02-19 02:32:50.805442 | localhost | skipping: Conditional result was False
2026-02-19 02:32:50.814151 | 
2026-02-19 02:32:50.814293 | LOOP [upload-logs : Upload compressed console log and json output]
2026-02-19 02:32:50.857253 | localhost | skipping: Conditional result was False
2026-02-19 02:32:50.857627 | 
2026-02-19 02:32:50.861748 | localhost | skipping: Conditional result was False
2026-02-19 02:32:50.880003 | 
2026-02-19 02:32:50.880259 | LOOP [upload-logs : Upload console log and json output]