2025-10-03 10:32:49.462989 | Job console starting...
2025-10-03 10:32:49.480455 | Updating repositories
2025-10-03 10:32:51.054646 | Preparing job workspace
2025-10-03 10:33:04.364361 | Running Ansible setup...
2025-10-03 10:33:09.547610 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-03 10:33:10.254231 | 
2025-10-03 10:33:10.254361 | PLAY [localhost]
2025-10-03 10:33:10.264343 | 
2025-10-03 10:33:10.264485 | TASK [Gathering Facts]
2025-10-03 10:33:11.315297 | localhost | ok
2025-10-03 10:33:11.338658 | 
2025-10-03 10:33:11.338844 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-03 10:33:11.868649 | localhost -> localhost | changed
2025-10-03 10:33:11.874475 | 
2025-10-03 10:33:11.874548 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-03 10:33:12.789045 | localhost -> localhost | changed
2025-10-03 10:33:12.798088 | 
2025-10-03 10:33:12.798180 | TASK [Setup log path fact]
2025-10-03 10:33:12.822485 | localhost | ok
2025-10-03 10:33:12.834185 | 
2025-10-03 10:33:12.834258 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-03 10:33:12.861820 | localhost | ok
2025-10-03 10:33:12.869774 | 
2025-10-03 10:33:12.869848 | TASK [emit-job-header : Print job information]
2025-10-03 10:33:12.898105 | # Job Information
2025-10-03 10:33:12.898363 | Ansible Version: 2.15.12
2025-10-03 10:33:12.898390 | Job: devstack-platform-centos-10-stream
2025-10-03 10:33:12.898410 | Pipeline: openstack-check
2025-10-03 10:33:12.898428 | Executor: ze02.softwarefactory-project.io
2025-10-03 10:33:12.898447 | Triggered by: https://review.opendev.org/c/openstack/devstack/+/954751
2025-10-03 10:33:12.898466 | Log URL (when completed): https://logserver.rdoproject.org/2b2/rdoproject.org/2b2fd07d71034204a10c916c074d6573/
2025-10-03 10:33:12.898484 | Event ID: 104b091dd2c0439ab222b181c79ec631
2025-10-03 10:33:12.902472 | 
2025-10-03 10:33:12.902545 | LOOP [emit-job-header : Print node information]
2025-10-03 10:33:13.000030 | localhost | ok:
2025-10-03 10:33:13.000476 | localhost | # Node Information
2025-10-03 10:33:13.000545 | localhost | Inventory Hostname: controller
2025-10-03 10:33:13.000576 | localhost | Hostname: np0005468665
2025-10-03 10:33:13.000597 | localhost | Username: zuul-worker
2025-10-03 10:33:13.000618 | localhost | Distro: CentOS 10
2025-10-03 10:33:13.000636 | localhost | Provider: vexxhost-nodepool-sf
2025-10-03 10:33:13.000653 | localhost | Region: RegionOne
2025-10-03 10:33:13.000688 | localhost | Label: cloud-centos-10-stream
2025-10-03 10:33:13.000707 | localhost | Product Name: OpenStack Nova
2025-10-03 10:33:13.000724 | localhost | Interface IP: 38.102.83.227
2025-10-03 10:33:13.035209 | 
2025-10-03 10:33:13.035322 | PLAY [all]
2025-10-03 10:33:13.043243 | 
2025-10-03 10:33:13.043318 | TASK [Gather network facts]
2025-10-03 10:33:14.648416 | controller | ok
2025-10-03 10:33:14.685371 | 
2025-10-03 10:33:14.685508 | TASK [include_role : start-zuul-console]
2025-10-03 10:33:14.706137 | controller | ok
2025-10-03 10:33:14.718695 | 
2025-10-03 10:33:14.718764 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-03 10:33:15.196972 | controller | ok
2025-10-03 10:33:15.208786 | 
2025-10-03 10:33:15.208935 | TASK [include_role : add-build-sshkey]
2025-10-03 10:33:15.229277 | controller | ok
2025-10-03 10:33:15.247535 | 
2025-10-03 10:33:15.247624 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-03 10:33:15.669501 | controller -> localhost | ok
2025-10-03 10:33:15.676575 | 
2025-10-03 10:33:15.676647 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-03 10:33:15.731158 | controller | ok
2025-10-03 10:33:15.761332 | controller | included: /var/lib/zuul/builds/2b2fd07d71034204a10c916c074d6573/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-03 10:33:15.778296 | 
2025-10-03 10:33:15.778640 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-03 10:33:16.646224 | controller -> localhost | Generating public/private rsa key pair.
2025-10-03 10:33:16.646532 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/2b2fd07d71034204a10c916c074d6573/work/2b2fd07d71034204a10c916c074d6573_id_rsa.
2025-10-03 10:33:16.646577 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/2b2fd07d71034204a10c916c074d6573/work/2b2fd07d71034204a10c916c074d6573_id_rsa.pub.
2025-10-03 10:33:16.646610 | controller -> localhost | The key fingerprint is:
2025-10-03 10:33:16.646644 | controller -> localhost | SHA256:lxteHyP4mwuzUHOXVYQFVHtCLXkrgeZZ/btAnEN/1vo zuul-build-sshkey
2025-10-03 10:33:16.646694 | controller -> localhost | The key's randomart image is:
2025-10-03 10:33:16.646731 | controller -> localhost | +---[RSA 3072]----+
2025-10-03 10:33:16.646762 | controller -> localhost | |            ..=O=|
2025-10-03 10:33:16.646806 | controller -> localhost | |           o =+.=|
2025-10-03 10:33:16.646837 | controller -> localhost | |          o = =+*|
2025-10-03 10:33:16.646865 | controller -> localhost | |           = * **|
2025-10-03 10:33:16.646892 | controller -> localhost | |        S B = Boo|
2025-10-03 10:33:16.646919 | controller -> localhost | |         + B =.+ |
2025-10-03 10:33:16.646945 | controller -> localhost | |        . = . o..|
2025-10-03 10:33:16.646970 | controller -> localhost | |         . + o .E|
2025-10-03 10:33:16.646997 | controller -> localhost | |          . +.   |
2025-10-03 10:33:16.647023 | controller -> localhost | +----[SHA256]-----+
2025-10-03 10:33:16.647073 | controller -> localhost | ok: Runtime: 0:00:00.128834
2025-10-03 10:33:16.655695 | 
2025-10-03 10:33:16.655759 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-03 10:33:16.678388 | controller | ok
2025-10-03 10:33:16.690505 | controller | included: /var/lib/zuul/builds/2b2fd07d71034204a10c916c074d6573/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-03 10:33:16.698791 | 
2025-10-03 10:33:16.698855 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-03 10:33:16.723688 | controller | skipping: Conditional result was False
2025-10-03 10:33:16.730109 | 
2025-10-03 10:33:16.730173 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-03 10:33:17.232694 | controller | changed
2025-10-03 10:33:17.237998 | 
2025-10-03 10:33:17.238084 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-03 10:33:17.546763 | controller | ok
2025-10-03 10:33:17.562118 | 
2025-10-03 10:33:17.562266 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-03 10:33:18.588038 | controller | changed
2025-10-03 10:33:18.594724 | 
2025-10-03 10:33:18.594836 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-03 10:33:19.661567 | controller | changed
2025-10-03 10:33:19.666995 | 
2025-10-03 10:33:19.667059 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-03 10:33:19.702589 | controller | skipping: Conditional result was False
2025-10-03 10:33:19.711836 | 
2025-10-03 10:33:19.711986 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-03 10:33:20.466395 | controller -> localhost | changed
2025-10-03 10:33:20.476574 | 
2025-10-03 10:33:20.476679 | TASK [add-build-sshkey : Add back temp key]
2025-10-03 10:33:21.060200 | controller -> localhost | Identity added: /var/lib/zuul/builds/2b2fd07d71034204a10c916c074d6573/work/2b2fd07d71034204a10c916c074d6573_id_rsa (zuul-build-sshkey)
2025-10-03 10:33:21.060492 | controller -> localhost | ok: Runtime: 0:00:00.022386
2025-10-03 10:33:21.070823 | 
2025-10-03 10:33:21.070966 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-03 10:33:21.527548 | controller | ok
2025-10-03 10:33:21.535625 | 
2025-10-03 10:33:21.535819 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-03 10:33:21.571708 | controller | skipping: Conditional result was False
2025-10-03 10:33:21.590172 | 
2025-10-03 10:33:21.590327 | TASK [include_role : validate-host]
2025-10-03 10:33:21.623821 | controller | ok
2025-10-03 10:33:21.658015 | 
2025-10-03 10:33:21.658166 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-03 10:33:21.722943 | controller | ok
2025-10-03 10:33:21.731402 | 
2025-10-03 10:33:21.731763 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-03 10:33:21.972194 | controller -> localhost | ok
2025-10-03 10:33:21.978557 | 
2025-10-03 10:33:21.978625 | TASK [validate-host : Collect information about the host]
2025-10-03 10:33:23.850229 | controller | ok
2025-10-03 10:33:23.866363 | 
2025-10-03 10:33:23.866522 | TASK [validate-host : Sanitize hostname]
2025-10-03 10:33:23.930097 | controller | ok
2025-10-03 10:33:23.937470 | 
2025-10-03 10:33:23.937563 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-03 10:33:24.385820 | controller -> localhost | changed
2025-10-03 10:33:24.391516 | 
2025-10-03 10:33:24.391581 | TASK [validate-host : Collect information about zuul worker]
2025-10-03 10:33:24.885845 | controller | ok
2025-10-03 10:33:24.898133 | 
2025-10-03 10:33:24.898289 | TASK [validate-host : Write out all zuul information for each host]
2025-10-03 10:33:25.423162 | controller -> localhost | changed
2025-10-03 10:33:25.434418 | 
2025-10-03 10:33:25.434511 | TASK [include_role : prepare-workspace-openshift]
2025-10-03 10:33:25.448506 | controller | skipping: Conditional result was False
2025-10-03 10:33:25.455189 | 
2025-10-03 10:33:25.455502 | TASK [include_role : remove-zuul-sshkey]
2025-10-03 10:33:25.469647 | controller | skipping: Conditional result was False
2025-10-03 10:33:25.478004 | 
2025-10-03 10:33:25.478126 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-03 10:33:25.784269 | controller | ok: "logs"
2025-10-03 10:33:25.784572 | controller | ok: All items complete
2025-10-03 10:33:25.784614 | 
2025-10-03 10:33:26.043231 | controller | ok: "artifacts"
2025-10-03 10:33:26.324610 | controller | ok: "docs"
2025-10-03 10:33:26.338583 | 
2025-10-03 10:33:26.338745 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-03 10:33:26.673900 | controller | changed: "logs"
2025-10-03 10:33:26.987919 | controller | changed: "artifacts"
2025-10-03 10:33:27.282066 | controller | changed: "docs"
2025-10-03 10:33:27.327171 | 
2025-10-03 10:33:27.327303 | PLAY RECAP
2025-10-03 10:33:27.327361 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-03 10:33:27.327396 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-03 10:33:27.327421 | 
2025-10-03 10:33:27.478197 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-03 10:33:27.483864 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-03 10:33:28.088159 | 
2025-10-03 10:33:28.088321 | PLAY [localhost]
2025-10-03 10:33:28.106270 | 
2025-10-03 10:33:28.106388 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-10-03 10:33:28.523609 | localhost | ok
2025-10-03 10:33:28.531312 | 
2025-10-03 10:33:28.531493 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-10-03 10:33:29.214497 | localhost | changed
2025-10-03 10:33:29.242032 | 
2025-10-03 10:33:29.242146 | PLAY [all]
2025-10-03 10:33:29.258978 | 
2025-10-03 10:33:29.259055 | TASK [include_role : prepare-workspace]
2025-10-03 10:33:29.289281 | controller | ok
2025-10-03 10:33:29.305030 | 
2025-10-03 10:33:29.305128 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-03 10:33:29.778291 | controller | ok
2025-10-03 10:33:29.799311 | 
2025-10-03 10:33:29.799526 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-03 10:35:09.702243 | controller | Output suppressed because no_log was given
2025-10-03 10:35:09.712814 | 
2025-10-03 10:35:09.712918 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-03 10:35:10.243409 | controller | changed: "logs"
2025-10-03 10:35:10.519563 | controller | changed: "artifacts"
2025-10-03 10:35:10.777424 | controller | changed: "docs"
2025-10-03 10:35:10.799175 | 
2025-10-03 10:35:10.799392 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-03 10:35:11.128045 | controller | changed: "logs"
2025-10-03 10:35:11.128467 | controller | changed: All items complete
2025-10-03 10:35:11.128529 | 
2025-10-03 10:35:11.432725 | controller | changed: "artifacts"
2025-10-03 10:35:11.696978 | controller | changed: "docs"
2025-10-03 10:35:11.714776 | 
2025-10-03 10:35:11.714904 | TASK [Check if worker can sudo]
2025-10-03 10:35:12.302798 | controller | ok: Runtime: 0:00:00.062896
2025-10-03 10:35:12.315646 | 
2025-10-03 10:35:12.315822 | TASK [configure-mirrors : Gather needed facts]
2025-10-03 10:35:12.395633 | controller | skipping: Conditional result was False
2025-10-03 10:35:12.404645 | 
2025-10-03 10:35:12.404782 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-10-03 10:35:12.514265 | controller | ok
2025-10-03 10:35:12.532350 | controller | included: /var/lib/zuul/builds/2b2fd07d71034204a10c916c074d6573/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-10-03 10:35:12.545604 | 
2025-10-03 10:35:12.545773 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-10-03 10:35:12.880104 | controller | ok
2025-10-03 10:35:12.891833 | 
2025-10-03 10:35:12.891974 | LOOP [configure-mirrors : Include OS-specific variables]
2025-10-03 10:35:12.969561 | controller | ok: "/var/lib/zuul/builds/2b2fd07d71034204a10c916c074d6573/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS.yaml"
2025-10-03 10:35:12.987082 | 
2025-10-03 10:35:12.987277 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-10-03 10:35:14.022923 | controller | changed
2025-10-03 10:35:14.031802 | 
2025-10-03 10:35:14.031915 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-10-03 10:35:14.121541 | controller | ok: "/var/lib/zuul/builds/2b2fd07d71034204a10c916c074d6573/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/default.yaml"
2025-10-03 10:35:14.121831 | controller | ok: All items complete
2025-10-03 10:35:14.121866 | 
2025-10-03 10:35:14.143119 | controller | included: /var/lib/zuul/builds/2b2fd07d71034204a10c916c074d6573/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/default.yaml
2025-10-03 10:35:14.151418 | 
2025-10-03 10:35:14.151568 | TASK [configure-mirrors : Warn about unsupported distribution]
2025-10-03 10:35:14.223987 | WARNING: CentOS mirrors are not supported either by this role yet. The execution of the job will continue without setting up cached mirrors.
2025-10-03 10:35:14.247598 | 
2025-10-03 10:35:14.247655 | PLAY RECAP
2025-10-03 10:35:14.247719 | controller | ok: 11 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-03 10:35:14.247747 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-03 10:35:14.247765 | 
2025-10-03 10:35:14.378269 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-10-03 10:35:14.382601 | PRE-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2025-10-03 10:35:15.078724 | 
2025-10-03 10:35:15.078853 | PLAY [all]
2025-10-03 10:35:15.096844 | 
2025-10-03 10:35:15.096954 | TASK [Fix the permissions of the zuul home directory]
2025-10-03 10:35:15.710387 | controller | changed
2025-10-03 10:35:15.719690 | 
2025-10-03 10:35:15.719795 | TASK [Gather minimum local MTU]
2025-10-03 10:35:15.827919 | controller | ok
2025-10-03 10:35:15.839365 | 
2025-10-03 10:35:15.839501 | TASK [Calculate external_bridge_mtu]
2025-10-03 10:35:15.904848 | controller | ok
2025-10-03 10:35:15.924312 | 
2025-10-03 10:35:15.924399 | TASK [configure-swap : Set ephemeral device if /dev/xvde exists]
2025-10-03 10:35:15.963020 | controller | skipping: Conditional result was False
2025-10-03 10:35:15.993388 | 
2025-10-03 10:35:15.993590 | TASK [configure-swap : Get ephemeral0 device node]
2025-10-03 10:35:16.536094 | controller | ok: Runtime: 0:00:00.009719
2025-10-03 10:35:16.548020 | 
2025-10-03 10:35:16.548166 | TASK [configure-swap : Set ephemeral device if LABEL exists]
2025-10-03 10:35:16.576014 | controller | skipping: Conditional result was False
2025-10-03 10:35:16.589952 | 
2025-10-03 10:35:16.590107 | TASK [configure-swap : Setup swap on ephemeral storage]
2025-10-03 10:35:16.617866 | controller | skipping: Conditional result was False
2025-10-03 10:35:16.630563 | 
2025-10-03 10:35:16.630752 | TASK [configure-swap : Setup swap file on root device]
2025-10-03 10:35:16.732523 | controller | ok
2025-10-03 10:35:16.746632 | controller | included: /var/lib/zuul/builds/2b2fd07d71034204a10c916c074d6573/untrusted/project_4/opendev.org/openstack/openstack-zuul-jobs/roles/configure-swap/tasks/root.yaml
2025-10-03 10:35:16.756140 | 
2025-10-03 10:35:16.756243 | TASK [configure-swap : Calculate required swap]
2025-10-03 10:35:16.828937 | controller | ok
2025-10-03 10:35:16.837631 | 
2025-10-03 10:35:16.837788 | TASK [configure-swap : Get root filesystem]
2025-10-03 06:35:17.176612 | controller | xfs
2025-10-03 10:35:17.376709 | controller | ok: Runtime: 0:00:00.012248
2025-10-03 10:35:17.390133 | 
2025-10-03 10:35:17.390296 | TASK [configure-swap : Save root filesystem]
2025-10-03 10:35:17.438133 | controller | ok
2025-10-03 10:35:17.450139 | 
2025-10-03 10:35:17.450274 | TASK [configure-swap : Debug the root_filesystem variable]
2025-10-03 10:35:17.489608 | controller | ok:
2025-10-03 10:35:17.489964 | controller | {
2025-10-03 10:35:17.490026 | controller |   "root_filesystem": "xfs"
2025-10-03 10:35:17.490081 | controller | }
2025-10-03 10:35:17.503915 | 
2025-10-03 10:35:17.504056 | TASK [configure-swap : Create swap backing file]
2025-10-03 06:35:45.361590 | controller | 8192+0 records in
2025-10-03 06:35:45.361784 | controller | 8192+0 records out
2025-10-03 06:35:45.361814 | controller | 8589934592 bytes (8.6 GB, 8.0 GiB) copied, 27.4308 s, 313 MB/s
2025-10-03 10:35:45.630521 | controller | ok: Runtime: 0:00:27.440900
2025-10-03 10:35:45.644099 | 
2025-10-03 10:35:45.644281 | TASK [configure-swap : Ensure swapfile perms]
2025-10-03 10:35:46.711004 | controller | changed
2025-10-03 10:35:46.723882 | 
2025-10-03 10:35:46.724092 | TASK [configure-swap : Make swapfile]
2025-10-03 06:35:53.684117 | controller | Setting up swapspace version 1, size = 8 GiB (8589930496 bytes)
2025-10-03 06:35:53.684294 | controller | no label, UUID=8a3e72e4-2b5f-407c-b4ce-8eda866fa6e1
2025-10-03 10:35:53.778136 | controller | ok: Runtime: 0:00:06.176975
2025-10-03 10:35:53.791977 | 
2025-10-03 10:35:53.792138 | TASK [configure-swap : Write swap to fstab]
2025-10-03 10:35:54.383823 | controller | changed
2025-10-03 10:35:54.396533 | 
2025-10-03 10:35:54.396728 | TASK [configure-swap : Add all swap]
2025-10-03 10:35:54.948536 | controller | ok: Runtime: 0:00:00.027754
2025-10-03 10:35:54.961098 | 
2025-10-03 10:35:54.961282 | TASK [configure-swap : Debug the swap_required variable]
2025-10-03 10:35:55.020910 | controller | ok:
2025-10-03 10:35:55.021279 | controller | {
2025-10-03 10:35:55.021377 | controller |   "swap_required": "8192"
2025-10-03 10:35:55.021448 | controller | }
2025-10-03 10:35:55.034804 | 
2025-10-03 10:35:55.035005 | TASK [configure-swap : Set swappiness]
2025-10-03 10:35:55.565452 | controller | changed
2025-10-03 10:35:55.570998 | 
2025-10-03 10:35:55.571085 | TASK [configure-swap : Debug the ephemeral_device variable]
2025-10-03 10:35:55.610062 | controller | ok:
2025-10-03 10:35:55.610414 | controller | {
2025-10-03 10:35:55.610500 | controller |   "ephemeral_device": "VARIABLE IS NOT DEFINED!: 'ephemeral_device' is undefined. 'ephemeral_device' is undefined"
2025-10-03 10:35:55.610568 | controller | }
2025-10-03 10:35:55.630964 | 
2025-10-03 10:35:55.631087 | TASK [setup-stack-user : Create stack group]
2025-10-03 10:35:56.342867 | controller | changed
2025-10-03 10:35:56.355592 | 
2025-10-03 10:35:56.355869 | TASK [setup-stack-user : Create the stack user home folder]
2025-10-03 10:35:56.703224 | controller | changed
2025-10-03 10:35:56.711398 | 
2025-10-03 10:35:56.711533 | TASK [setup-stack-user : Create stack user]
2025-10-03 10:35:57.517112 | controller | changed
2025-10-03 10:35:57.523107 | 
2025-10-03 10:35:57.523244 | TASK [setup-stack-user : Set stack user home directory permissions and ownership]
2025-10-03 10:35:57.917330 | controller | changed
2025-10-03 10:35:57.931562 | 
2025-10-03 10:35:57.931736 | TASK [setup-stack-user : Copy 50_stack_sh file to /etc/sudoers.d]
2025-10-03 10:35:59.628713 | controller | changed
2025-10-03 10:35:59.639362 | 
2025-10-03 10:35:59.639493 | TASK [setup-stack-user : Create .cache folder within BASE]
2025-10-03 10:35:59.991097 | controller | changed
2025-10-03 10:36:00.050785 | 
2025-10-03 10:36:00.050934 | TASK [setup-tempest-user : Create tempest group]
2025-10-03 10:36:00.672319 | controller | changed
2025-10-03 10:36:00.687334 | 
2025-10-03 10:36:00.687491 | TASK [setup-tempest-user : Create tempest user]
2025-10-03 10:36:01.167282 | controller | changed
2025-10-03 10:36:01.185354 | 
2025-10-03 10:36:01.185561 | TASK [setup-tempest-user : Copy 51_tempest_sh to /etc/sudoers.d]
2025-10-03 10:36:02.667371 | controller | changed
2025-10-03 10:36:02.689569 | 
2025-10-03 10:36:02.689744 | TASK [setup-devstack-source-dirs : Find all OpenStack source repos used by this job]
2025-10-03 10:36:03.154634 | controller | ok: Not all paths examined, check warnings for details
2025-10-03 10:36:03.174824 | 
2025-10-03 10:36:03.174993 | LOOP [setup-devstack-source-dirs : Copy Zuul repos into devstack working directory]
2025-10-03 10:36:05.392579 | controller | ok: Item: Runtime: 0:00:01.785537
2025-10-03 10:36:06.223274 | controller | ok: Item: Runtime: 0:00:00.561199
2025-10-03 10:36:07.085245 | controller | ok: Item: Runtime: 0:00:00.557324
2025-10-03 10:36:08.751045 | controller | ok: Item: Runtime: 0:00:01.336336
2025-10-03 10:36:09.904154 | controller | ok: Item: Runtime: 0:00:00.836844
2025-10-03 10:36:11.606518 | controller | ok: Item: Runtime: 0:00:01.383690
2025-10-03 10:36:15.375219 | controller | ok: Item: Runtime: 0:00:03.429029
2025-10-03 10:36:15.785403 | controller | ok: Item: Runtime: 0:00:00.073931
2025-10-03 10:36:16.914154 | controller | ok: Item: Runtime: 0:00:00.741011
2025-10-03 10:36:17.557832 | controller | ok: Item: Runtime: 0:00:00.263145
2025-10-03 10:36:19.441009 | controller | ok: Item: Runtime: 0:00:01.085817
2025-10-03 10:36:20.387231 | controller | ok: Item: Runtime: 0:00:00.532490
2025-10-03 10:36:20.404279 | 
2025-10-03 10:36:20.404401 | TASK [setup-devstack-source-dirs : Find top level github projects]
2025-10-03 10:36:20.745655 | controller | ok: All paths examined
2025-10-03 10:36:20.754279 | 
2025-10-03 10:36:20.754387 | TASK [setup-devstack-source-dirs : Find actual github repos]
2025-10-03 10:36:21.317091 | controller | ok: All paths examined
2025-10-03 10:36:21.330945 | 
2025-10-03 10:36:21.331128 | LOOP [setup-devstack-source-dirs : Copy github repos into devstack working directory]
2025-10-03 10:36:22.067587 | controller | ok: Item: Runtime: 0:00:00.155518
2025-10-03 10:36:22.068055 | controller | changed: All items complete
2025-10-03 10:36:22.068123 | 
2025-10-03 10:36:22.093560 | 
2025-10-03 10:36:22.093806 | LOOP [setup-devstack-source-dirs : Setup refspec for repos into devstack working directory]
2025-10-03 10:36:22.151914 | controller | skipping: Conditional result was False
2025-10-03 10:36:22.155892 | controller | skipping: Conditional result was False
2025-10-03 10:36:22.161486 | controller | skipping: Conditional result was False
2025-10-03 10:36:22.166633 | controller | skipping: Conditional result was False
2025-10-03 10:36:22.172282 | controller | skipping: Conditional result was False
2025-10-03 10:36:22.177208 | controller | skipping: Conditional result was False
2025-10-03 10:36:22.184555 | controller | skipping: Conditional result was False
2025-10-03 10:36:22.190451 | controller | skipping: Conditional result was False
2025-10-03 10:36:22.195574 | controller | skipping: Conditional result was False
2025-10-03 10:36:22.201114 | controller | skipping: Conditional result was False
2025-10-03 10:36:22.206048 | controller | skipping: Conditional result was False
2025-10-03 10:36:22.212671 | controller | skipping: Conditional result was False
2025-10-03 10:36:22.239641 | 
2025-10-03 10:36:22.239855 | TASK [setup-devstack-source-dirs : Set ownership of repos]
2025-10-03 10:37:23.772857 | controller | changed
2025-10-03 10:37:23.783191 | 
2025-10-03 10:37:23.783263 | TASK [setup-devstack-log-dir : Create logs directory]
2025-10-03 10:37:24.123026 | controller | changed
2025-10-03 10:37:24.138373 | 
2025-10-03 10:37:24.138497 | TASK [setup-devstack-cache : Copy cached devstack files]
2025-10-03 06:37:24.552973 | controller | find: ‘/opt/cache/files’: No such file or directory
2025-10-03 10:37:24.710962 | controller | ERROR
2025-10-03 10:37:24.711331 | controller | {
2025-10-03 10:37:24.711403 | controller |   "delta": "0:00:00.008032",
2025-10-03 10:37:24.711478 | controller |   "end": "2025-10-03 06:37:24.553501",
2025-10-03 10:37:24.711567 | controller |   "msg": "non-zero return code",
2025-10-03 10:37:24.711623 | controller |   "rc": 1,
2025-10-03 10:37:24.711699 | controller |   "start": "2025-10-03 06:37:24.545469"
2025-10-03 10:37:24.711751 | controller | }
2025-10-03 10:37:24.711805 | controller | ERROR: Ignoring Errors
2025-10-03 10:37:24.725077 | 
2025-10-03 10:37:24.725215 | TASK [setup-devstack-cache : Set ownership of cached files]
2025-10-03 10:37:25.183556 | controller | ok
2025-10-03 10:37:25.208310 | 
2025-10-03 10:37:25.208523 | TASK [start-fresh-logging : Check for /bin/journalctl file]
2025-10-03 06:37:25.570171 | controller | /usr/bin/journalctl
2025-10-03 10:37:25.764199 | controller | ok: Runtime: 0:00:00.007668
2025-10-03 10:37:25.777853 | 
2025-10-03 10:37:25.778196 | TASK [start-fresh-logging : Get current date]
2025-10-03 06:37:26.188638 | controller | 2025-10-03 06:37:26
2025-10-03 10:37:26.341157 | controller | ok: Runtime: 0:00:00.008263
2025-10-03 10:37:26.350528 | 
2025-10-03 10:37:26.350713 | TASK [start-fresh-logging : Copy current date to log-start-timestamp.txt]
2025-10-03 10:37:27.290537 | controller | changed
2025-10-03 10:37:27.304185 | 
2025-10-03 10:37:27.304372 | TASK [start-fresh-logging : Stop rsyslog]
2025-10-03 10:37:27.332167 | controller | skipping: Conditional result was False
2025-10-03 10:37:27.346342 | 
2025-10-03 10:37:27.346497 | TASK [start-fresh-logging : Save syslog file prior to devstack run]
2025-10-03 10:37:27.896251 | controller | skipping: Conditional result was False
2025-10-03 10:37:27.904728 | 
2025-10-03 10:37:27.904894 | TASK [start-fresh-logging : Save kern.log file prior to devstack run]
2025-10-03 10:37:28.450453 | controller | skipping: Conditional result was False
2025-10-03 10:37:28.464639 | 
2025-10-03 10:37:28.464830 | TASK [start-fresh-logging : Recreate syslog file]
2025-10-03 10:37:28.492026 | controller | skipping: Conditional result was False
2025-10-03 10:37:28.510243 | 
2025-10-03 10:37:28.510824 | TASK [start-fresh-logging : Recreate syslog file owner and group]
2025-10-03 10:37:29.057117 | controller | skipping: Conditional result was False
2025-10-03 10:37:29.065851 | 
2025-10-03 10:37:29.065952 | TASK [start-fresh-logging : Recreate syslog file permissions]
2025-10-03 10:37:29.605641 | controller | skipping: Conditional result was False
2025-10-03 10:37:29.621490 | 
2025-10-03 10:37:29.621722 | TASK [start-fresh-logging : Add read permissions to all on syslog file]
2025-10-03 10:37:29.648449 | controller | skipping: Conditional result was False
2025-10-03 10:37:29.658251 | 
2025-10-03 10:37:29.658344 | TASK [start-fresh-logging : Recreate kern.log file]
2025-10-03 10:37:29.684056 | controller | skipping: Conditional result was False
2025-10-03 10:37:29.693305 | 
2025-10-03 10:37:29.693393 | TASK [start-fresh-logging : Recreate kern.log file owner and group]
2025-10-03 10:37:30.230609 | controller | skipping: Conditional result was False
2025-10-03 10:37:30.239614 | 
2025-10-03 10:37:30.239757 | TASK [start-fresh-logging : Recreate kern.log file permissions]
2025-10-03 10:37:30.780873 | controller | skipping: Conditional result was False
2025-10-03 10:37:30.794972 | 
2025-10-03 10:37:30.795122 | TASK [start-fresh-logging : Add read permissions to all on kern.log file]
2025-10-03 10:37:30.822493 | controller | skipping: Conditional result was False
2025-10-03 10:37:30.839637 | 
2025-10-03 10:37:30.839893 | TASK [start-fresh-logging : Start rsyslog]
2025-10-03 10:37:30.868518 | controller | skipping: Conditional result was False
2025-10-03 10:37:30.884759 | 
2025-10-03 10:37:30.884887 | TASK [write-devstack-local-conf : Write a job-specific local_conf file]
2025-10-03 10:37:31.363514 | controller | ok
2025-10-03 10:37:31.451750 | 
2025-10-03 10:37:31.451858 | PLAY RECAP
2025-10-03 10:37:31.451898 | controller | ok: 39 changed: 24 unreachable: 0 failed: 0 skipped: 16 rescued: 0 ignored: 1
2025-10-03 10:37:31.451918 | 
2025-10-03 10:37:31.570942 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/pre.yaml@master]
2025-10-03 10:37:31.579850 | RUN START: [untrusted : opendev.org/openstack/tempest/playbooks/devstack-tempest.yaml@master]
2025-10-03 10:37:32.204317 | 
2025-10-03 10:37:32.204479 | PLAY [all]
2025-10-03 10:37:32.226727 | 
2025-10-03 10:37:32.226863 | TASK [Run devstack on the controller]
2025-10-03 10:37:32.246720 | controller | ok
2025-10-03 10:37:32.261797 | 
2025-10-03 10:37:32.261921 | TASK [run-devstack : Run devstack]
2025-10-03 06:37:32.902631 | controller | + unset GREP_OPTIONS
2025-10-03 06:37:32.902698 | controller | + unset LANG
2025-10-03 06:37:32.903329 | controller | + unset LANGUAGE
2025-10-03 06:37:32.903345 | controller | + LC_ALL=en_US.utf8
2025-10-03 06:37:32.903352 | controller | + export LC_ALL
2025-10-03 06:37:32.903362 | controller | ++ env
2025-10-03 06:37:32.903508 | controller | ++ grep -E '^OS_'
2025-10-03 06:37:32.903713 | controller | ++ cut -d = -f 1
2025-10-03 06:37:32.906445 | controller | + unset
2025-10-03 06:37:32.906466 | controller | + umask 022
2025-10-03 06:37:32.907183 | controller | + PATH=/sbin:/bin:/usr/sbin:/usr/bin:/usr/local/bin:/usr/local/sbin:/usr/sbin:/sbin
2025-10-03 06:37:32.907201 | controller | +++ dirname ./stack.sh
2025-10-03 06:37:32.908833 | controller | ++ cd .
2025-10-03 06:37:32.909060 | controller | ++ pwd
2025-10-03 06:37:32.909074 | controller | + TOP_DIR=/opt/stack/devstack
2025-10-03 06:37:32.909103 | controller | + NOUNSET=
2025-10-03 06:37:32.909138 | controller | + [[ -n '' ]]
2025-10-03 06:37:32.909462 | controller | ++ date +%s
2025-10-03 06:37:32.910443 | controller | + DEVSTACK_START_TIME=1759487852
2025-10-03 06:37:32.910460 | controller | + [[ -r /opt/stack/devstack/.stackenv ]]
2025-10-03 06:37:32.910493 | controller | + FILES=/opt/stack/devstack/files
2025-10-03 06:37:32.910502 | controller | + '[' '!' -d /opt/stack/devstack/files ']'
2025-10-03 06:37:32.910538 | controller | + '[' '!' -d /opt/stack/devstack/inc ']'
2025-10-03 06:37:32.910561 | controller | + '[' '!' -d /opt/stack/devstack/lib ']'
2025-10-03 06:37:32.910570 | controller | + [[ '' == \y ]]
2025-10-03 06:37:32.910634 | controller | + [[ 1003 -eq 0 ]]
2025-10-03 06:37:32.910643 | controller | + [[ -n '' ]]
2025-10-03 06:37:32.910649 | controller | + [[ -e /opt/stack/.no-devstack ]]
2025-10-03 06:37:32.910655 | controller | + LAST_SPINNER_PID=
2025-10-03 06:37:32.910662 | controller | + source /opt/stack/devstack/functions
2025-10-03 06:37:32.910707 | controller | ++ [[ -z '' ]]
2025-10-03 06:37:32.910715 | controller | ++ declare -r -g _DEVSTACK_FUNCTIONS=1
2025-10-03 06:37:32.911452 | controller | ++++ dirname /opt/stack/devstack/functions
2025-10-03 06:37:32.912435 | controller | +++ cd /opt/stack/devstack
2025-10-03 06:37:32.912463 | controller | +++ pwd
2025-10-03 06:37:32.912685 | controller | ++ FUNC_DIR=/opt/stack/devstack
2025-10-03 06:37:32.912700 | controller | ++ source /opt/stack/devstack/functions-common
2025-10-03 06:37:32.913580 | controller | ++++ set +o
2025-10-03 06:37:32.913696 | controller | ++++ grep xtrace
2025-10-03 06:37:32.916447 | controller | +++ _XTRACE_FUNCTIONS_COMMON='set -o xtrace'
2025-10-03 06:37:32.923394 | controller | +++ set +o xtrace
2025-10-03 06:37:32.923419 | controller | ++ source /opt/stack/devstack/inc/ini-config
2025-10-03 06:37:32.924684 | controller | ++++ set +o
2025-10-03 06:37:32.925200 | controller | ++++ grep xtrace
2025-10-03 06:37:32.928255 | controller | +++ INC_CONF_TRACE='set -o xtrace'
2025-10-03 06:37:32.928276 | controller | +++ set +o xtrace
2025-10-03 06:37:32.929178 | controller | ++ source /opt/stack/devstack/inc/meta-config
2025-10-03 06:37:32.930142 | controller | ++++ grep xtrace
2025-10-03 06:37:32.932179 | controller | ++++ set +o
2025-10-03 06:37:32.932229 | controller | +++ _XTRACE_INC_META='set -o xtrace'
2025-10-03 06:37:32.932506 | controller | +++ set +o xtrace
2025-10-03 06:37:32.932525 | controller | ++ source /opt/stack/devstack/inc/python
2025-10-03 06:37:32.933650 | controller | ++++ grep xtrace
2025-10-03 06:37:32.935387 | controller | ++++ set +o
2025-10-03 06:37:32.935407 | controller | +++ INC_PY_TRACE='set -o xtrace'
2025-10-03 06:37:32.936225 | controller | +++ set +o xtrace
2025-10-03 06:37:32.936248 | controller | ++ source /opt/stack/devstack/inc/rootwrap
2025-10-03 06:37:32.937182 | controller | ++++ set +o
2025-10-03 06:37:32.937378 | controller | ++++ grep xtrace
2025-10-03 06:37:32.939215 | controller | +++ INC_ROOT_TRACE='set -o xtrace'
2025-10-03 06:37:32.939234 | controller | +++ set +o xtrace
2025-10-03 06:37:32.939481 | controller | ++ source /opt/stack/devstack/inc/async
2025-10-03 06:37:32.940273 | controller | ++++ trueorfalse True DEVSTACK_PARALLEL
2025-10-03 06:37:32.940986 | controller | ++++ local xtrace
2025-10-03 06:37:32.941005 | controller | +++++ set +o
2025-10-03 06:37:32.941184 | controller | +++++ grep xtrace
2025-10-03 06:37:32.942764 | controller | ++++ xtrace='set -o xtrace'
2025-10-03 06:37:32.942812 | controller | ++++ set +o xtrace
2025-10-03 06:37:32.943297 | controller | +++ DEVSTACK_PARALLEL=True
2025-10-03 06:37:32.943312 | controller | +++ _ASYNC_BG_TIME=0
2025-10-03 06:37:32.944648 | controller | +++ set +o
2025-10-03 06:37:32.944864 | controller | +++ grep xtrace
2025-10-03 06:37:32.946837 | controller | ++ _XTRACE_FUNCTIONS='set -o xtrace'
2025-10-03 06:37:32.946855 | controller | ++ set +o xtrace
2025-10-03 06:37:32.948512 | controller | + source /opt/stack/devstack/lib/stack
2025-10-03 06:37:32.948623 | controller | + GetDistro
2025-10-03 06:37:32.948650 | controller | + GetOSVersion
2025-10-03 06:37:32.948667 | controller | + source /etc/os-release
2025-10-03 06:37:32.948674 | controller | ++ NAME='CentOS Stream'
2025-10-03 06:37:32.948684 | controller | ++ VERSION='10 (Coughlan)'
2025-10-03 06:37:32.948691 | controller | ++ ID=centos
2025-10-03 06:37:32.948697 | controller | ++ ID_LIKE='rhel fedora'
2025-10-03 06:37:32.948706 | controller | ++ VERSION_ID=10
2025-10-03 06:37:32.948712 | controller | ++ PLATFORM_ID=platform:el10
2025-10-03 06:37:32.948718 | controller | ++ PRETTY_NAME='CentOS Stream 10 (Coughlan)'
2025-10-03 06:37:32.948725 | controller | ++ ANSI_COLOR='0;31'
2025-10-03 06:37:32.948731 | controller | ++ LOGO=fedora-logo-icon
2025-10-03 06:37:32.948755 | controller | ++ CPE_NAME=cpe:/o:centos:centos:10
2025-10-03 06:37:32.948762 | controller | ++ HOME_URL=https://centos.org/
2025-10-03 06:37:32.948768 | controller | ++ VENDOR_NAME=CentOS
2025-10-03 06:37:32.948774 | controller | ++ VENDOR_URL=https://centos.org/
2025-10-03 06:37:32.948780 | controller | ++ BUG_REPORT_URL=https://issues.redhat.com/
2025-10-03 06:37:32.948786 | controller | ++ REDHAT_SUPPORT_PRODUCT='Red Hat Enterprise Linux 10'
2025-10-03 06:37:32.948793 | controller | ++ REDHAT_SUPPORT_PRODUCT_VERSION='CentOS Stream'
2025-10-03 06:37:32.948801 | controller | + [[ centos =~ (centos|rocky|rhel) ]]
2025-10-03 06:37:32.948831 | controller | + os_RELEASE=10
2025-10-03 06:37:32.949698 | controller | ++ echo 10 '(Coughlan)'
2025-10-03 06:37:32.949864 | controller | ++ grep -oP '(?<=[(])[^)]*'
2025-10-03 06:37:32.951650 | controller | + os_CODENAME=Coughlan
2025-10-03 06:37:32.952467 | controller | ++ echo CentOS Stream
2025-10-03 06:37:32.952632 | controller | ++ tr -d '[:space:]'
2025-10-03 06:37:32.953985 | controller | + os_VENDOR=CentOSStream
2025-10-03 06:37:32.954016 | controller | + [[ CentOSStream =~ (Debian|Ubuntu) ]]
2025-10-03 06:37:32.954024 | controller | + os_PACKAGE=rpm
2025-10-03 06:37:32.954030 | controller | + typeset -xr os_VENDOR
2025-10-03 06:37:32.954037 | controller | + typeset -xr os_RELEASE
2025-10-03 06:37:32.954043 | controller | + typeset -xr os_PACKAGE
2025-10-03 06:37:32.954050 | controller | + typeset -xr os_CODENAME
2025-10-03 06:37:32.954081 | controller | + [[ CentOSStream =~ (Ubuntu) ]]
2025-10-03 06:37:32.954088 | controller | + [[ CentOSStream =~ (Debian) ]]
2025-10-03 06:37:32.954096 | controller | + [[ CentOSStream =~ (Fedora) ]]
2025-10-03 06:37:32.954103 | controller | + [[ CentOSStream =~ (Red.*Hat) ]]
2025-10-03 06:37:32.954127 | controller | + [[ CentOSStream =~ (CentOS) ]]
2025-10-03 06:37:32.955048 | controller | ++ echo 10
2025-10-03 06:37:32.955170 | controller | ++ cut -d. -f1
2025-10-03 06:37:32.956507 | controller | + MAJOR_VERSION=10
2025-10-03 06:37:32.956524 | controller | + DISTRO=rhel10
2025-10-03 06:37:32.956532 | controller | + typeset -xr DISTRO
2025-10-03 06:37:32.956614 | controller | + rm -f /opt/stack/devstack/.localrc.auto
2025-10-03 06:37:32.957887 | controller | + extract_localrc_section /opt/stack/devstack/local.conf /opt/stack/devstack/localrc /opt/stack/devstack/.localrc.auto
2025-10-03 06:37:32.957902 | controller | + local configfile=/opt/stack/devstack/local.conf
2025-10-03 06:37:32.957910 | controller | + local localrcfile=/opt/stack/devstack/localrc
2025-10-03 06:37:32.957917 | controller | + local localautofile=/opt/stack/devstack/.localrc.auto
2025-10-03 06:37:32.957925 | controller | + [[ -r /opt/stack/devstack/local.conf ]]
2025-10-03 06:37:32.958613 | controller | ++ get_meta_section_files /opt/stack/devstack/local.conf local
2025-10-03 06:37:32.960725 | controller | ++ local file=/opt/stack/devstack/local.conf
2025-10-03 06:37:32.960751 | controller | ++ local matchgroup=local
2025-10-03 06:37:32.960760 | controller | ++ [[ -r /opt/stack/devstack/local.conf ]]
2025-10-03 06:37:32.960770 | controller | ++ awk -v matchgroup=local '
2025-10-03 06:37:32.960777 | controller |         /^\[\[.+\|.*\]\]/ {
2025-10-03 06:37:32.960784 | controller |             gsub("[][]", "", $1);
2025-10-03 06:37:32.960790 | controller |             split($1, a, "|");
2025-10-03 06:37:32.960796 | controller |             if (a[1] == matchgroup)
2025-10-03 06:37:32.960801 | controller |                 print a[2]
2025-10-03 06:37:32.960807 | controller |         }
2025-10-03 06:37:32.960812 | controller |     ' /opt/stack/devstack/local.conf
2025-10-03 06:37:32.960821 | controller | + LRC=localrc
2025-10-03 06:37:32.960919 | controller | + for lfile in $LRC
2025-10-03 06:37:32.960926 | controller | + [[ localrc == \l\o\c\a\l\r\c ]]
2025-10-03 06:37:32.960932 | controller | + [[ -r /opt/stack/devstack/localrc ]]
2025-10-03 06:37:32.960937 | controller | + echo '# Generated file, do not edit'
2025-10-03 06:37:32.960945 | controller | + get_meta_section /opt/stack/devstack/local.conf local localrc
2025-10-03 06:37:32.960952 | controller | + local file=/opt/stack/devstack/local.conf
2025-10-03 06:37:32.960960 | controller | + local matchgroup=local
2025-10-03 06:37:32.960971 | controller | + local configfile=localrc
2025-10-03 06:37:32.960978 | controller | + [[ -r /opt/stack/devstack/local.conf ]]
2025-10-03 06:37:32.961003 | controller | + [[ -z localrc ]]
2025-10-03 06:37:32.961011 | controller | + awk -v matchgroup=local -v configfile=localrc '
2025-10-03 06:37:32.963770 | controller |         BEGIN { group = "" }
2025-10-03 06:37:32.963786 | controller |         /^\[\[.+\|.*\]\]/ {
2025-10-03 06:37:32.963792 | controller |             gsub("[][]", "", $1);
2025-10-03 06:37:32.963798 | controller |             split($1, a, "|");
2025-10-03 06:37:32.963804 | controller |             if (a[1] == matchgroup && a[2] == configfile) {
2025-10-03 06:37:32.963810 | controller |                 group=a[1]
2025-10-03 06:37:32.963815 | controller |             } else {
2025-10-03 06:37:32.963821 | controller |                 group=""
2025-10-03 06:37:32.963827 | controller |             }
2025-10-03 06:37:32.963832 | controller |             next
2025-10-03 06:37:32.963838 | controller |         }
2025-10-03 06:37:32.963844 | controller |         {
2025-10-03 06:37:32.963850 | controller |             if (group != "")
2025-10-03 06:37:32.963855 | controller |                 print $0
2025-10-03 06:37:32.963861 | controller |         }
2025-10-03 06:37:32.963866 | controller |     ' /opt/stack/devstack/local.conf
2025-10-03 06:37:32.963876 | controller | + [[ ! -r /opt/stack/devstack/stackrc ]]
2025-10-03 06:37:32.964830 | controller | + source /opt/stack/devstack/stackrc
2025-10-03 06:37:32.964845 | controller | ++ [[ -z '' ]]
2025-10-03 06:37:32.964852 | controller | ++ declare -r -g _DEVSTACK_STACKRC=1
2025-10-03 06:37:32.964861 | controller | ++++ dirname /opt/stack/devstack/stackrc
2025-10-03 06:37:32.965924 | controller | +++ cd /opt/stack/devstack
2025-10-03 06:37:32.965946 | controller | +++ pwd
2025-10-03 06:37:32.966287 | controller | ++ RC_DIR=/opt/stack/devstack
2025-10-03 06:37:32.966300 | controller | ++ source /opt/stack/devstack/functions
2025-10-03 06:37:32.966370 | controller | +++ [[ -z 1 ]]
2025-10-03 06:37:32.966378 | controller | +++ return 0
2025-10-03 06:37:32.966385 | controller | ++ TARGET_BRANCH=master
2025-10-03 06:37:32.966391 | controller | ++ TRAILING_TARGET_BRANCH=master
2025-10-03 06:37:32.966397 | controller | ++ BRANCHLESS_TARGET_BRANCH=master
2025-10-03 06:37:32.966404 | controller | ++ DEST=/opt/stack
2025-10-03 06:37:32.966410 | controller | ++ DATA_DIR=/opt/stack/data
2025-10-03 06:37:32.966416 | controller | ++ SERVICE_DIR=/opt/stack/status
2025-10-03 06:37:32.966423 | controller | ++ SUBUNIT_OUTPUT=/opt/stack/devstack.subunit
2025-10-03 06:37:32.966430 | controller | ++ [[ 1003 -eq 0 ]]
2025-10-03 06:37:32.966873 | controller | +++ whoami
2025-10-03 06:37:32.968848 | controller | ++ STACK_USER=stack
2025-10-03 06:37:32.968893 | controller | ++ REGION_NAME=RegionOne
2025-10-03 06:37:32.969055 | controller | ++ KEYSTONE_REGION_NAME=RegionOne
2025-10-03 06:37:32.969072 | controller | ++ isset ENABLED_SERVICES
2025-10-03 06:37:32.969098 | controller | ++ [[ -v ENABLED_SERVICES ]]
2025-10-03 06:37:32.969105 | controller | ++ ENABLED_SERVICES=key
2025-10-03 06:37:32.969111 | controller | ++ ENABLED_SERVICES+=,n-api,n-cpu,n-cond,n-sch,n-novnc,n-api-meta
2025-10-03 06:37:32.969116 | controller | ++ ENABLED_SERVICES+=,placement-api,placement-client
2025-10-03 06:37:32.969122 | controller | ++ ENABLED_SERVICES+=,g-api
2025-10-03 06:37:32.969127 | controller | ++ ENABLED_SERVICES+=,c-sch,c-api,c-vol
2025-10-03 06:37:32.969133 | controller | ++ ENABLED_SERVICES+=,ovn-controller,ovn-northd,ovs-vswitchd,ovsdb-server
2025-10-03 06:37:32.969141 | controller | ++ ENABLED_SERVICES+=,q-svc,q-ovn-agent
2025-10-03 06:37:32.969147 | controller | ++ ENABLED_SERVICES+=,horizon
2025-10-03 06:37:32.969152 | controller | ++ ENABLED_SERVICES+=,rabbit,tempest,mysql,etcd3,dstat
2025-10-03 06:37:32.969158 | controller | ++ ENABLE_HTTPD_MOD_WSGI_SERVICES=True
2025-10-03 06:37:32.969164 | controller | ++ NOVA_ENABLED_APIS=osapi_compute,metadata
2025-10-03 06:37:32.969169 | controller | ++ [[ -f /opt/stack/devstack/localrc ]]
2025-10-03 06:37:32.969175 | controller | ++ [[ -f /opt/stack/devstack/.localrc.auto ]]
2025-10-03 06:37:32.969193 | controller | ++ source /opt/stack/devstack/.localrc.auto
2025-10-03 06:37:32.969199 | controller | +++ disable_all_services
2025-10-03 06:37:32.969204 | controller | +++ ENABLED_SERVICES=
2025-10-03 06:37:32.969210 | controller | +++ enable_service c-api
2025-10-03 06:37:32.969218 | controller | +++ local xtrace
2025-10-03 06:37:32.970181 | controller | ++++ set +o
2025-10-03 06:37:32.971809 | controller | ++++ grep xtrace
2025-10-03 06:37:32.971829 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:32.992052 | controller | +++ set +o xtrace
2025-10-03 06:37:32.992099 | controller | +++ enable_service c-bak
2025-10-03 06:37:32.993001 | controller | +++ local xtrace
2025-10-03 06:37:32.993029 | controller | ++++ set +o
2025-10-03 06:37:32.993177 | controller | ++++ grep xtrace
2025-10-03 06:37:32.995018 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:32.995038 | controller | +++ set +o xtrace
2025-10-03 06:37:33.018528 | controller | +++ enable_service c-sch
2025-10-03 06:37:33.019387 | controller | +++ local xtrace
2025-10-03 06:37:33.019410 | controller | ++++ set +o
2025-10-03 06:37:33.019560 | controller | ++++ grep xtrace
2025-10-03 06:37:33.021445 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.021464 | controller | +++ set +o xtrace
2025-10-03 06:37:33.042626 | controller | +++ enable_service c-vol
2025-10-03 06:37:33.043366 | controller | +++ local xtrace
2025-10-03 06:37:33.043400 | controller | ++++ set +o
2025-10-03 06:37:33.043482 | controller | ++++ grep xtrace
2025-10-03 06:37:33.045143 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.065513 | controller | +++ set +o xtrace
2025-10-03 06:37:33.065539 | controller | +++ disable_service dstat
2025-10-03 06:37:33.066393 | controller | +++ local xtrace
2025-10-03 06:37:33.066416 | controller | ++++ set +o
2025-10-03 06:37:33.066798 | controller | ++++ grep xtrace
2025-10-03 06:37:33.069753 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.086467 | controller | +++ set +o xtrace
2025-10-03 06:37:33.086496 | controller | +++ enable_service etcd3
2025-10-03 06:37:33.087070 | controller | +++ local xtrace
2025-10-03 06:37:33.087094 | controller | ++++ set +o
2025-10-03 06:37:33.088765 | controller | ++++ grep xtrace
2025-10-03 06:37:33.088803 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.110726 | controller | +++ set +o xtrace
2025-10-03 06:37:33.110771 | controller | +++ enable_service file_tracker
2025-10-03 06:37:33.110867 | controller | +++ local xtrace
2025-10-03 06:37:33.111812 | controller | ++++ set +o
2025-10-03 06:37:33.111967 | controller | ++++ grep xtrace
2025-10-03 06:37:33.113592 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.113725 | controller | +++ set +o xtrace
2025-10-03 06:37:33.137262 | controller | +++ enable_service g-api
2025-10-03 06:37:33.137534 | controller | +++ local xtrace
2025-10-03 06:37:33.138092 | controller | ++++ set +o
2025-10-03 06:37:33.138283 | controller | ++++ grep xtrace
2025-10-03 06:37:33.140089 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.140137 | controller | +++ set +o xtrace
2025-10-03 06:37:33.162958 | controller | +++ enable_service horizon
2025-10-03 06:37:33.163005 | controller | +++ local xtrace
2025-10-03 06:37:33.163979 | controller | ++++ set +o
2025-10-03 06:37:33.164192 | controller | ++++ grep xtrace
2025-10-03 06:37:33.166285 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.187492 | controller | +++ set +o xtrace
2025-10-03 06:37:33.187538 | controller | +++ enable_service key
2025-10-03 06:37:33.187573 | controller | +++ local xtrace
2025-10-03 06:37:33.188409 | controller | ++++ set +o
2025-10-03 06:37:33.188554 | controller | ++++ grep xtrace
2025-10-03 06:37:33.190261 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.190311 | controller | +++ set +o xtrace
2025-10-03 06:37:33.210351 | controller | +++ enable_service memory_tracker
2025-10-03 06:37:33.210430 | controller | +++ local xtrace
2025-10-03 06:37:33.211436 | controller | ++++ set +o
2025-10-03 06:37:33.211625 | controller | ++++ grep xtrace
2025-10-03 06:37:33.213592 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.235455 | controller | +++ set +o xtrace
2025-10-03 06:37:33.235476 | controller | +++ enable_service mysql
2025-10-03 06:37:33.235578 | controller | +++ local xtrace
2025-10-03 06:37:33.236505 | controller | ++++ set +o
2025-10-03 06:37:33.236652 | controller | ++++ grep xtrace
2025-10-03 06:37:33.238952 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.239169 | controller | +++ set +o xtrace
2025-10-03 06:37:33.261966 | controller | +++ enable_service n-api
2025-10-03 06:37:33.262011 | controller | +++ local xtrace
2025-10-03 06:37:33.262819 | controller | ++++ set +o
2025-10-03 06:37:33.263060 | controller | ++++ grep xtrace
2025-10-03 06:37:33.265790 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.265839 | controller | +++ set +o xtrace
2025-10-03 06:37:33.295786 | controller | +++ enable_service n-api-meta
2025-10-03 06:37:33.296628 | controller | +++ local xtrace
2025-10-03 06:37:33.296640 | controller | ++++ set +o
2025-10-03 06:37:33.297101 | controller | ++++ grep xtrace
2025-10-03 06:37:33.299839 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.325570 | controller | +++ set +o xtrace
2025-10-03 06:37:33.325599 | controller | +++ enable_service n-cond
2025-10-03 06:37:33.325632 | controller | +++ local xtrace
2025-10-03 06:37:33.326519 | controller | ++++ set +o
2025-10-03 06:37:33.326793 | controller | ++++ grep xtrace
2025-10-03 06:37:33.329842 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.329890 | controller | +++ set +o xtrace
2025-10-03 06:37:33.357347 | controller | +++ enable_service n-cpu
2025-10-03 06:37:33.357436 | controller | +++ local xtrace
2025-10-03 06:37:33.358305 | controller | ++++ set +o
2025-10-03 06:37:33.358533 | controller | ++++ grep xtrace
2025-10-03 06:37:33.361768 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.392582 | controller | +++ set +o xtrace
2025-10-03 06:37:33.392619 | controller | +++ enable_service n-novnc
2025-10-03 06:37:33.393573 | controller | +++ local xtrace
2025-10-03 06:37:33.393594 | controller | ++++ set +o
2025-10-03 06:37:33.394005 | controller | ++++ grep xtrace
2025-10-03 06:37:33.397535 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.429168 | controller | +++ set +o xtrace
2025-10-03 06:37:33.429240 | controller | +++ enable_service n-sch
2025-10-03 06:37:33.430259 | controller | +++ local xtrace
2025-10-03 06:37:33.430278 | controller | ++++ set +o
2025-10-03 06:37:33.430632 | controller | ++++ grep xtrace
2025-10-03 06:37:33.432489 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.432507 | controller | +++ set +o xtrace
2025-10-03 06:37:33.462372 | controller | +++ enable_service openstack-cli-server
2025-10-03 06:37:33.463273 | controller | +++ local xtrace
2025-10-03 06:37:33.463465 | controller | ++++ set +o
2025-10-03 06:37:33.465476 | controller | ++++ grep xtrace
2025-10-03 06:37:33.465496 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.489839 | controller | +++ set +o xtrace
2025-10-03 06:37:33.489907 | controller | +++ enable_service ovn-controller
2025-10-03 06:37:33.490802 | controller | +++ local xtrace
2025-10-03 06:37:33.490871 | controller | ++++ set +o
2025-10-03 06:37:33.490924 | controller | ++++ grep xtrace
2025-10-03 06:37:33.492797 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.515695 | controller | +++ set +o xtrace
2025-10-03 06:37:33.515719 | controller | +++ enable_service ovn-northd
2025-10-03 06:37:33.516809 | controller | +++ local xtrace
2025-10-03 06:37:33.516829 | controller | ++++ set +o
2025-10-03 06:37:33.519154 | controller | ++++ grep xtrace
2025-10-03 06:37:33.519170 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.541445 | controller | +++ set +o xtrace
2025-10-03 06:37:33.541496 | controller | +++ enable_service ovs-vswitchd
2025-10-03 06:37:33.542798 | controller | +++ local xtrace
2025-10-03 06:37:33.542865 | controller | ++++ set +o
2025-10-03 06:37:33.544776 | controller | ++++ grep xtrace
2025-10-03 06:37:33.544844 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.566215 | controller | +++ set +o xtrace
2025-10-03 06:37:33.566239 | controller | +++ enable_service ovsdb-server
2025-10-03 06:37:33.567411 | controller | +++ local xtrace
2025-10-03 06:37:33.567431 | controller | ++++ set +o
2025-10-03 06:37:33.568913 | controller | ++++ grep xtrace
2025-10-03 06:37:33.568931 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.591273 | controller | +++ set +o xtrace
2025-10-03 06:37:33.591297 | controller | +++ enable_service placement-api
2025-10-03 06:37:33.592187 | controller | +++ local xtrace
2025-10-03 06:37:33.592204 | controller | ++++ set +o
2025-10-03 06:37:33.592420 | controller | ++++ grep xtrace
2025-10-03 06:37:33.594677 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.594696 | controller | +++ set +o xtrace
2025-10-03 06:37:33.619139 | controller | +++ enable_service q-ovn-agent
2025-10-03 06:37:33.619160 | controller | +++ local xtrace
2025-10-03 06:37:33.619971 | controller | ++++ set +o
2025-10-03 06:37:33.620199 | controller | ++++ grep xtrace
2025-10-03 06:37:33.622265 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.622298 | controller | +++ set +o xtrace
2025-10-03 06:37:33.649456 | controller | +++ enable_service q-svc
2025-10-03 06:37:33.650419 | controller | +++ local xtrace
2025-10-03 06:37:33.650439 | controller | ++++ set +o
2025-10-03 06:37:33.650655 | controller | ++++ grep xtrace
2025-10-03 06:37:33.652584 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.675333 | controller | +++ set +o xtrace
2025-10-03 06:37:33.675356 | controller | +++ enable_service rabbit
2025-10-03 06:37:33.676108 | controller | +++ local xtrace
2025-10-03 06:37:33.676168 | controller | ++++ set +o
2025-10-03 06:37:33.676260 | controller | ++++ grep xtrace
2025-10-03 06:37:33.678071 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.678176 | controller | +++ set +o xtrace
2025-10-03 06:37:33.700151 | controller | +++ enable_service s-account
2025-10-03 06:37:33.700291 | controller | +++ local xtrace
2025-10-03 06:37:33.701667 | controller | ++++ set +o
2025-10-03 06:37:33.704365 | controller | ++++ grep xtrace
2025-10-03 06:37:33.704434 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.740491 | controller | +++ set +o xtrace
2025-10-03 06:37:33.740560 | controller | +++ enable_service s-container
2025-10-03 06:37:33.741807 | controller | +++ local xtrace
2025-10-03 06:37:33.741878 | controller | ++++ set +o
2025-10-03 06:37:33.744211 | controller | ++++ grep xtrace
2025-10-03 06:37:33.744240 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.744310 | controller | +++ set +o xtrace
2025-10-03 06:37:33.771687 | controller | +++ enable_service s-object
2025-10-03 06:37:33.772840 | controller | +++ local xtrace
2025-10-03 06:37:33.772876 | controller | ++++ set +o
2025-10-03 06:37:33.773068 | controller | ++++ grep xtrace
2025-10-03 06:37:33.775376 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.775479 | controller | +++ set +o xtrace
2025-10-03 06:37:33.802842 | controller | +++ enable_service s-proxy
2025-10-03 06:37:33.803097 | controller | +++ local xtrace
2025-10-03 06:37:33.805086 | controller | ++++ set +o
2025-10-03 06:37:33.805549 | controller | ++++ grep xtrace
2025-10-03 06:37:33.807665 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.807684 | controller | +++ set +o xtrace
2025-10-03 06:37:33.833958 | controller | +++ enable_service tempest
2025-10-03 06:37:33.835300 | controller | +++ local xtrace
2025-10-03 06:37:33.835319 | controller | ++++ set +o
2025-10-03 06:37:33.835487 | controller | ++++ grep xtrace
2025-10-03 06:37:33.837570 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.837643 | controller | +++ set +o xtrace
2025-10-03 06:37:33.864094 | controller | +++ enable_service tls-proxy
2025-10-03 06:37:33.865176 | controller | +++ local xtrace
2025-10-03 06:37:33.865195 | controller | ++++ set +o
2025-10-03 06:37:33.866114 | controller | ++++ grep xtrace
2025-10-03 06:37:33.868361 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.894487 | controller | +++ set +o xtrace
2025-10-03 06:37:33.894521 | controller | +++ ADMIN_PASSWORD=secretadmin
2025-10-03 06:37:33.894553 | controller | +++ DATABASE_PASSWORD=secretdatabase
2025-10-03 06:37:33.894562 | controller | +++ DEBUG_LIBVIRT_COREDUMPS=True
2025-10-03 06:37:33.894569 | controller | +++ ENABLE_SYSCTL_MEM_TUNING=True
2025-10-03 06:37:33.894598 | controller | +++ ENABLE_SYSCTL_NET_TUNING=True
2025-10-03 06:37:33.894604 | controller | +++ ENABLE_VOLUME_MULTIATTACH=True
2025-10-03 06:37:33.894629 | controller | +++ ENABLE_ZSWAP=True
2025-10-03 06:37:33.894635 | controller | +++ ERROR_ON_CLONE=True
2025-10-03 06:37:33.894641 | controller | +++ FIXED_RANGE=10.1.0.0/20
2025-10-03 06:37:33.894646 | controller | +++ FLOATING_RANGE=172.24.5.0/24
2025-10-03 06:37:33.894652 | controller | +++ FORCE_CONFIG_DRIVE=True
2025-10-03 06:37:33.894658 | controller | +++ GLANCE_USE_IMPORT_WORKFLOW=True
2025-10-03 06:37:33.894663 | controller | +++ HOST_IP=38.102.83.227
2025-10-03 06:37:33.894672 | controller | +++ IMAGE_URLS='http://download.cirros-cloud.net/0.6.2/cirros-0.6.2-x86_64-disk.img, http://download.cirros-cloud.net/0.6.1/cirros-0.6.1-x86_64-disk.img'
2025-10-03 06:37:33.894718 | controller | +++ IPV4_ADDRS_SAFE_TO_USE=10.1.0.0/20
2025-10-03 06:37:33.894787 | controller | +++ LIBVIRT_TYPE=qemu
2025-10-03 06:37:33.894794 | controller | +++ LOGFILE=/opt/stack/logs/devstacklog.txt
2025-10-03 06:37:33.894800 | controller | +++ LOG_COLOR=False
2025-10-03 06:37:33.894805 | controller | +++ NETWORK_GATEWAY=10.1.0.1
2025-10-03 06:37:33.894811 | controller | +++ NOVA_LIBVIRT_TB_CACHE_SIZE=128
2025-10-03 06:37:33.894823 | controller | +++ NOVA_VNC_ENABLED=True
2025-10-03 06:37:33.894830 | controller | +++ OVN_DBS_LOG_LEVEL=dbg
2025-10-03 06:37:33.894837 | controller | +++ PUBLIC_BRIDGE_MTU=1430
2025-10-03 06:37:33.894849 | controller | +++ PUBLIC_NETWORK_GATEWAY=172.24.5.1
2025-10-03 06:37:33.894857 | controller | +++ PYTHON3_VERSION=3.12
2025-10-03 06:37:33.894865 | controller | +++ RABBIT_PASSWORD=secretrabbit
2025-10-03 06:37:33.894870 | controller | +++ SERVICE_HOST=38.102.83.227
2025-10-03 06:37:33.894876 | controller | +++ SERVICE_PASSWORD=secretservice
2025-10-03 06:37:33.894881 | controller | +++ SWIFT_HASH=1234123412341234
2025-10-03 06:37:33.894887 | controller | +++ SWIFT_REPLICAS=1
2025-10-03 06:37:33.894893 | controller | +++ SWIFT_START_ALL_SERVICES=False
2025-10-03 06:37:33.894898 | controller | +++ USE_PYTHON3=True
2025-10-03 06:37:33.894903 | controller | +++ VERBOSE=True
2025-10-03 06:37:33.894909 | controller | +++ VERBOSE_NO_TIMESTAMP=True
2025-10-03 06:37:33.894915 | controller | +++ LIBS_FROM_GIT=novnc,cinder,devstack,glance,horizon,keystone,neutron,nova,os-test-images,placement,requirements,swift,tempest
2025-10-03 06:37:33.894920 | controller | +++ enable_plugin neutron https://opendev.org/openstack/neutron
2025-10-03 06:37:33.894926 | controller | +++ local name=neutron
2025-10-03 06:37:33.894932 | controller | +++ local url=https://opendev.org/openstack/neutron
2025-10-03 06:37:33.894941 | controller | +++ local branch=master
2025-10-03 06:37:33.895046 | controller | +++ is_plugin_enabled neutron
2025-10-03 06:37:33.895055 | controller | +++ local name=neutron
2025-10-03 06:37:33.895060 | controller | +++ [[ ,, =~ ,neutron, ]]
2025-10-03 06:37:33.895066 | controller | +++ return 1
2025-10-03 06:37:33.895072 | controller | +++ DEVSTACK_PLUGINS+=,neutron
2025-10-03 06:37:33.895078 | controller | +++ GITREPO[$name]=https://opendev.org/openstack/neutron
2025-10-03 06:37:33.895089 | controller | +++ GITDIR[$name]=/opt/stack/neutron
2025-10-03 06:37:33.895095 | controller | +++ GITBRANCH[$name]=master
2025-10-03 06:37:33.895116 | controller | ++ CELLSV2_SETUP=superconductor
2025-10-03 06:37:33.895840 | controller | ++ HORIZON_APACHE_ROOT=/dashboard
2025-10-03 06:37:33.895860 | controller | +++ trueorfalse False USER_UNITS
2025-10-03 06:37:33.895976 | controller | +++ local xtrace
2025-10-03 06:37:33.897326 | controller | ++++ set +o
2025-10-03 06:37:33.900443 | controller | ++++ grep xtrace
2025-10-03 06:37:33.900463 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.901159 | controller | +++ set +o xtrace
2025-10-03 06:37:33.901180 | controller | ++ USER_UNITS=False
2025-10-03 06:37:33.901254 | controller | ++ [[ False == \T\r\u\e ]]
2025-10-03 06:37:33.901881 | controller | ++ SYSTEMD_DIR=/etc/systemd/system
2025-10-03 06:37:33.901899 | controller | ++ SYSTEMCTL='sudo systemctl'
2025-10-03 06:37:33.901905 | controller | ++ [[ -r /opt/stack/devstack/.localrc.password ]]
2025-10-03 06:37:33.901914 | controller | +++ _get_python_version python3
2025-10-03 06:37:33.902001 | controller | +++ local interp=python3
2025-10-03 06:37:33.902760 | controller | +++ local version
2025-10-03 06:37:33.902782 | controller | ++++ which python3
2025-10-03 06:37:33.904666 | controller | +++ [[ -x /bin/python3 ]]
2025-10-03 06:37:33.905364 | controller | ++++ python3 -c 'import sys; print("%s.%s" % sys.version_info[0:2])'
2025-10-03 06:37:33.918087 | controller | +++ version=3.12
2025-10-03 06:37:33.918111 | controller | +++ echo 3.12
2025-10-03 06:37:33.918505 | controller | ++ _DEFAULT_PYTHON3_VERSION=3.12
2025-10-03 06:37:33.918554 | controller | ++ export PYTHON3_VERSION=3.12
2025-10-03 06:37:33.918590 | controller | ++ PYTHON3_VERSION=3.12
2025-10-03 06:37:33.918599 | controller | ++ export 'VIRTUALENV_CMD=python3 -m venv'
2025-10-03 06:37:33.918655 | controller | ++ VIRTUALENV_CMD='python3 -m venv'
2025-10-03 06:37:33.918665 | controller | ++ '[' -t 1 ']'
2025-10-03 06:37:33.919430 | controller | ++ _LOG_COLOR_DEFAULT=False
2025-10-03 06:37:33.919456 | controller | +++ trueorfalse False LOG_COLOR
2025-10-03 06:37:33.919635 | controller | +++ local xtrace
2025-10-03 06:37:33.920774 | controller | ++++ set +o
2025-10-03 06:37:33.920947 | controller | ++++ grep xtrace
2025-10-03 06:37:33.923802 | controller | +++ xtrace='set -o xtrace'
2025-10-03 06:37:33.923822 | controller | +++ set +o xtrace
2025-10-03 06:37:33.924443 | controller | ++ LOG_COLOR=False
2025-10-03 06:37:33.924528 | controller | ++ [[ False == \T\r\u\e ]]
2025-10-03 06:37:33.924537 | controller | ++ export 'PS4=+ $(short_source):   '
2025-10-03 06:37:33.928171 | controller | ++ PS4='+ $(short_source):   '
2025-10-03 06:37:33.928248 | controller | +++ stackrc:source:167                       :   trueorfalse False ENFORCE_SCOPE
2025-10-03 06:37:33.930202 | controller | +++ functions-common:trueorfalse:222         :   local xtrace
2025-10-03 06:37:33.933811 | controller | ++++ functions-common:trueorfalse:223         :   set +o
2025-10-03 06:37:33.935108 | controller | ++++ functions-common:trueorfalse:223         :   grep xtrace
2025-10-03 06:37:33.939716 | controller | +++ functions-common:trueorfalse:223         :   xtrace='set -o xtrace'
2025-10-03 06:37:33.941907 | controller | +++ functions-common:trueorfalse:224         :   set +o xtrace
2025-10-03 06:37:33.944687 | controller | ++ stackrc:source:167                       :   ENFORCE_SCOPE=False
2025-10-03 06:37:33.947466 | controller | ++ stackrc:source:174                       :   DEVSTACK_VENV=/opt/stack/data/venv
2025-10-03 06:37:33.950252 | controller | ++ stackrc:source:180                       :   [[ CentOSStream =~ (CentOSStream|Rocky) ]]
2025-10-03 06:37:33.953939 | controller | +++ stackrc:source:181                       :   trueorfalse False GLOBAL_VENV
2025-10-03 06:37:33.956682 | controller | +++ functions-common:trueorfalse:222         :   local xtrace
2025-10-03 06:37:33.960803 | controller | ++++ functions-common:trueorfalse:223         :   set +o
2025-10-03 06:37:33.960949 | controller | ++++ functions-common:trueorfalse:223         :   grep xtrace
2025-10-03 06:37:33.966732 | controller | +++ functions-common:trueorfalse:223         :   xtrace='set -o xtrace'
2025-10-03 06:37:33.969162 | controller | +++ functions-common:trueorfalse:224         :   set +o xtrace
2025-10-03 06:37:33.972815 | controller | ++ stackrc:source:181                       :   GLOBAL_VENV=False
2025-10-03 06:37:33.976519 | controller | +++ stackrc:source:190                       :   trueorfalse False USE_VENV
2025-10-03 06:37:33.978841 | controller | +++ functions-common:trueorfalse:222         :   local xtrace
2025-10-03 06:37:33.983757 | controller | ++++ functions-common:trueorfalse:223         :   set +o
2025-10-03 06:37:33.984648 | controller | ++++ functions-common:trueorfalse:223         :   grep xtrace
2025-10-03 06:37:33.990304 | controller | +++ functions-common:trueorfalse:223         :   xtrace='set -o xtrace'
2025-10-03 06:37:33.992453 | controller | +++ functions-common:trueorfalse:224         :   set +o xtrace
2025-10-03 06:37:33.995618 | controller | ++ stackrc:source:190                       :   USE_VENV=False
2025-10-03 06:37:33.998435 | controller | ++ stackrc:source:195                       :   ADDITIONAL_VENV_PACKAGES=
2025-10-03 06:37:34.001894 | controller | +++ stackrc:source:199                       :   trueorfalse False DATABASE_QUERY_LOGGING
2025-10-03 06:37:34.004347 | controller | +++ functions-common:trueorfalse:222         :   local xtrace
2025-10-03 06:37:34.008336 | controller | ++++ functions-common:trueorfalse:223         :   grep xtrace
2025-10-03 06:37:34.010988 | controller | ++++ functions-common:trueorfalse:223         :   set +o
2025-10-03 06:37:34.013607 | controller | +++ functions-common:trueorfalse:223         :   xtrace='set -o xtrace'
2025-10-03 06:37:34.016123 | controller | +++ functions-common:trueorfalse:224         :   set +o xtrace
2025-10-03 06:37:34.019158 | controller | ++ stackrc:source:199                       :   DATABASE_QUERY_LOGGING=False
2025-10-03 06:37:34.022556 | controller | +++ stackrc:source:203                       :   trueorfalse True MYSQL_GATHER_PERFORMANCE
2025-10-03 06:37:34.024794 | controller | +++ functions-common:trueorfalse:222         :   local xtrace
2025-10-03 06:37:34.028728 | controller | ++++ functions-common:trueorfalse:223         :   set +o
2025-10-03 06:37:34.030467 | controller | ++++ functions-common:trueorfalse:223         :   grep xtrace
2025-10-03 06:37:34.035758 | controller | +++ functions-common:trueorfalse:223         :   xtrace='set -o xtrace'
2025-10-03 06:37:34.037817 | controller | +++ functions-common:trueorfalse:224         :   set +o xtrace
2025-10-03 06:37:34.040853 | controller | ++ stackrc:source:203                       :   MYSQL_GATHER_PERFORMANCE=True
2025-10-03 06:37:34.044459 | controller | +++ stackrc:source:208                       :   trueorfalse True MYSQL_REDUCE_MEMORY
2025-10-03 06:37:34.047047 | controller | +++ functions-common:trueorfalse:222         :   local xtrace
2025-10-03 06:37:34.050858 | controller | ++++ functions-common:trueorfalse:223         :   grep xtrace
2025-10-03 06:37:34.051137 | controller | ++++ functions-common:trueorfalse:223         :   set +o
2025-10-03 06:37:34.055499 | controller | +++ functions-common:trueorfalse:223         :   xtrace='set -o xtrace'
2025-10-03 06:37:34.057236 | controller | +++ functions-common:trueorfalse:224         :   set +o xtrace
2025-10-03 06:37:34.059717 | controller | ++ stackrc:source:208                       :   MYSQL_REDUCE_MEMORY=True
2025-10-03 06:37:34.062859 | controller | ++ stackrc:source:219                       :   GIT_TIMEOUT=0
2025-10-03 06:37:34.065322 | controller | ++ stackrc:source:225                       :   WSGI_MODE=uwsgi
2025-10-03 06:37:34.067586 | controller | ++ stackrc:source:226                       :   [[ uwsgi != \u\w\s\g\i ]]
2025-10-03 06:37:34.069404 | controller | ++ stackrc:source:234                       :   GIT_BASE=https://opendev.org
2025-10-03 06:37:34.071541 | controller | ++ stackrc:source:237                       :   REQUIREMENTS_DIR=/opt/stack/requirements
2025-10-03 06:37:34.074021 | controller | ++ stackrc:source:255                       :   DEVSTACK_SERIES=2026.1
2025-10-03 06:37:34.075932 | controller | ++ stackrc:source:264                       :   CINDER_REPO=https://opendev.org/openstack/cinder.git
2025-10-03 06:37:34.078397 | controller | ++ stackrc:source:265                       :   CINDER_BRANCH=master
2025-10-03 06:37:34.080837 | controller | ++ stackrc:source:268                       :   GLANCE_REPO=https://opendev.org/openstack/glance.git
2025-10-03 06:37:34.083006 | controller | ++ stackrc:source:269                       :   GLANCE_BRANCH=master
2025-10-03 06:37:34.085267 | controller | ++ stackrc:source:272                       :   HORIZON_REPO=https://opendev.org/openstack/horizon.git
2025-10-03 06:37:34.087454 | controller | ++ stackrc:source:273                       :   HORIZON_BRANCH=master
2025-10-03 06:37:34.089855 | controller | ++ stackrc:source:276                       :   KEYSTONE_REPO=https://opendev.org/openstack/keystone.git
2025-10-03 06:37:34.092462 | controller | ++ stackrc:source:277                       :   KEYSTONE_BRANCH=master
2025-10-03 06:37:34.095097 | controller | ++ stackrc:source:280                       :   NEUTRON_REPO=https://opendev.org/openstack/neutron.git
2025-10-03 06:37:34.097652 | controller | ++ stackrc:source:281                       :   NEUTRON_BRANCH=master
2025-10-03 06:37:34.100361 | controller | ++ stackrc:source:284                       :   NOVA_REPO=https://opendev.org/openstack/nova.git
2025-10-03 06:37:34.102922 | controller | ++ stackrc:source:285                       :   NOVA_BRANCH=master
2025-10-03 06:37:34.104881 | controller | ++ stackrc:source:288                       :   SWIFT_REPO=https://opendev.org/openstack/swift.git
2025-10-03 06:37:34.107323 | controller | ++ stackrc:source:289                       :   SWIFT_BRANCH=master
2025-10-03 06:37:34.109651 | controller | ++ stackrc:source:292                       :   PLACEMENT_REPO=https://opendev.org/openstack/placement.git
2025-10-03 06:37:34.111856 | controller | ++ stackrc:source:293                       :   PLACEMENT_BRANCH=master
2025-10-03 06:37:34.113630 | controller | ++ stackrc:source:302                       :   REQUIREMENTS_REPO=https://opendev.org/openstack/requirements.git
2025-10-03 06:37:34.114929 | controller | ++ stackrc:source:303                       :   REQUIREMENTS_BRANCH=master
2025-10-03 06:37:34.117561 | controller | ++ stackrc:source:306                       :   TEMPEST_REPO=https://opendev.org/openstack/tempest.git
2025-10-03 06:37:34.119881 | controller | ++ stackrc:source:307                       :   TEMPEST_BRANCH=master
2025-10-03 06:37:34.122052 | controller | ++ stackrc:source:308                       :   TEMPEST_VENV_UPPER_CONSTRAINTS=master
2025-10-03 06:37:34.123387 | controller | ++ stackrc:source:310                       :   OSTESTIMAGES_REPO=https://opendev.org/openstack/os-test-images.git
2025-10-03 06:37:34.125675 | controller | ++ stackrc:source:311                       :   OSTESTIMAGES_BRANCH=master
2025-10-03 06:37:34.127148 | controller | ++ stackrc:source:312                       :   OSTESTIMAGES_DIR=/opt/stack/os-test-images
2025-10-03 06:37:34.129142 | controller | ++ stackrc:source:322                       :   GITREPO["python-cinderclient"]=https://opendev.org/openstack/python-cinderclient.git
2025-10-03 06:37:34.132092 | controller | ++ stackrc:source:323                       :   GITBRANCH["python-cinderclient"]=master
2025-10-03 06:37:34.134516 | controller | ++ stackrc:source:326                       :   GITREPO["python-brick-cinderclient-ext"]=https://opendev.org/openstack/python-brick-cinderclient-ext.git
2025-10-03 06:37:34.136870 | controller | ++ stackrc:source:327                       :   GITBRANCH["python-brick-cinderclient-ext"]=master
2025-10-03 06:37:34.139078 | controller | ++ stackrc:source:330                       :   GITREPO["python-barbicanclient"]=https://opendev.org/openstack/python-barbicanclient.git
2025-10-03 06:37:34.141238 | controller | ++ stackrc:source:331                       :   GITBRANCH["python-barbicanclient"]=master
2025-10-03 06:37:34.143873 | controller | ++ stackrc:source:332                       :   GITDIR["python-barbicanclient"]=/opt/stack/python-barbicanclient
2025-10-03 06:37:34.145310 | controller | ++ stackrc:source:335                       :   GITREPO["python-glanceclient"]=https://opendev.org/openstack/python-glanceclient.git
2025-10-03 06:37:34.147771 | controller | ++ stackrc:source:336                       :   GITBRANCH["python-glanceclient"]=master
2025-10-03 06:37:34.149128 | controller | ++ stackrc:source:339                       :   GITREPO["python-ironicclient"]=https://opendev.org/openstack/python-ironicclient.git
2025-10-03 06:37:34.152161 | controller | ++ stackrc:source:340                       :   GITBRANCH["python-ironicclient"]=master
2025-10-03 06:37:34.153760 | controller | ++ stackrc:source:342                       :   GITDIR["python-ironicclient"]=/opt/stack/python-ironicclient
2025-10-03 06:37:34.155972 | controller | ++ stackrc:source:345                       :   GITREPO["keystoneauth"]=https://opendev.org/openstack/keystoneauth.git
2025-10-03 06:37:34.157335 | controller | ++ stackrc:source:346                       :   GITBRANCH["keystoneauth"]=master
2025-10-03 06:37:34.159452 | controller | ++ stackrc:source:349                       :   GITREPO["python-keystoneclient"]=https://opendev.org/openstack/python-keystoneclient.git
2025-10-03 06:37:34.161525 | controller | ++ stackrc:source:350                       :   GITBRANCH["python-keystoneclient"]=master
2025-10-03 06:37:34.163887 | controller | ++ stackrc:source:353                       :   GITREPO["python-neutronclient"]=https://opendev.org/openstack/python-neutronclient.git
2025-10-03 06:37:34.166344 | controller | ++ stackrc:source:354                       :   GITBRANCH["python-neutronclient"]=master
2025-10-03 06:37:34.169051 | controller | ++ stackrc:source:357                       :   GITREPO["python-novaclient"]=https://opendev.org/openstack/python-novaclient.git
2025-10-03 06:37:34.170574 | controller | ++ stackrc:source:358                       :   GITBRANCH["python-novaclient"]=master
2025-10-03 06:37:34.173074 | controller | ++ stackrc:source:361                       :   GITREPO["python-swiftclient"]=https://opendev.org/openstack/python-swiftclient.git
2025-10-03 06:37:34.174477 | controller | ++ stackrc:source:362                       :   GITBRANCH["python-swiftclient"]=master
2025-10-03 06:37:34.176822 | controller | ++ stackrc:source:365                       :   GITREPO["python-openstackclient"]=https://opendev.org/openstack/python-openstackclient.git
2025-10-03 06:37:34.179161 | controller | ++ stackrc:source:366                       :   GITBRANCH["python-openstackclient"]=master
2025-10-03 06:37:34.181451 | controller | ++ stackrc:source:368                       :   GITDIR["python-openstackclient"]=/opt/stack/python-openstackclient
2025-10-03 06:37:34.182959 | controller | ++ stackrc:source:371                       :   GITREPO["osc-placement"]=https://opendev.org/openstack/osc-placement.git
2025-10-03 06:37:34.184760 | controller | ++ stackrc:source:372                       :   GITBRANCH["osc-placement"]=master
2025-10-03 06:37:34.187280 | controller | ++ stackrc:source:383                       :   GITREPO["castellan"]=https://opendev.org/openstack/castellan.git
2025-10-03 06:37:34.188676 | controller | ++ stackrc:source:384                       :   GITBRANCH["castellan"]=master
2025-10-03 06:37:34.190944 | controller | ++ stackrc:source:387                       :   GITREPO["cliff"]=https://opendev.org/openstack/cliff.git
2025-10-03 06:37:34.192377 | controller | ++ stackrc:source:388                       :   GITBRANCH["cliff"]=master
2025-10-03 06:37:34.194518 | controller | ++ stackrc:source:391                       :   GITREPO["futurist"]=https://opendev.org/openstack/futurist.git
2025-10-03 06:37:34.196622 | controller | ++ stackrc:source:392                       :   GITBRANCH["futurist"]=master
2025-10-03 06:37:34.198947 | controller | ++ stackrc:source:395                       :   GITREPO["debtcollector"]=https://opendev.org/openstack/debtcollector.git
2025-10-03 06:37:34.200300 | controller | ++ stackrc:source:396                       :   GITBRANCH["debtcollector"]=master
2025-10-03 06:37:34.202451 | controller | ++ stackrc:source:399                       :   GITREPO["etcd3gw"]=https://opendev.org/openstack/etcd3gw.git
2025-10-03 06:37:34.203880 | controller | ++ stackrc:source:400                       :   GITBRANCH["etcd3gw"]=master
2025-10-03 06:37:34.205057 | controller | ++ stackrc:source:403                       :   GITREPO["automaton"]=https://opendev.org/openstack/automaton.git
2025-10-03 06:37:34.207125 | controller | ++ stackrc:source:404                       :   GITBRANCH["automaton"]=master
2025-10-03 06:37:34.208464 | controller | ++ stackrc:source:407                       :   GITREPO["oslo.cache"]=https://opendev.org/openstack/oslo.cache.git
2025-10-03 06:37:34.210612 | controller | ++ stackrc:source:408                       :   GITBRANCH["oslo.cache"]=master
2025-10-03 06:37:34.212092 | controller | ++ stackrc:source:411                       :   GITREPO["oslo.concurrency"]=https://opendev.org/openstack/oslo.concurrency.git
2025-10-03 06:37:34.213467 | controller | ++ stackrc:source:412                       :   GITBRANCH["oslo.concurrency"]=master
2025-10-03 06:37:34.216237 | controller | ++ stackrc:source:415                       :   GITREPO["oslo.config"]=https://opendev.org/openstack/oslo.config.git
2025-10-03 06:37:34.218421 | controller | ++ stackrc:source:416                       :   GITBRANCH["oslo.config"]=master
2025-10-03 06:37:34.220691 | controller | ++ stackrc:source:419                       :   GITREPO["oslo.context"]=https://opendev.org/openstack/oslo.context.git
2025-10-03 06:37:34.221891 | controller | ++ stackrc:source:420                       :   GITBRANCH["oslo.context"]=master
2025-10-03 06:37:34.223871 | controller | ++ stackrc:source:423                       :   GITREPO["oslo.db"]=https://opendev.org/openstack/oslo.db.git
2025-10-03 06:37:34.225952 | controller | ++ stackrc:source:424                       :   GITBRANCH["oslo.db"]=master
2025-10-03 06:37:34.228229 | controller | ++ stackrc:source:427                       :   GITREPO["oslo.i18n"]=https://opendev.org/openstack/oslo.i18n.git
2025-10-03 06:37:34.230228 | controller | ++ stackrc:source:428                       :   GITBRANCH["oslo.i18n"]=master
2025-10-03 06:37:34.231598 | controller | ++ stackrc:source:431                       :   GITREPO["oslo.limit"]=https://opendev.org/openstack/oslo.limit.git
2025-10-03 06:37:34.234096 | controller | ++ stackrc:source:432                       :   GITBRANCH["oslo.limit"]=master
2025-10-03 06:37:34.236383 | controller | ++ stackrc:source:435                       :   GITREPO["oslo.log"]=https://opendev.org/openstack/oslo.log.git
2025-10-03 06:37:34.238633 | controller | ++ stackrc:source:436                       :   GITBRANCH["oslo.log"]=master
2025-10-03 06:37:34.240454 | controller | ++ stackrc:source:439                       :   GITREPO["oslo.messaging"]=https://opendev.org/openstack/oslo.messaging.git
2025-10-03 06:37:34.242766 | controller | ++ stackrc:source:440                       :   GITBRANCH["oslo.messaging"]=master
2025-10-03 06:37:34.244665 | controller | ++ stackrc:source:443                       :   GITREPO["oslo.middleware"]=https://opendev.org/openstack/oslo.middleware.git
2025-10-03 06:37:34.246984 | controller | ++ stackrc:source:444                       :   GITBRANCH["oslo.middleware"]=master
2025-10-03 06:37:34.248141 | controller | ++ stackrc:source:447                       :   GITREPO["oslo.policy"]=https://opendev.org/openstack/oslo.policy.git
2025-10-03 06:37:34.249967 | controller | ++ stackrc:source:448                       :   GITBRANCH["oslo.policy"]=master
2025-10-03 06:37:34.251301 | controller | ++ stackrc:source:451                       :   GITREPO["oslo.privsep"]=https://opendev.org/openstack/oslo.privsep.git
2025-10-03 06:37:34.252808 | controller | ++ stackrc:source:452                       :   GITBRANCH["oslo.privsep"]=master
2025-10-03 06:37:34.254911 | controller | ++ stackrc:source:455                       :   GITREPO["oslo.reports"]=https://opendev.org/openstack/oslo.reports.git
2025-10-03 06:37:34.258602 | controller | ++ stackrc:source:456                       :   GITBRANCH["oslo.reports"]=master
2025-10-03 06:37:34.260638 | controller | ++ stackrc:source:459                       :   GITREPO["oslo.rootwrap"]=https://opendev.org/openstack/oslo.rootwrap.git
2025-10-03 06:37:34.262556 | controller | ++ stackrc:source:460                       :   GITBRANCH["oslo.rootwrap"]=master
2025-10-03 06:37:34.264510 | controller | ++ stackrc:source:463                       :   GITREPO["oslo.serialization"]=https://opendev.org/openstack/oslo.serialization.git
2025-10-03 06:37:34.266447 | controller | ++ stackrc:source:464                       :   GITBRANCH["oslo.serialization"]=master
2025-10-03 06:37:34.268352 | controller | ++ stackrc:source:467                       :   GITREPO["oslo.service"]=https://opendev.org/openstack/oslo.service.git
2025-10-03 06:37:34.270958 | controller | ++ stackrc:source:468                       :   GITBRANCH["oslo.service"]=master
2025-10-03 06:37:34.273566 | controller | ++ stackrc:source:471                       :   GITREPO["oslo.utils"]=https://opendev.org/openstack/oslo.utils.git
2025-10-03 06:37:34.275842 | controller | ++ stackrc:source:472                       :   GITBRANCH["oslo.utils"]=master
2025-10-03 06:37:34.277911 | controller | ++ stackrc:source:475                       :   GITREPO["oslo.versionedobjects"]=https://opendev.org/openstack/oslo.versionedobjects.git
2025-10-03 06:37:34.279662 | controller | ++ stackrc:source:476                       :   GITBRANCH["oslo.versionedobjects"]=master
2025-10-03 06:37:34.281379 | controller | ++ stackrc:source:479                       :   GITREPO["oslo.vmware"]=https://opendev.org/openstack/oslo.vmware.git
2025-10-03 06:37:34.283416 | controller | ++ stackrc:source:480                       :   GITBRANCH["oslo.vmware"]=master
2025-10-03 06:37:34.285618 | controller | ++ stackrc:source:483                       :   GITREPO["osprofiler"]=https://opendev.org/openstack/osprofiler.git
2025-10-03 06:37:34.287795 | controller | ++ stackrc:source:484                       :   GITBRANCH["osprofiler"]=master
2025-10-03 06:37:34.290145 | controller | ++ stackrc:source:487                       :   GITREPO["pycadf"]=https://opendev.org/openstack/pycadf.git
2025-10-03 06:37:34.292483 | controller | ++ stackrc:source:488                       :   GITBRANCH["pycadf"]=master
2025-10-03 06:37:34.294752 | controller | ++ stackrc:source:491                       :   GITREPO["stevedore"]=https://opendev.org/openstack/stevedore.git
2025-10-03 06:37:34.296998 | controller | ++ stackrc:source:492                       :   GITBRANCH["stevedore"]=master
2025-10-03 06:37:34.299107 | controller | ++ stackrc:source:495                       :   GITREPO["taskflow"]=https://opendev.org/openstack/taskflow.git
2025-10-03 06:37:34.301511 | controller | ++ stackrc:source:496                       :   GITBRANCH["taskflow"]=master
2025-10-03 06:37:34.303899 | controller | ++ stackrc:source:499                       :   GITREPO["tooz"]=https://opendev.org/openstack/tooz.git
2025-10-03 06:37:34.305919 | controller | ++ stackrc:source:500                       :   GITBRANCH["tooz"]=master
2025-10-03 06:37:34.308000 | controller | ++ stackrc:source:503                       :   GITREPO["pbr"]=https://opendev.org/openstack/pbr.git
2025-10-03 06:37:34.310288 | controller | ++ stackrc:source:504                       :   GITBRANCH["pbr"]=master
2025-10-03 06:37:34.312325 | controller | ++ stackrc:source:514                       :   GITREPO["cursive"]=https://opendev.org/openstack/cursive.git
2025-10-03 06:37:34.314318 | controller | ++ stackrc:source:515                       :   GITBRANCH["cursive"]=master
2025-10-03 06:37:34.316297 | controller | ++ stackrc:source:518                       :   GITREPO["glance_store"]=https://opendev.org/openstack/glance_store.git
2025-10-03 06:37:34.318630 | controller | ++ stackrc:source:519                       :   GITBRANCH["glance_store"]=master
2025-10-03 06:37:34.320814 | controller | ++ stackrc:source:522                       :   GITREPO["keystonemiddleware"]=https://opendev.org/openstack/keystonemiddleware.git
2025-10-03 06:37:34.322818 | controller | ++ stackrc:source:523                       :   GITBRANCH["keystonemiddleware"]=master
2025-10-03 06:37:34.325250 | controller | ++ stackrc:source:526                       :   GITREPO["ceilometermiddleware"]=https://opendev.org/openstack/ceilometermiddleware.git
2025-10-03 06:37:34.327217 | controller | ++ stackrc:source:527                       :   GITBRANCH["ceilometermiddleware"]=master
2025-10-03 06:37:34.330066 | controller | ++ stackrc:source:528                       :   GITDIR["ceilometermiddleware"]=/opt/stack/ceilometermiddleware
2025-10-03 06:37:34.332207 | controller | ++ stackrc:source:531                       :   GITREPO["openstacksdk"]=https://opendev.org/openstack/openstacksdk.git
2025-10-03 06:37:34.334692 | controller | ++ stackrc:source:532                       :   GITBRANCH["openstacksdk"]=master
2025-10-03 06:37:34.336777 | controller | ++ stackrc:source:535                       :   GITREPO["os-brick"]=https://opendev.org/openstack/os-brick.git
2025-10-03 06:37:34.338899 | controller | ++ stackrc:source:536                       :   GITBRANCH["os-brick"]=master
2025-10-03 06:37:34.341754 | controller | ++ stackrc:source:539                       :   GITREPO["os-client-config"]=https://opendev.org/openstack/os-client-config.git
2025-10-03 06:37:34.343816 | controller | ++ stackrc:source:540                       :   GITBRANCH["os-client-config"]=master
2025-10-03 06:37:34.346273 | controller | ++ stackrc:source:541                       :   GITDIR["os-client-config"]=/opt/stack/os-client-config
2025-10-03 06:37:34.348792 | controller | ++ stackrc:source:544                       :   GITREPO["os-vif"]=https://opendev.org/openstack/os-vif.git
2025-10-03 06:37:34.351656 | controller | ++ stackrc:source:545                       :   GITBRANCH["os-vif"]=master
2025-10-03 06:37:34.353631 | controller | ++ stackrc:source:548                       :   GITREPO["osc-lib"]=https://opendev.org/openstack/osc-lib.git
2025-10-03 06:37:34.355830 | controller | ++ stackrc:source:549                       :   GITBRANCH["osc-lib"]=master
2025-10-03 06:37:34.357898 | controller | ++ stackrc:source:552                       :   GITREPO["ironic-lib"]=https://opendev.org/openstack/ironic-lib.git
2025-10-03 06:37:34.360652 | controller | ++ stackrc:source:553                       :   GITBRANCH["ironic-lib"]=master
2025-10-03 06:37:34.362692 | controller | ++ stackrc:source:555                       :   GITDIR["ironic-lib"]=/opt/stack/ironic-lib
2025-10-03 06:37:34.364684 | controller | ++ stackrc:source:558                       :   GITREPO["diskimage-builder"]=https://opendev.org/openstack/diskimage-builder.git
2025-10-03 06:37:34.367175 | controller | ++ stackrc:source:559                       :   GITBRANCH["diskimage-builder"]=master
2025-10-03 06:37:34.369184 | controller | ++ stackrc:source:560                       :   GITDIR["diskimage-builder"]=/opt/stack/diskimage-builder
2025-10-03 06:37:34.371334 | controller | ++ stackrc:source:563                       :   GITREPO["neutron-lib"]=https://opendev.org/openstack/neutron-lib.git
2025-10-03 06:37:34.373405 | controller | ++ stackrc:source:564                       :   GITBRANCH["neutron-lib"]=master
2025-10-03 06:37:34.375946 | controller | ++ stackrc:source:565                       :   GITDIR["neutron-lib"]=/opt/stack/neutron-lib
2025-10-03 06:37:34.378081 | controller | ++ stackrc:source:568                       :   GITREPO["os-resource-classes"]=https://opendev.org/openstack/os-resource-classes.git
2025-10-03 06:37:34.380039 | controller | ++ stackrc:source:569                       :   GITBRANCH["os-resource-classes"]=master
2025-10-03 06:37:34.382348 | controller | ++ stackrc:source:572                       :   GITREPO["os-traits"]=https://opendev.org/openstack/os-traits.git
2025-10-03 06:37:34.384431 | controller | ++ stackrc:source:573                       :   GITBRANCH["os-traits"]=master
2025-10-03 06:37:34.387274 | controller | ++ stackrc:source:576                       :   GITREPO["ovsdbapp"]=https://opendev.org/openstack/ovsdbapp.git
2025-10-03 06:37:34.389495 | controller | ++ stackrc:source:577                       :   GITBRANCH["ovsdbapp"]=master
2025-10-03 06:37:34.392303 | controller | ++ stackrc:source:578                       :   GITDIR["ovsdbapp"]=/opt/stack/ovsdbapp
2025-10-03 06:37:34.394386 | controller | ++ stackrc:source:581                       :   GITREPO["os-ken"]=https://opendev.org/openstack/os-ken.git
2025-10-03 06:37:34.396506 | controller | ++ stackrc:source:582                       :   GITBRANCH["os-ken"]=master
2025-10-03 06:37:34.399558 | controller | ++ stackrc:source:583                       :   GITDIR["os-ken"]=/opt/stack/os-ken
2025-10-03 06:37:34.401706 | controller | ++ stackrc:source:595                       :   IRONIC_PYTHON_AGENT_REPO=https://opendev.org/openstack/ironic-python-agent.git
2025-10-03 06:37:34.404391 | controller | ++ stackrc:source:596                       :   IRONIC_PYTHON_AGENT_BRANCH=master
2025-10-03 06:37:34.407077 | controller | ++ stackrc:source:599                       :   NOVNC_REPO=https://github.com/novnc/novnc.git
2025-10-03 06:37:34.409167 | controller | ++ stackrc:source:600                       :   NOVNC_BRANCH=v1.3.0
2025-10-03 06:37:34.411844 | controller | ++ stackrc:source:603                       :   SPICE_REPO=http://anongit.freedesktop.org/git/spice/spice-html5.git
2025-10-03 06:37:34.414243 | controller | ++ stackrc:source:604                       :   SPICE_BRANCH=master
2025-10-03 06:37:34.417467 | controller | +++ stackrc:source:610                       :   trueorfalse False ENABLE_VOLUME_MULTIATTACH
2025-10-03 06:37:34.420015 | controller | +++ functions-common:trueorfalse:222         :   local xtrace
2025-10-03 06:37:34.423824 | controller | ++++ functions-common:trueorfalse:223         :   set +o
2025-10-03 06:37:34.424890 | controller | ++++ functions-common:trueorfalse:223         :   grep xtrace
2025-10-03 06:37:34.429721 | controller | +++ functions-common:trueorfalse:223         :   xtrace='set -o xtrace'
2025-10-03 06:37:34.432556 | controller | +++ functions-common:trueorfalse:224         :   set +o xtrace
2025-10-03 06:37:34.435290 | controller | ++ stackrc:source:610                       :   ENABLE_VOLUME_MULTIATTACH=True
2025-10-03 06:37:34.437970 | controller | ++ stackrc:source:615                       :   DEFAULT_VIRT_DRIVER=libvirt
2025-10-03 06:37:34.440566 | controller | ++ stackrc:source:616                       :   VIRT_DRIVER=libvirt
2025-10-03 06:37:34.443254 | controller | ++ stackrc:source:617                       :   case "$VIRT_DRIVER" in
2025-10-03 06:37:34.445621 | controller | ++ stackrc:source:619                       :   LIBVIRT_TYPE=qemu
2025-10-03 06:37:34.448487 | controller | ++ stackrc:source:620                       :   LIBVIRT_CPU_MODE=custom
2025-10-03 06:37:34.451274 | controller | ++ stackrc:source:621                       :   LIBVIRT_CPU_MODEL=Nehalem
2025-10-03 06:37:34.453627 | controller | ++ stackrc:source:623                       :   [[ -z CentOSStream ]]
2025-10-03 06:37:34.456428 | controller | ++ stackrc:source:627                       :   [[ CentOSStream =~ (Debian|Ubuntu) ]]
2025-10-03 06:37:34.458868 | controller | ++ stackrc:source:630                       :   LIBVIRT_GROUP=libvirtd
2025-10-03 06:37:34.461254 | controller | ++ stackrc:source:667                       :   CIRROS_VERSION=0.6.3
2025-10-03 06:37:34.464537 | controller | +++ stackrc:source:668                       :   uname -m
2025-10-03 06:37:34.468244 | controller | ++ stackrc:source:668                       :   CIRROS_ARCH=x86_64
2025-10-03 06:37:34.471594 | controller | +++ stackrc:source:673                       :   trueorfalse True DOWNLOAD_DEFAULT_IMAGES
2025-10-03 06:37:34.473927 | controller | +++ functions-common:trueorfalse:222         :   local xtrace
2025-10-03 06:37:34.478372 | controller | ++++ functions-common:trueorfalse:223         :   set +o
2025-10-03 06:37:34.479811 | controller | ++++ functions-common:trueorfalse:223         :   grep xtrace
2025-10-03 06:37:34.484350 | controller | +++ functions-common:trueorfalse:223         :   xtrace='set -o xtrace'
2025-10-03 06:37:34.487178 | controller | +++ functions-common:trueorfalse:224         :   set +o xtrace
2025-10-03 06:37:34.490079 | controller | ++ stackrc:source:673                       :   DOWNLOAD_DEFAULT_IMAGES=True
2025-10-03 06:37:34.492189 | controller | ++ stackrc:source:674                       :   [[ True == \T\r\u\e ]]
2025-10-03 06:37:34.494265 | controller | ++ stackrc:source:675                       :   [[ -n http://download.cirros-cloud.net/0.6.2/cirros-0.6.2-x86_64-disk.img, http://download.cirros-cloud.net/0.6.1/cirros-0.6.1-x86_64-disk.img ]]
2025-10-03 06:37:34.496301 | controller | ++ stackrc:source:676                       :   IMAGE_URLS+=,
2025-10-03 06:37:34.498551 | controller | ++ stackrc:source:678                       :   case "$VIRT_DRIVER" in
2025-10-03 06:37:34.500686 | controller | ++ stackrc:source:680                       :   case "$LIBVIRT_TYPE" in
2025-10-03 06:37:34.502534 | controller | ++ stackrc:source:686                       :   DEFAULT_IMAGE_NAME=cirros-0.6.3-x86_64-disk
2025-10-03 06:37:34.504640 | controller | ++ stackrc:source:687                       :   DEFAULT_IMAGE_FILE_NAME=cirros-0.6.3-x86_64-disk.img
2025-10-03 06:37:34.506713 | controller | ++ stackrc:source:688                       :   IMAGE_URLS+=https://github.com/cirros-dev/cirros/releases/download/0.6.3/cirros-0.6.3-x86_64-disk.img
2025-10-03 06:37:34.508700 | controller | ++ stackrc:source:701                       :   DOWNLOAD_DEFAULT_IMAGES=False
2025-10-03 06:37:34.510701 | controller | ++ stackrc:source:710                       :   EXTRA_CACHE_URLS=
2025-10-03 06:37:34.512321 | controller | ++ stackrc:source:713                       :   ETCD_VERSION=v3.5.21
2025-10-03 06:37:34.515393 | controller | ++ stackrc:source:714                       :   ETCD_SHA256_AMD64=adddda4b06718e68671ffabff2f8cee48488ba61ad82900e639d108f2148501c
2025-10-03 06:37:34.517525 | controller | ++ stackrc:source:715                       :   ETCD_SHA256_ARM64=95bf6918623a097c0385b96f139d90248614485e781ec9bee4768dbb6c79c53f
2025-10-03 06:37:34.519364 | controller | ++ stackrc:source:716                       :   ETCD_SHA256_PPC64=6fb6ecb3d1b331eb177dc610a8efad3aceb1f836d6aeb439ba0bfac5d5c2a38c
2025-10-03 06:37:34.521725 | controller | ++ stackrc:source:717                       :   ETCD_SHA256_S390X=a211a83961ba8a7e94f7d6343ad769e699db21a715ba4f3b68cf31ea28f9c951
2025-10-03 06:37:34.524414 | controller | ++ stackrc:source:719                       :   is_arch x86_64
2025-10-03 06:37:34.526877 | controller | +++ functions-common:is_arch:517             :   uname -m
2025-10-03 06:37:34.531151 | controller | ++ functions-common:is_arch:517             :   [[ x86_64 == \x\8\6\_\6\4 ]]
2025-10-03 06:37:34.533157 | controller | ++ stackrc:source:720                       :   ETCD_ARCH=amd64
2025-10-03 06:37:34.534940 | controller | ++ stackrc:source:721                       :   ETCD_SHA256=adddda4b06718e68671ffabff2f8cee48488ba61ad82900e639d108f2148501c
2025-10-03 06:37:34.537747 | controller | ++ stackrc:source:734                       :   ETCD_PORT=2379
2025-10-03 06:37:34.539649 | controller | ++ stackrc:source:735                       :   ETCD_PEER_PORT=2380
2025-10-03 06:37:34.541371 | controller | ++ stackrc:source:736                       :   ETCD_DOWNLOAD_URL=https://github.com/etcd-io/etcd/releases/download
2025-10-03 06:37:34.542968 | controller | ++ stackrc:source:737                       :   ETCD_NAME=etcd-v3.5.21-linux-amd64
2025-10-03 06:37:34.544513 | controller | ++ stackrc:source:738                       :   ETCD_DOWNLOAD_FILE=etcd-v3.5.21-linux-amd64.tar.gz
2025-10-03 06:37:34.546147 | controller | ++ stackrc:source:739                       :   ETCD_DOWNLOAD_LOCATION=https://github.com/etcd-io/etcd/releases/download/v3.5.21/etcd-v3.5.21-linux-amd64.tar.gz
2025-10-03 06:37:34.547779 | controller | ++ stackrc:source:741                       :   EXTRA_CACHE_URLS+=,https://github.com/etcd-io/etcd/releases/download/v3.5.21/etcd-v3.5.21-linux-amd64.tar.gz
2025-10-03 06:37:34.549398 | controller | ++ stackrc:source:744                       :   CACHE_BACKEND=dogpile.cache.memcached
2025-10-03 06:37:34.551023 | controller | ++ stackrc:source:745                       :   MEMCACHE_SERVERS=localhost:11211
2025-10-03 06:37:34.552816 | controller | ++ stackrc:source:748                       :   for image_url in ${IMAGE_URLS//,/ }
2025-10-03 06:37:34.556421 | controller | +++ stackrc:source:749                       :   echo 'http://download.cirros-cloud.net/0.6.2/cirros-0.6.2-x86_64-disk.img, http://download.cirros-cloud.net/0.6.1/cirros-0.6.1-x86_64-disk.img,https://github.com/cirros-dev/cirros/releases/download/0.6.3/cirros-0.6.3-x86_64-disk.img'
2025-10-03 06:37:34.557591 | controller | +++ stackrc:source:749                       :   wc -l
2025-10-03 06:37:34.557714 | controller | +++ stackrc:source:749                       :   grep -o -F http://download.cirros-cloud.net/0.6.2/cirros-0.6.2-x86_64-disk.img
2025-10-03 06:37:34.563642 | controller | ++ stackrc:source:749                       :   '[' 1 -gt 1 ']'
2025-10-03 06:37:34.565387 | controller | ++ stackrc:source:748                       :   for image_url in ${IMAGE_URLS//,/ }
2025-10-03 06:37:34.568658 | controller | +++ stackrc:source:749                       :   echo 'http://download.cirros-cloud.net/0.6.2/cirros-0.6.2-x86_64-disk.img, http://download.cirros-cloud.net/0.6.1/cirros-0.6.1-x86_64-disk.img,https://github.com/cirros-dev/cirros/releases/download/0.6.3/cirros-0.6.3-x86_64-disk.img'
2025-10-03 06:37:34.568931 | controller | +++ stackrc:source:749                       :   grep -o -F http://download.cirros-cloud.net/0.6.1/cirros-0.6.1-x86_64-disk.img
2025-10-03 06:37:34.569841 | controller | +++ stackrc:source:749                       :   wc -l
2025-10-03 06:37:34.574376 | controller | ++ stackrc:source:749                       :   '[' 1 -gt 1 ']'
2025-10-03 06:37:34.576376 | controller | ++ stackrc:source:748                       :   for image_url in ${IMAGE_URLS//,/ }
2025-10-03 06:37:34.579511 | controller | +++ stackrc:source:749                       :   grep -o -F https://github.com/cirros-dev/cirros/releases/download/0.6.3/cirros-0.6.3-x86_64-disk.img
2025-10-03 06:37:34.580009 | controller | +++ stackrc:source:749                       :   echo 'http://download.cirros-cloud.net/0.6.2/cirros-0.6.2-x86_64-disk.img, http://download.cirros-cloud.net/0.6.1/cirros-0.6.1-x86_64-disk.img,https://github.com/cirros-dev/cirros/releases/download/0.6.3/cirros-0.6.3-x86_64-disk.img'
2025-10-03 06:37:34.580198 | controller | +++ stackrc:source:749                       :   wc -l
2025-10-03 06:37:34.586810 | controller | ++ stackrc:source:749                       :   '[' 1 -gt 1 ']'
2025-10-03 06:37:34.588278 | controller | ++ stackrc:source:755                       :   VOLUME_BACKING_FILE_SIZE=30G
2025-10-03 06:37:34.589566 | controller | ++ stackrc:source:758                       :   VOLUME_NAME_PREFIX=volume-
2025-10-03 06:37:34.590970 | controller | ++ stackrc:source:759                       :   INSTANCE_NAME_PREFIX=instance-
2025-10-03 06:37:34.592459 | controller | ++ stackrc:source:762                       :   S3_SERVICE_PORT=3333
2025-10-03 06:37:34.594416 | controller | ++ stackrc:source:765                       :   PRIVATE_NETWORK_NAME=private
2025-10-03 06:37:34.596228 | controller | ++ stackrc:source:766                       :   PUBLIC_NETWORK_NAME=public
2025-10-03 06:37:34.597585 | controller | ++ stackrc:source:768                       :   PUBLIC_INTERFACE=
2025-10-03 06:37:34.598956 | controller | ++ stackrc:source:771                       :   SERVICE_PROTOCOL=http
2025-10-03 06:37:34.600619 | controller | +++ stackrc:source:777                       :   nproc
2025-10-03 06:37:34.604728 | controller | +++ stackrc:source:777                       :   nproc
2025-10-03 06:37:34.607812 | controller | ++ stackrc:source:777                       :   API_WORKERS=2
2025-10-03 06:37:34.609123 | controller | ++ stackrc:source:780                       :   SERVICE_TIMEOUT=60
2025-10-03 06:37:34.610402 | controller | ++ stackrc:source:783                       :   NOVA_READY_TIMEOUT=60
2025-10-03 06:37:34.612555 | controller | ++ stackrc:source:786                       :   SERVICE_GRACEFUL_SHUTDOWN_TIMEOUT=5
2025-10-03 06:37:34.614339 | controller | ++ stackrc:source:789                       :   WORKER_TIMEOUT=80
2025-10-03 06:37:34.616293 | controller | +++ stackrc:source:797                       :   trueorfalse False OFFLINE
2025-10-03 06:37:34.618242 | controller | +++ functions-common:trueorfalse:222         :   local xtrace
2025-10-03 06:37:34.621362 | controller | ++++ functions-common:trueorfalse:223         :   set +o
2025-10-03 06:37:34.622347 | controller | ++++ functions-common:trueorfalse:223         :   grep xtrace
2025-10-03 06:37:34.626973 | controller | +++ functions-common:trueorfalse:223         :   xtrace='set -o xtrace'
2025-10-03 06:37:34.629089 | controller | +++ functions-common:trueorfalse:224         :   set +o xtrace
2025-10-03 06:37:34.631999 | controller | ++ stackrc:source:797                       :   OFFLINE=False
2025-10-03 06:37:34.634512 | controller | +++ stackrc:source:802                       :   trueorfalse False ERROR_ON_CLONE
2025-10-03 06:37:34.636388 | controller | +++ functions-common:trueorfalse:222         :   local xtrace
2025-10-03 06:37:34.639591 | controller | ++++ functions-common:trueorfalse:223         :   set +o
2025-10-03 06:37:34.640530 | controller | ++++ functions-common:trueorfalse:223         :   grep xtrace
2025-10-03 06:37:34.644803 | controller | +++ functions-common:trueorfalse:223         :   xtrace='set -o xtrace'
2025-10-03 06:37:34.646728 | controller | +++ functions-common:trueorfalse:224         :   set +o xtrace
2025-10-03 06:37:34.649285 | controller | ++ stackrc:source:802                       :   ERROR_ON_CLONE=True
2025-10-03 06:37:34.652324 | controller | +++ stackrc:source:805                       :   trueorfalse True ENABLE_DEBUG_LOG_LEVEL
2025-10-03 06:37:34.654131 | controller | +++ functions-common:trueorfalse:222         :   local xtrace
2025-10-03 06:37:34.656616 | controller | ++++ functions-common:trueorfalse:223         :   set +o
2025-10-03 06:37:34.658113 | controller | ++++ functions-common:trueorfalse:223         :   grep xtrace
2025-10-03 06:37:34.662138 | controller | +++ functions-common:trueorfalse:223         :   xtrace='set -o xtrace'
2025-10-03 06:37:34.663673 | controller | +++ functions-common:trueorfalse:224         :   set +o xtrace
2025-10-03 06:37:34.666252 | controller | ++ stackrc:source:805                       :   ENABLE_DEBUG_LOG_LEVEL=True
2025-10-03 06:37:34.668590 | controller | ++ stackrc:source:811                       :   FLOATING_RANGE=172.24.5.0/24
2025-10-03 06:37:34.670630 | controller | ++ stackrc:source:812                       :   IPV4_ADDRS_SAFE_TO_USE=10.1.0.0/20
2025-10-03 06:37:34.672905 | controller | ++ stackrc:source:813                       :   FIXED_RANGE=10.1.0.0/20
2025-10-03 06:37:34.675168 | controller | ++ stackrc:source:814                       :   HOST_IP_IFACE=
2025-10-03 06:37:34.677400 | controller | ++ stackrc:source:815                       :   HOST_IP=38.102.83.227
2025-10-03 06:37:34.679798 | controller | ++ stackrc:source:816                       :   HOST_IPV6=
2025-10-03 06:37:34.683162 | controller | +++ stackrc:source:818                       :   get_default_host_ip 10.1.0.0/20 172.24.5.0/24 '' 38.102.83.227 inet
2025-10-03 06:37:34.684785 | controller | +++ functions-common:get_default_host_ip:763 :   local fixed_range=10.1.0.0/20
2025-10-03 06:37:34.686682 | controller | +++ functions-common:get_default_host_ip:764 :   local floating_range=172.24.5.0/24
2025-10-03 06:37:34.688553 | controller | +++ functions-common:get_default_host_ip:765 :   local host_ip_iface=
2025-10-03 06:37:34.690446 | controller | +++ functions-common:get_default_host_ip:766 :   local host_ip=38.102.83.227
2025-10-03 06:37:34.692407 | controller | +++ functions-common:get_default_host_ip:767 :   local af=inet
2025-10-03 06:37:34.694431 | controller | +++ functions-common:get_default_host_ip:770 :   '[' -z 38.102.83.227 -o 38.102.83.227 == dhcp ']'
2025-10-03 06:37:34.696389 | controller | +++ functions-common:get_default_host_ip:794 :   echo 38.102.83.227
2025-10-03 06:37:34.699174 | controller | ++ stackrc:source:818                       :   HOST_IP=38.102.83.227
2025-10-03 06:37:34.701169 | controller | ++ stackrc:source:819                       :   '[' 38.102.83.227 == '' ']'
2025-10-03 06:37:34.704251 | controller | +++ stackrc:source:823                       :   get_default_host_ip '' '' '' '' inet6
2025-10-03 06:37:34.705691 | controller | +++ functions-common:get_default_host_ip:763 :   local fixed_range=
2025-10-03 06:37:34.707596 | controller | +++ functions-common:get_default_host_ip:764 :   local floating_range=
2025-10-03 06:37:34.709641 | controller | +++ functions-common:get_default_host_ip:765 :   local host_ip_iface=
2025-10-03 06:37:34.711393 | controller | +++ functions-common:get_default_host_ip:766 :   local host_ip=
2025-10-03 06:37:34.713377 | controller | +++ functions-common:get_default_host_ip:767 :   local af=inet6
2025-10-03 06:37:34.715409 | controller | +++ functions-common:get_default_host_ip:770 :   '[' -z '' -o '' == dhcp ']'
2025-10-03 06:37:34.718171 | controller | +++ functions-common:get_default_host_ip:771 :   host_ip=
2025-10-03 06:37:34.721323 | controller | ++++ functions-common:get_default_host_ip:773 :   ip -f inet6 route list match default table all
2025-10-03 06:37:34.721430 | controller | ++++ functions-common:get_default_host_ip:773 :   grep via
2025-10-03 06:37:34.722806 | controller | ++++ functions-common:get_default_host_ip:773 :   awk '/default/ {print $5}'
2025-10-03 06:37:34.724247 | controller | ++++ functions-common:get_default_host_ip:773 :   head -1
2025-10-03 06:37:34.728549 | controller | +++ functions-common:get_default_host_ip:773 :   host_ip_iface=
2025-10-03 06:37:34.731293 | controller | +++ functions-common:get_default_host_ip:774 :   local host_ips
2025-10-03 06:37:34.734418 | controller | ++++ functions-common:get_default_host_ip:775 :   sed /temporary/d
2025-10-03 06:37:34.735021 | controller | ++++ functions-common:get_default_host_ip:775 :   awk '/inet6/ {split($2,parts,"/");  print parts[1]}'
2025-10-03 06:37:34.735465 | controller | ++++ functions-common:get_default_host_ip:775 :   LC_ALL=C
2025-10-03 06:37:34.737974 | controller | ++++ functions-common:get_default_host_ip:775 :   ip -f inet6 addr show
2025-10-03 06:37:34.743218 | controller | +++ functions-common:get_default_host_ip:775 :   host_ips='::1
2025-10-03 06:37:34.745306 | controller | fe80::f816:3eff:fe2f:25fa'
2025-10-03 06:37:34.745328 | controller | +++ functions-common:get_default_host_ip:776 :   local ip
2025-10-03 06:37:34.747582 | controller | +++ functions-common:get_default_host_ip:777 :   for ip in $host_ips
2025-10-03 06:37:34.749121 | controller | +++ functions-common:get_default_host_ip:784 :   [[ inet6 == \i\n\e\t\6 ]]
2025-10-03 06:37:34.751187 | controller | +++ functions-common:get_default_host_ip:785 :   host_ip=::1
2025-10-03 06:37:34.753360 | controller | +++ functions-common:get_default_host_ip:786 :   break
2025-10-03 06:37:34.755847 | controller | +++ functions-common:get_default_host_ip:794 :   echo ::1
2025-10-03 06:37:34.758888 | controller | ++ stackrc:source:823                       :   HOST_IPV6=::1
2025-10-03 06:37:34.761543 | controller | +++ stackrc:source:826                       :   trueorfalse True NEUTRON_PORT_SECURITY
2025-10-03 06:37:34.763513 | controller | +++ functions-common:trueorfalse:222         :   local xtrace
2025-10-03 06:37:34.766568 | controller | ++++ functions-common:trueorfalse:223         :   set +o
2025-10-03 06:37:34.766679 | controller | ++++ functions-common:trueorfalse:223         :   grep xtrace
2025-10-03 06:37:34.770683 | controller | +++ functions-common:trueorfalse:223         :   xtrace='set -o xtrace'
2025-10-03 06:37:34.772564 | controller | +++ functions-common:trueorfalse:224         :   set +o xtrace
2025-10-03 06:37:34.775625 | controller | ++ stackrc:source:826                       :   NEUTRON_PORT_SECURITY=True
2025-10-03 06:37:34.777123 | controller | ++ stackrc:source:831                       :   SERVICE_IP_VERSION=4
2025-10-03 06:37:34.779086 | controller | ++ stackrc:source:837                       :   [[ 4 != \4 ]]
2025-10-03 06:37:34.781089 | controller | ++ stackrc:source:841                       :   [[ 4 == 4 ]]
2025-10-03 06:37:34.783032 | controller | ++ stackrc:source:842                       :   DEF_SERVICE_HOST=38.102.83.227
2025-10-03 06:37:34.784972 | controller | ++ stackrc:source:843                       :   DEF_SERVICE_LOCAL_HOST=127.0.0.1
2025-10-03 06:37:34.787410 | controller | ++ stackrc:source:844                       :   DEF_SERVICE_LISTEN_ADDRESS=0.0.0.0
2025-10-03 06:37:34.789070 | controller | ++ stackrc:source:847                       :   [[ 4 == 6 ]]
2025-10-03 06:37:34.791949 | controller | ++ stackrc:source:858                       :   SERVICE_LISTEN_ADDRESS=0.0.0.0
2025-10-03 06:37:34.794018 | controller | ++ stackrc:source:862                       :   SERVICE_HOST=38.102.83.227
2025-10-03 06:37:34.798364 | controller | ++ stackrc:source:864                       :   SERVICE_LOCAL_HOST=127.0.0.1
2025-10-03 06:37:34.802694 | controller | ++ stackrc:source:868                       :   TUNNEL_IP_VERSION=4
2025-10-03 06:37:34.804806 | controller | ++ stackrc:source:871                       :   [[ 4 != \4 ]]
2025-10-03 06:37:34.806949 | controller | ++ stackrc:source:875                       :   [[ 4 == 4 ]]
2025-10-03 06:37:34.808943 | controller | ++ stackrc:source:876                       :   DEF_TUNNEL_ENDPOINT_IP=38.102.83.227
2025-10-03 06:37:34.811126 | controller | ++ stackrc:source:879                       :   [[ 4 == 6 ]]
2025-10-03 06:37:34.813406 | controller | ++ stackrc:source:890                       :   TUNNEL_ENDPOINT_IP=38.102.83.227
2025-10-03 06:37:34.815775 | controller | +++ stackrc:source:893                       :   trueorfalse False SYSLOG
2025-10-03 06:37:34.817905 | controller | +++ functions-common:trueorfalse:222         :   local xtrace
2025-10-03 06:37:34.821489 | controller | ++++ functions-common:trueorfalse:223         :   grep xtrace
2025-10-03 06:37:34.825206 | controller | ++++ functions-common:trueorfalse:223         :   set +o
2025-10-03 06:37:34.825233 | controller | +++ functions-common:trueorfalse:223         :   xtrace='set -o xtrace'
2025-10-03 06:37:34.827137 | controller | +++ functions-common:trueorfalse:224         :   set +o xtrace
2025-10-03 06:37:34.829525 | controller | ++ stackrc:source:893                       :   SYSLOG=False
2025-10-03 06:37:34.831430 | controller | ++ stackrc:source:894                       :   SYSLOG_HOST=38.102.83.227
2025-10-03 06:37:34.833307 | controller | ++ stackrc:source:895                       :   SYSLOG_PORT=516
2025-10-03 06:37:34.835311 | controller | ++ stackrc:source:899                       :   GIT_DEPTH=0
2025-10-03 06:37:34.837843 | controller | +++ stackrc:source:903                       :   trueorfalse True RECREATE_KEYSTONE_DB
2025-10-03 06:37:34.839967 | controller | +++ functions-common:trueorfalse:222         :   local xtrace
2025-10-03 06:37:34.843159 | controller | ++++ functions-common:trueorfalse:223         :   set +o
2025-10-03 06:37:34.843178 | controller | ++++ functions-common:trueorfalse:223         :   grep xtrace
2025-10-03 06:37:34.847134 | controller | +++ functions-common:trueorfalse:223         :   xtrace='set -o xtrace'
2025-10-03 06:37:34.849019 | controller | +++ functions-common:trueorfalse:224         :   set +o xtrace
2025-10-03 06:37:34.851750 | controller | ++ stackrc:source:903                       :   RECREATE_KEYSTONE_DB=True
2025-10-03 06:37:34.853719 | controller | ++ stackrc:source:915                       :   [[ -z '' ]]
2025-10-03 06:37:34.855660 | controller | ++ stackrc:source:916                       :   default_logdir=/opt/stack/logs
2025-10-03 06:37:34.857584 | controller | ++ stackrc:source:917                       :   [[ -z /opt/stack/logs/devstacklog.txt ]]
2025-10-03 06:37:34.859578 | controller | ++ stackrc:source:922                       :   LOGDIR=/opt/stack/logs
2025-10-03 06:37:34.861461 | controller | ++ stackrc:source:923                       :   logfile=devstacklog.txt
2025-10-03 06:37:34.863449 | controller | ++ stackrc:source:924                       :   [[ -z /opt/stack/logs ]]
2025-10-03 06:37:34.865387 | controller | ++ stackrc:source:924                       :   [[ /opt/stack/logs == \d\e\v\s\t\a\c\k\l\o\g\.\t\x\t ]]
2025-10-03 06:37:34.867616 | controller | ++ stackrc:source:929                       :   unset default_logdir logfile
2025-10-03 06:37:34.869559 | controller | ++ stackrc:source:935                       :   ULIMIT_NOFILE=2048
2025-10-03 06:37:34.871642 | controller | + ./stack.sh:main:229                      :   write_devstack_version
2025-10-03 06:37:34.874546 | controller | + functions:write_devstack_version:869     :   cat -
2025-10-03 06:37:34.874944 | controller | + functions:write_devstack_version:869     :   sudo tee /etc/devstack-version
2025-10-03 06:37:34.878010 | controller | ++ functions:write_devstack_version:869     :   git log '--format=%H %s %ci' -1
2025-10-03 06:37:34.914035 | controller | + ./stack.sh:main:233                      :   SUPPORTED_DISTROS='bookworm|jammy|noble|rhel9|rhel10'
2025-10-03 06:37:34.917315 | controller | + ./stack.sh:main:235                      :   [[ ! rhel10 =~ bookworm|jammy|noble|rhel9|rhel10 ]]
2025-10-03 06:37:34.920475 | controller | + ./stack.sh:main:246                      :   export_proxy_variables
2025-10-03 06:37:34.923437 | controller | + functions-common:export_proxy_variables:2241 :   isset http_proxy
2025-10-03 06:37:34.926567 | controller | + functions-common:isset:264               :   [[ -v http_proxy ]]
2025-10-03 06:37:34.929801 | controller | + functions-common:export_proxy_variables:2244 :   isset https_proxy
2025-10-03 06:37:34.932942 | controller | + functions-common:isset:264               :   [[ -v https_proxy ]]
2025-10-03 06:37:34.936217 | controller | + functions-common:export_proxy_variables:2247 :   isset no_proxy
2025-10-03 06:37:34.938999 | controller | + functions-common:isset:264               :   [[ -v no_proxy ]]
2025-10-03 06:37:34.941642 | controller | + ./stack.sh:main:251                      :   disable_negated_services
2025-10-03 06:37:34.944216 | controller | + functions-common:disable_negated_services:1946 :   local xtrace
2025-10-03 06:37:34.949641 | controller | ++ functions-common:disable_negated_services:1947 :   set +o
2025-10-03 06:37:34.950577 | controller | ++ functions-common:disable_negated_services:1947 :   grep xtrace
2025-10-03 06:37:34.955125 | controller | + functions-common:disable_negated_services:1947 :   xtrace='set -o xtrace'
2025-10-03 06:37:34.958203 | controller | + functions-common:disable_negated_services:1948 :   set +o xtrace
2025-10-03 06:37:34.979020 | controller | + ./stack.sh:main:258                      :   is_package_installed sudo
2025-10-03 06:37:34.981623 | controller | + functions-common:is_package_installed:1450 :   [[ -z sudo ]]
2025-10-03 06:37:34.984060 | controller | + functions-common:is_package_installed:1454 :   [[ -z rpm ]]
2025-10-03 06:37:34.987173 | controller | + functions-common:is_package_installed:1458 :   [[ rpm = \d\e\b ]]
2025-10-03 06:37:34.989720 | controller | + functions-common:is_package_installed:1460 :   [[ rpm = \r\p\m ]]
2025-10-03 06:37:34.992318 | controller | + functions-common:is_package_installed:1461 :   rpm --quiet -q sudo
2025-10-03 06:37:35.078802 | controller | + ./stack.sh:main:261                      :   sudo grep -q '^#includedir.*/etc/sudoers.d' /etc/sudoers
2025-10-03 06:37:35.098195 | controller | + ./stack.sh:main:265                      :   [[ -n '' ]]
2025-10-03 06:37:35.101721 | controller | ++ ./stack.sh:main:274                      :   mktemp
2025-10-03 06:37:35.106367 | controller | + ./stack.sh:main:274                      :   TEMPFILE=/tmp/tmp.QBOkDyZhU1
2025-10-03 06:37:35.109077 | controller | + ./stack.sh:main:275                      :   echo 'stack ALL=(root) NOPASSWD:ALL'
2025-10-03 06:37:35.111840 | controller | + ./stack.sh:main:278                      :   echo 'Defaults:stack secure_path=/sbin:/usr/sbin:/usr/bin:/bin:/usr/local/sbin:/usr/local/bin'
2025-10-03 06:37:35.114933 | controller | + ./stack.sh:main:279                      :   echo 'Defaults:stack !requiretty'
2025-10-03 06:37:35.118046 | controller | + ./stack.sh:main:280                      :   chmod 0440 /tmp/tmp.QBOkDyZhU1
2025-10-03 06:37:35.122211 | controller | + ./stack.sh:main:281                      :   sudo chown root:root /tmp/tmp.QBOkDyZhU1
2025-10-03 06:37:35.154435 | controller | + ./stack.sh:main:282                      :   sudo mv /tmp/tmp.QBOkDyZhU1 /etc/sudoers.d/50_stack_sh
2025-10-03 06:37:35.189116 | controller | + ./stack.sh:main:288                      :   is_ubuntu
2025-10-03 06:37:35.192438 | controller | + functions-common:is_ubuntu:555           :   [[ -z rpm ]]
2025-10-03 06:37:35.195706 | controller | + functions-common:is_ubuntu:558           :   '[' rpm = deb ']'
2025-10-03 06:37:35.199269 | controller | + ./stack.sh:main:327                      :   DEST=/opt/stack
2025-10-03 06:37:35.202457 | controller | + ./stack.sh:main:332                      :   [[ ! -d /opt/stack ]]
2025-10-03 06:37:35.206009 | controller | + ./stack.sh:main:339                      :   [[ -n /opt/stack/logs ]]
2025-10-03 06:37:35.209226 | controller | + ./stack.sh:main:340                      :   sudo mkdir -p /opt/stack/logs
2025-10-03 06:37:35.239336 | controller | + ./stack.sh:main:341                      :   safe_chown -R stack /opt/stack/logs
2025-10-03 06:37:35.241911 | controller | + functions-common:safe_chown:2324         :   _safe_permission_operation chown -R stack /opt/stack/logs
2025-10-03 06:37:35.245227 | controller | + functions-common:_safe_permission_operation:2149 :   local xtrace
2025-10-03 06:37:35.249613 | controller | ++ functions-common:_safe_permission_operation:2150 :   set +o
2025-10-03 06:37:35.249782 | controller | ++ functions-common:_safe_permission_operation:2150 :   grep xtrace
2025-10-03 06:37:35.255948 | controller | + functions-common:_safe_permission_operation:2150 :   xtrace='set -o xtrace'
2025-10-03 06:37:35.259093 | controller | + functions-common:_safe_permission_operation:2151 :   set +o xtrace
2025-10-03 06:37:35.265594 | controller | + functions-common:_safe_permission_operation:2172 :   sudo chown -R stack /opt/stack/logs
2025-10-03 06:37:35.293175 | controller | + ./stack.sh:main:342                      :   safe_chmod 0755 /opt/stack/logs
2025-10-03 06:37:35.295866 | controller | + functions-common:safe_chmod:2318         :   _safe_permission_operation chmod 0755 /opt/stack/logs
2025-10-03 06:37:35.298352 | controller | + functions-common:_safe_permission_operation:2149 :   local xtrace
2025-10-03 06:37:35.302377 | controller | ++ functions-common:_safe_permission_operation:2150 :   set +o
2025-10-03 06:37:35.302880 | controller | ++ functions-common:_safe_permission_operation:2150 :   grep xtrace
2025-10-03 06:37:35.308439 | controller | + functions-common:_safe_permission_operation:2150 :   xtrace='set -o xtrace'
2025-10-03 06:37:35.310301 | controller | + functions-common:_safe_permission_operation:2151 :   set +o xtrace
2025-10-03 06:37:35.314598 | controller | + functions-common:_safe_permission_operation:2172 :   sudo chmod 0755 /opt/stack/logs
2025-10-03 06:37:35.342902 | controller | + ./stack.sh:main:346                      :   DATA_DIR=/opt/stack/data
2025-10-03 06:37:35.345384 | controller | + ./stack.sh:main:347                      :   [[ ! -d /opt/stack/data ]]
2025-10-03 06:37:35.348179 | controller | + ./stack.sh:main:348                      :   sudo mkdir -p /opt/stack/data
2025-10-03 06:37:35.377228 | controller | + ./stack.sh:main:349                      :   safe_chown -R stack /opt/stack/data
2025-10-03 06:37:35.379916 | controller | + functions-common:safe_chown:2324         :   _safe_permission_operation chown -R stack /opt/stack/data
2025-10-03 06:37:35.382531 | controller | + functions-common:_safe_permission_operation:2149 :   local xtrace
2025-10-03 06:37:35.386376 | controller | ++ functions-common:_safe_permission_operation:2150 :   grep xtrace
2025-10-03 06:37:35.387028 | controller | ++ functions-common:_safe_permission_operation:2150 :   set +o
2025-10-03 06:37:35.390881 | controller | + functions-common:_safe_permission_operation:2150 :   xtrace='set -o xtrace'
2025-10-03 06:37:35.393546 | controller | + functions-common:_safe_permission_operation:2151 :   set +o xtrace
2025-10-03 06:37:35.399588 | controller | + functions-common:_safe_permission_operation:2172 :   sudo chown -R stack /opt/stack/data
2025-10-03 06:37:35.429717 | controller | + ./stack.sh:main:350                      :   safe_chmod 0755 /opt/stack/data
2025-10-03 06:37:35.431846 | controller | + functions-common:safe_chmod:2318         :   _safe_permission_operation chmod 0755 /opt/stack/data
2025-10-03 06:37:35.434429 | controller | + functions-common:_safe_permission_operation:2149 :   local xtrace
2025-10-03 06:37:35.438788 | controller | ++ functions-common:_safe_permission_operation:2150 :   grep xtrace
2025-10-03 06:37:35.439704 | controller | ++ functions-common:_safe_permission_operation:2150 :   set +o
2025-10-03 06:37:35.443095 | controller | + functions-common:_safe_permission_operation:2150 :   xtrace='set -o xtrace'
2025-10-03 06:37:35.445468 | controller | + functions-common:_safe_permission_operation:2151 :   set +o xtrace
2025-10-03 06:37:35.451122 | controller | + functions-common:_safe_permission_operation:2172 :   sudo chmod 0755 /opt/stack/data
2025-10-03 06:37:35.470790 | controller | + ./stack.sh:main:354                      :   async_init
2025-10-03 06:37:35.473122 | controller | + inc/async:async_init:217                 :   local async_dir=/opt/stack/async
2025-10-03 06:37:35.475222 | controller | + inc/async:async_init:220                 :   rm -Rf /opt/stack/async
2025-10-03 06:37:35.479807 | controller | + inc/async:async_init:223                 :   mkdir -p /opt/stack/async
2025-10-03 06:37:35.485039 | controller | ++ ./stack.sh:main:359                      :   hostname -s
2025-10-03 06:37:35.489178 | controller | + ./stack.sh:main:359                      :   LOCAL_HOSTNAME=np0005468665
2025-10-03 06:37:35.491342 | controller | + ./stack.sh:main:360                      :   grep -Fqwe np0005468665 /etc/hosts
2025-10-03 06:37:35.496054 | controller | + ./stack.sh:main:361                      :   sudo sed -i 's/\(^127.0.0.1.*\)/\1 np0005468665/' /etc/hosts
2025-10-03 06:37:35.519548 | controller | ++ ./stack.sh:main:367                      :   trueorfalse False SKIP_EPEL_INSTALL
2025-10-03 06:37:35.521769 | controller | ++ functions-common:trueorfalse:222         :   local xtrace
2025-10-03 06:37:35.525159 | controller | +++ functions-common:trueorfalse:223         :   set +o
2025-10-03 06:37:35.526299 | controller | +++ functions-common:trueorfalse:223         :   grep xtrace
2025-10-03 06:37:35.531605 | controller | ++ functions-common:trueorfalse:223         :   xtrace='set -o xtrace'
2025-10-03 06:37:35.533714 | controller | ++ functions-common:trueorfalse:224         :   set +o xtrace
2025-10-03 06:37:35.537092 | controller | + ./stack.sh:main:367                      :   SKIP_EPEL_INSTALL=False
2025-10-03 06:37:35.539321 | controller | + ./stack.sh:main:369                      :   [[ rhel10 == \r\h\e\l\8 ]]
2025-10-03 06:37:35.541261 | controller | + ./stack.sh:main:398                      :   [[ rhel10 == \r\h\e\l\9 ]]
2025-10-03 06:37:35.543922 | controller | + ./stack.sh:main:412                      :   [[ rhel10 == \r\h\e\l\1\0 ]]
2025-10-03 06:37:35.546167 | controller | + ./stack.sh:main:414                      :   sudo dnf config-manager --set-enabled crb
2025-10-03 06:37:35.970072 | controller | + ./stack.sh:main:416                      :   _install_rdo
2025-10-03 06:37:35.972068 | controller | + ./stack.sh:_install_rdo:305              :   [[ rhel10 =~ rhel ]]
2025-10-03 06:37:35.973997 | controller | + ./stack.sh:_install_rdo:306              :   VERSION=10
2025-10-03 06:37:35.975822 | controller | + ./stack.sh:_install_rdo:307              :   rdo_release=master
2025-10-03 06:37:35.977655 | controller | + ./stack.sh:_install_rdo:308              :   [[ master == \m\a\s\t\e\r ]]
2025-10-03 06:37:35.979655 | controller | + ./stack.sh:_install_rdo:310              :   sudo wget https://trunk.rdoproject.org/centos10-master/delorean-deps.repo -O /etc/yum.repos.d/delorean-deps.repo
2025-10-03 06:37:36.000669 | controller | --2025-10-03 06:37:35--  https://trunk.rdoproject.org/centos10-master/delorean-deps.repo
2025-10-03 06:37:36.105229 | controller | Resolving trunk.rdoproject.org (trunk.rdoproject.org)... 38.129.56.180
2025-10-03 06:37:36.109363 | controller | Connecting to trunk.rdoproject.org (trunk.rdoproject.org)|38.129.56.180|:443... connected.
2025-10-03 06:37:36.166818 | controller | HTTP request sent, awaiting response... 200 OK
2025-10-03 06:37:36.166911 | controller | Length: 1435 (1.4K)
2025-10-03 06:37:36.166919 | controller | Saving to: ‘/etc/yum.repos.d/delorean-deps.repo’
2025-10-03 06:37:36.166926 | controller |
2025-10-03 06:37:36.166938 | controller |      0K .                                                     100% 47.2M=0s
2025-10-03 06:37:36.172898 | controller |
2025-10-03 06:37:36.172940 | controller | 2025-10-03 06:37:36 (47.2 MB/s) - ‘/etc/yum.repos.d/delorean-deps.repo’ saved [1435/1435]
2025-10-03 06:37:36.172950 | controller |
2025-10-03 06:37:36.172961 | controller | + ./stack.sh:_install_rdo:319              :   sudo dnf -y update
2025-10-03 06:37:36.984933 | controller | CentOS Stream 10 - BaseOS                        75 kB/s | 6.7 kB     00:00
2025-10-03 06:37:37.284357 | controller | CentOS Stream 10 - AppStream                     29 kB/s | 6.8 kB     00:00
2025-10-03 06:37:37.530847 | controller | CentOS Stream 10 - CRB                           44 kB/s | 6.6 kB     00:00
2025-10-03 06:37:37.660252 | controller | CentOS Stream 10 - Extras packages               79 kB/s | 8.0 kB     00:00
2025-10-03 06:37:37.727026 | controller | dlrn-master-testing                             3.1 MB/s | 206 kB     00:00
2025-10-03 06:37:37.848423 | controller | dlrn-master-build-deps                          2.1 MB/s |  73 kB     00:00
2025-10-03 06:37:37.927753 | controller | centos9-rabbitmq                                1.3 MB/s |  44 kB     00:00
2025-10-03 06:37:38.013784 | controller | centos10-storage                                972 kB/s |  47 kB     00:00
2025-10-03 06:37:39.353033 | controller | NFV SIG OpenvSwitch                             6.4 kB/s | 8.2 kB     00:01
2025-10-03 06:37:39.877066 | controller | Extra Packages for Enterprise Linux 10 - x86_64  12 MB/s | 5.6 MB     00:00
2025-10-03 06:37:42.709440 | controller | Dependencies resolved.
2025-10-03 06:37:42.710411 | controller | Nothing to do.
2025-10-03 06:37:42.710447 | controller | Complete!
2025-10-03 06:37:42.782914 | controller | + ./stack.sh:main:434                      :   install_python
2025-10-03 06:37:42.786286 | controller | + inc/python:install_python:483            :   install_python3
2025-10-03 06:37:42.790278 | controller | + inc/python:install_python3:489           :   is_ubuntu
2025-10-03 06:37:42.793460 | controller | + functions-common:is_ubuntu:555           :   [[ -z rpm ]]
2025-10-03 06:37:42.796650 | controller | + functions-common:is_ubuntu:558           :   '[' rpm = deb ']'
2025-10-03 06:37:42.799866 | controller | + inc/python:install_python3:491           :   is_fedora
2025-10-03 06:37:42.803124 | controller | + functions-common:is_fedora:535           :   [[ -z CentOSStream ]]
2025-10-03 06:37:42.805916 | controller | + functions-common:is_fedora:539           :   '[' CentOSStream = Fedora ']'
2025-10-03 06:37:42.809009 | controller | + functions-common:is_fedora:539           :   '[' CentOSStream = 'Red Hat' ']'
2025-10-03 06:37:42.811704 | controller | + functions-common:is_fedora:540           :   '[' CentOSStream = openEuler ']'
2025-10-03 06:37:42.814788 | controller | + functions-common:is_fedora:541           :   '[' CentOSStream = RedHatEnterpriseServer ']'
2025-10-03 06:37:42.818193 | controller | + functions-common:is_fedora:542           :   '[' CentOSStream = RedHatEnterprise ']'
2025-10-03 06:37:42.821694 | controller | + functions-common:is_fedora:543           :   '[' CentOSStream = RedHatEnterpriseLinux ']'
2025-10-03 06:37:42.824916 | controller | + functions-common:is_fedora:544           :   '[' CentOSStream = RockyLinux ']'
2025-10-03 06:37:42.828301 | controller | + functions-common:is_fedora:545           :   '[' CentOSStream = CentOS ']'
2025-10-03 06:37:42.830573 | controller | + functions-common:is_fedora:545           :   '[' CentOSStream = CentOSStream ']'
2025-10-03 06:37:42.834091 | controller | + inc/python:install_python3:492           :   install_package python3.12-devel python3.12-pip
2025-10-03 06:37:42.838275 | controller | + functions-common:install_package:1441    :   update_package_repo
2025-10-03 06:37:42.841295 | controller | + functions-common:update_package_repo:1415 :   NO_UPDATE_REPOS=False
2025-10-03 06:37:42.844385 | controller | + functions-common:update_package_repo:1416 :   REPOS_UPDATED=False
2025-10-03 06:37:42.847798 | controller | + functions-common:update_package_repo:1417 :   RETRY_UPDATE=False
2025-10-03 06:37:42.851163 | controller | + functions-common:update_package_repo:1419 :   [[ False = \T\r\u\e ]]
2025-10-03 06:37:42.855174 | controller | + functions-common:update_package_repo:1423 :   is_ubuntu
2025-10-03 06:37:42.858037 | controller | + functions-common:is_ubuntu:555           :   [[ -z rpm ]]
2025-10-03 06:37:42.861036 | controller | + functions-common:is_ubuntu:558           :   '[' rpm = deb ']'
2025-10-03 06:37:42.864268 | controller | + functions-common:install_package:1442    :   real_install_package python3.12-devel python3.12-pip
2025-10-03 06:37:42.867219 | controller | + functions-common:real_install_package:1429 :   is_ubuntu
2025-10-03 06:37:42.871049 | controller | + functions-common:is_ubuntu:555           :   [[ -z rpm ]]
2025-10-03 06:37:42.874232 | controller | + functions-common:is_ubuntu:558           :   '[' rpm = deb ']'
2025-10-03 06:37:42.877629 | controller | + functions-common:real_install_package:1431 :   is_fedora
2025-10-03 06:37:42.881080 | controller | + functions-common:is_fedora:535           :   [[ -z CentOSStream ]]
2025-10-03 06:37:42.884185 | controller | + functions-common:is_fedora:539           :   '[' CentOSStream = Fedora ']'
2025-10-03 06:37:42.888069 | controller | + functions-common:is_fedora:539           :   '[' CentOSStream = 'Red Hat' ']'
2025-10-03 06:37:42.890896 | controller | + functions-common:is_fedora:540           :   '[' CentOSStream = openEuler ']'
2025-10-03 06:37:42.894166 | controller | + functions-common:is_fedora:541           :   '[' CentOSStream = RedHatEnterpriseServer ']'
2025-10-03 06:37:42.897131 | controller | + functions-common:is_fedora:542           :   '[' CentOSStream = RedHatEnterprise ']'
2025-10-03 06:37:42.900354 | controller | + functions-common:is_fedora:543           :   '[' CentOSStream = RedHatEnterpriseLinux ']'
2025-10-03 06:37:42.904014 | controller | + functions-common:is_fedora:544           :   '[' CentOSStream = RockyLinux ']'
2025-10-03 06:37:42.906830 | controller | + functions-common:is_fedora:545           :   '[' CentOSStream = CentOS ']'
2025-10-03 06:37:42.909472 | controller | + functions-common:is_fedora:545           :   '[' CentOSStream = CentOSStream ']'
2025-10-03 06:37:42.912821 | controller | + functions-common:real_install_package:1432 :   yum_install python3.12-devel python3.12-pip
2025-10-03 06:37:42.916265 | controller | + functions-common:yum_install:1486        :   local result parse_yum_result
2025-10-03 06:37:42.919652 | controller | + functions-common:yum_install:1488        :   [[ False = \T\r\u\e ]]
2025-10-03 06:37:42.923382 | controller | + functions-common:yum_install:1490        :   time_start yum_install
2025-10-03 06:37:42.926282 | controller | + functions-common:time_start:2409         :   local name=yum_install
2025-10-03 06:37:42.929684 | controller | + functions-common:time_start:2410         :   local start_time=
2025-10-03 06:37:42.933260 | controller | + functions-common:time_start:2411         :   [[ -n '' ]]
2025-10-03 06:37:42.937882 | controller | ++ functions-common:time_start:2414         :   date +%s%3N
2025-10-03 06:37:42.944151 | controller | + functions-common:time_start:2414         :   _TIME_START[$name]=1759487862940
2025-10-03 06:37:42.947063 | controller | + functions-common:yum_install:1491        :   sudo_with_proxies dnf install -y python3.12-devel python3.12-pip
2025-10-03 06:37:42.950332 | controller | + functions-common:sudo_with_proxies:2377  :   local sudo
2025-10-03 06:37:42.954415 | controller | ++ functions-common:sudo_with_proxies:2379  :   id -u
2025-10-03 06:37:42.962070 | controller | + functions-common:sudo_with_proxies:2379  :   [[ 1003 = \0 ]]
2025-10-03 06:37:42.965250 | controller | + functions-common:sudo_with_proxies:2379  :   sudo=sudo
2025-10-03 06:37:42.968667 | controller | + functions-common:sudo_with_proxies:2381  :   sudo http_proxy= https_proxy= no_proxy= dnf install -y python3.12-devel python3.12-pip
2025-10-03 06:37:43.669366 | controller | Last metadata expiration check: 0:00:04 ago on Fri 03 Oct 2025 06:37:39 AM EDT.
2025-10-03 06:37:43.751888 | controller | Package python3-devel-3.12.11-3.el10.x86_64 is already installed.
2025-10-03 06:37:43.753563 | controller | Package python3-pip-23.3.2-7.el10.noarch is already installed.
2025-10-03 06:37:43.782209 | controller | Dependencies resolved.
2025-10-03 06:37:43.783220 | controller | Nothing to do.
2025-10-03 06:37:43.833703 | controller | Complete!
2025-10-03 06:37:43.833815 | controller | + functions-common:yum_install:1492        :   time_stop yum_install
2025-10-03 06:37:43.835926 | controller | + functions-common:time_stop:2423          :   local name
2025-10-03 06:37:43.837659 | controller | + functions-common:time_stop:2424          :   local end_time
2025-10-03 06:37:43.839964 | controller | + functions-common:time_stop:2425          :   local elapsed_time
2025-10-03 06:37:43.843990 | controller | + functions-common:time_stop:2426          :   local total
2025-10-03 06:37:43.846835 | controller | + functions-common:time_stop:2427          :   local start_time
2025-10-03 06:37:43.849411 | controller | + functions-common:time_stop:2429          :   name=yum_install
2025-10-03 06:37:43.852700 | controller | + functions-common:time_stop:2430          :   start_time=1759487862940
2025-10-03 06:37:43.855330 | controller | + functions-common:time_stop:2432          :   [[ -z 1759487862940 ]]
2025-10-03 06:37:43.858378 | controller | ++ functions-common:time_stop:2435          :   date +%s%3N
2025-10-03 06:37:43.863539 | controller | + functions-common:time_stop:2435          :   end_time=1759487863860
2025-10-03 06:37:43.866945 | controller | + functions-common:time_stop:2436          :   elapsed_time=920
2025-10-03 06:37:43.869351 | controller | + functions-common:time_stop:2437          :   total=0
2025-10-03 06:37:43.871581 | controller | + functions-common:time_stop:2439          :   _TIME_START[$name]=
2025-10-03 06:37:43.873374 | controller | + functions-common:time_stop:2440          :   _TIME_TOTAL[$name]=920
2025-10-03 06:37:43.877650 | controller | ++ inc/python:install_python:484            :   which python3.12
2025-10-03 06:37:43.883108 | controller | + inc/python:install_python:484            :   export PYTHON=/bin/python3.12
2025-10-03 06:37:43.885616 | controller | + inc/python:install_python:484            :   PYTHON=/bin/python3.12
2025-10-03 06:37:43.889841 | controller | ++ ./stack.sh:main:441                      :   trueorfalse True VERBOSE
2025-10-03 06:37:43.893029 | controller | ++ functions-common:trueorfalse:222         :   local xtrace
2025-10-03 06:37:43.897421 | controller | +++ functions-common:trueorfalse:223         :   grep xtrace
2025-10-03 06:37:43.897666 | controller | +++ functions-common:trueorfalse:223         :   set +o
2025-10-03 06:37:43.903377 | controller | ++ functions-common:trueorfalse:223         :   xtrace='set -o xtrace'
2025-10-03 06:37:43.906371 | controller | ++ functions-common:trueorfalse:224         :   set +o xtrace
2025-10-03 06:37:43.909821 | controller | + ./stack.sh:main:441                      :   VERBOSE=True
2025-10-03 06:37:43.913692 | controller | ++ ./stack.sh:main:442                      :   trueorfalse False VERBOSE
2025-10-03 06:37:43.916695 | controller | ++ functions-common:trueorfalse:222         :   local xtrace
2025-10-03 06:37:43.920392 | controller | +++ functions-common:trueorfalse:223         :   set +o
2025-10-03 06:37:43.921223 | controller | +++ functions-common:trueorfalse:223         :   grep xtrace
2025-10-03 06:37:43.927418 | controller | ++ functions-common:trueorfalse:223         :   xtrace='set -o xtrace'
2025-10-03 06:37:43.929783 | controller | ++ functions-common:trueorfalse:224         :   set +o xtrace
2025-10-03 06:37:43.932396 | controller | + ./stack.sh:main:442                      :   VERBOSE_NO_TIMESTAMP=True
2025-10-03 06:37:43.935522 | controller | + ./stack.sh:main:488                      :   TIMESTAMP_FORMAT=%F-%H%M%S
2025-10-03 06:37:43.938501 | controller | + ./stack.sh:main:489                      :   LOGDAYS=7
2025-10-03 06:37:43.941773 | controller | ++ ./stack.sh:main:490                      :   date +%F-%H%M%S
2025-10-03 06:37:43.946754 | controller | + ./stack.sh:main:490                      :   CURRENT_LOG_TIME=2025-10-03-063743
2025-10-03 06:37:43.949169 | controller | + ./stack.sh:main:492                      :   [[ -n /opt/stack/logs/devstacklog.txt ]]
2025-10-03 06:37:43.951158 | controller | + ./stack.sh:main:495                      :   LOGFILE_DIR=/opt/stack/logs
2025-10-03 06:37:43.953413 | controller | + ./stack.sh:main:496                      :   LOGFILE_NAME=devstacklog.txt
2025-10-03 06:37:43.955663 | controller | + ./stack.sh:main:497                      :   mkdir -p /opt/stack/logs
2025-10-03 06:37:43.959357 | controller | + ./stack.sh:main:498                      :   find /opt/stack/logs -maxdepth 1 -name 'devstacklog.txt.*' -mtime +7 -exec rm '{}' ';'
2025-10-03 06:37:43.963183 | controller | + ./stack.sh:main:499                      :   LOGFILE=/opt/stack/logs/devstacklog.txt.2025-10-03-063743
2025-10-03 06:37:43.965495 | controller | + ./stack.sh:main:500                      :   SUMFILE=/opt/stack/logs/devstacklog.txt.2025-10-03-063743.summary.2025-10-03-063743
2025-10-03 06:37:43.967549 | controller | + ./stack.sh:main:506                      :   exec
2025-10-03 06:37:43.970005 | controller | + ./stack.sh:main:507                      :   [[ True == \T\r\u\e ]]
2025-10-03 06:37:43.972869 | controller | + ./stack.sh:main:508                      :   _of_args=-v
2025-10-03 06:37:43.975078 | controller | + ./stack.sh:main:509                      :   [[ True == \T\r\u\e ]]
2025-10-03 06:37:43.977570 | controller | + ./stack.sh:main:510                      :   _of_args='-v --no-timestamp'
2025-10-03 06:37:43.980046 | controller | + ./stack.sh:main:513                      :   exec
2025-10-03 06:37:43.982923 | controller | ++ ./stack.sh:main:513                      :   /bin/python3.12 /opt/stack/devstack/tools/outfilter.py -v --no-timestamp -o /opt/stack/logs/devstacklog.txt.2025-10-03-063743
2025-10-03 06:37:43.998199 | controller | /opt/stack/devstack/tools/outfilter.py:29: SyntaxWarning: invalid escape sequence '\+'
2025-10-03 06:37:43.998273 | controller |   IGNORE_LINES = re.compile('(set \+o|xtrace)')
2025-10-03 06:37:43.998301 | controller | /opt/stack/devstack/tools/outfilter.py:30: SyntaxWarning: invalid escape sequence '\d'
2025-10-03 06:37:43.998402 | controller |   HAS_DATE = re.compile('^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3} \|')
2025-10-03 06:37:44.018999 | controller | + ./stack.sh:main:515                      :   exec
2025-10-03 06:37:44.019051 | controller | ++ ./stack.sh:main:515                      :   /bin/python3.12 /opt/stack/devstack/tools/outfilter.py -o /opt/stack/logs/devstacklog.txt.2025-10-03-063743.summary.2025-10-03-063743
2025-10-03 06:37:44.019062 | controller | + ./stack.sh:main:523                      :   echo_summary 'stack.sh log /opt/stack/logs/devstacklog.txt.2025-10-03-063743'
2025-10-03 06:37:44.019071 | controller | + ./stack.sh:echo_summary:468              :   [[ -t 3 ]]
2025-10-03 06:37:44.019080 | controller | + ./stack.sh:echo_summary:474              :   echo -e stack.sh log /opt/stack/logs/devstacklog.txt.2025-10-03-063743
2025-10-03 06:37:44.019091 | controller | + ./stack.sh:main:525                      :   ln -sf /opt/stack/logs/devstacklog.txt.2025-10-03-063743 /opt/stack/logs/devstacklog.txt
2025-10-03 06:37:44.019100 | controller | + ./stack.sh:main:526                      :   ln -sf /opt/stack/logs/devstacklog.txt.2025-10-03-063743.summary.2025-10-03-063743 /opt/stack/logs/devstacklog.txt.summary
2025-10-03 06:37:44.019116 | controller | /opt/stack/devstack/tools/outfilter.py:29: SyntaxWarning: invalid escape sequence '\+'
2025-10-03 06:37:44.019128 | controller | /opt/stack/devstack/tools/outfilter.py:30: SyntaxWarning: invalid escape sequence '\d'
2025-10-03 06:37:44.019137 | controller |   HAS_DATE = re.compile('^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3} \|')
2025-10-03 06:37:44.019148 | controller | + ./stack.sh:main:541                      :   check_path_perm_sanity /opt/stack
2025-10-03 06:37:44.019158 | controller | + functions:check_path_perm_sanity:608     :   local real_path
2025-10-03 06:37:44.019173 | controller | ++ functions:check_path_perm_sanity:609     :   readlink -f /opt/stack
2025-10-03 06:37:44.019184 | controller | + functions:check_path_perm_sanity:609     :   real_path=/opt/stack
2025-10-03 06:37:44.019195 | controller | + functions:check_path_perm_sanity:610     :   local rebuilt_path=
2025-10-03 06:37:44.022614 | controller | ++ functions:check_path_perm_sanity:611     :   tr / ' '
2025-10-03 06:37:44.027425 | controller | ++ functions:check_path_perm_sanity:611     :   echo /opt/stack
2025-10-03 06:37:44.027457 | controller | + functions:check_path_perm_sanity:611     :   for i in $(echo ${real_path} | tr "/" " ")
2025-10-03 06:37:44.029793 | controller | + functions:check_path_perm_sanity:612     :   rebuilt_path=/opt
2025-10-03 06:37:44.032801 | controller | ++ functions:check_path_perm_sanity:614     :   stat -c %a /opt
2025-10-03 06:37:44.038158 | controller | + functions:check_path_perm_sanity:614     :   [[ 755 = 700 ]]
2025-10-03 06:37:44.040708 | controller | + functions:check_path_perm_sanity:611     :   for i in $(echo ${real_path} | tr "/" " ")
2025-10-03 06:37:44.043046 | controller | + functions:check_path_perm_sanity:612     :   rebuilt_path=/opt/stack
2025-10-03 06:37:44.045927 | controller | ++ functions:check_path_perm_sanity:614     :   stat -c %a /opt/stack
2025-10-03 06:37:44.049641 | controller | + functions:check_path_perm_sanity:614     :   [[ 755 = 700 ]]
2025-10-03 06:37:44.051791 | controller | + ./stack.sh:main:547                      :   trap exit_trap EXIT
2025-10-03 06:37:44.054303 | controller | + ./stack.sh:main:588                      :   trap err_trap ERR
2025-10-03 06:37:44.056639 | controller | + ./stack.sh:main:601                      :   set -o errexit
2025-10-03 06:37:44.058613 | controller | + ./stack.sh:main:604                      :   uname -a
2025-10-03 06:37:44.060351 | controller | Linux np0005468665.novalocal 6.12.0-134.el10.x86_64 #1 SMP PREEMPT_DYNAMIC Wed Sep 24 15:01:11 UTC 2025 x86_64 GNU/Linux
2025-10-03 06:37:44.062367 | controller | + ./stack.sh:main:607                      :   SSL_BUNDLE_FILE=/opt/stack/data/ca-bundle.pem
2025-10-03 06:37:44.064570 | controller | + ./stack.sh:main:608                      :   rm -f /opt/stack/data/ca-bundle.pem
2025-10-03 06:37:44.068320 | controller | + ./stack.sh:main:611                      :   source /opt/stack/devstack/lib/database
2025-10-03 06:37:44.111675 | controller | + ./stack.sh:main:612                      :   source /opt/stack/devstack/lib/rpc_backend
2025-10-03 06:37:44.134486 | controller | + ./stack.sh:main:615                      :   source /opt/stack/devstack/lib/host
2025-10-03 06:37:44.138108 | controller | +++ lib/host:source:12                       :   trueorfalse True ENABLE_KSM
2025-10-03 06:37:44.162486 | controller | ++ lib/host:source:12                       :   ENABLE_KSM=True
2025-10-03 06:37:44.166540 | controller | +++ lib/host:source:13                       :   trueorfalse True ENABLE_KSMTUNED
2025-10-03 06:37:44.189628 | controller | ++ lib/host:source:13                       :   ENABLE_KSMTUNED=True
2025-10-03 06:37:44.194126 | controller | +++ lib/host:source:34                       :   trueorfalse False ENABLE_ZSWAP
2025-10-03 06:37:44.218687 | controller | ++ lib/host:source:34                       :   ENABLE_ZSWAP=True
2025-10-03 06:37:44.222263 | controller | ++ lib/host:source:37                       :   ZSWAP_COMPRESSOR=lz4
2025-10-03 06:37:44.225686 | controller | ++ lib/host:source:38                       :   ZSWAP_ZPOOL=zsmalloc
2025-10-03 06:37:44.229310 | controller | +++ lib/host:source:53                       :   trueorfalse False ENABLE_SYSCTL_MEM_TUNING
2025-10-03 06:37:44.251057 | controller | ++ lib/host:source:53                       :   ENABLE_SYSCTL_MEM_TUNING=True
2025-10-03 06:37:44.255134 | controller | +++ lib/host:source:75                       :   trueorfalse False ENABLE_SYSCTL_NET_TUNING
2025-10-03 06:37:44.275891 | controller | ++ lib/host:source:75                       :   ENABLE_SYSCTL_NET_TUNING=True
2025-10-03 06:37:44.278915 | controller | + ./stack.sh:main:618                      :   tune_host
2025-10-03 06:37:44.281704 | controller | + lib/host:tune_host:96                    :   configure_host_mem
2025-10-03 06:37:44.283757 | controller | + lib/host:configure_host_mem:70           :   configure_zswap
2025-10-03 06:37:44.286389 | controller | + lib/host:configure_zswap:40              :   [[ True == \T\r\u\e ]]
2025-10-03 06:37:44.288850 | controller | + lib/host:configure_zswap:43              :   is_ubuntu
2025-10-03 06:37:44.291260 | controller | + functions-common:is_ubuntu:555           :   [[ -z rpm ]]
2025-10-03 06:37:44.293624 | controller | + functions-common:is_ubuntu:558           :   '[' rpm = deb ']'
2025-10-03 06:37:44.297150 | controller | + lib/host:configure_zswap:47              :   echo 1
2025-10-03 06:37:44.297618 | controller | + lib/host:configure_zswap:47              :   sudo tee /sys/module/zswap/parameters/enabled
2025-10-03 06:37:44.315264 | controller | 1
2025-10-03 06:37:44.320979 | controller | + lib/host:configure_zswap:49              :   sudo grep -R . /sys/module/zswap/parameters
2025-10-03 06:37:44.349466 | controller | /sys/module/zswap/parameters/enabled:Y
2025-10-03 06:37:44.355146 | controller | /sys/module/zswap/parameters/shrinker_enabled:N
2025-10-03 06:37:44.355165 | controller | /sys/module/zswap/parameters/max_pool_percent:20
2025-10-03 06:37:44.355172 | controller | /sys/module/zswap/parameters/compressor:lzo
2025-10-03 06:37:44.355178 | controller | /sys/module/zswap/parameters/zpool:zbud
2025-10-03 06:37:44.355184 | controller | /sys/module/zswap/parameters/accept_threshold_percent:90
2025-10-03 06:37:44.355193 | controller | + lib/host:configure_host_mem:71           :   configure_ksm
2025-10-03 06:37:44.357501 | controller | + lib/host:configure_ksm:15                :   [[ True == \T\r\u\e ]]
2025-10-03 06:37:44.360258 | controller | + lib/host:configure_ksm:16                :   install_package ksmtuned
2025-10-03 06:37:44.363478 | controller | + functions-common:install_package:1441    :   update_package_repo
2025-10-03 06:37:44.366529 | controller | + functions-common:update_package_repo:1415 :   NO_UPDATE_REPOS=False
2025-10-03 06:37:44.369565 | controller | + functions-common:update_package_repo:1416 :   REPOS_UPDATED=False
2025-10-03 06:37:44.372088 | controller | + functions-common:update_package_repo:1417 :   RETRY_UPDATE=False
2025-10-03 06:37:44.375518 | controller | + functions-common:update_package_repo:1419 :   [[ False = \T\r\u\e ]]
2025-10-03 06:37:44.378548 | controller | + functions-common:update_package_repo:1423 :   is_ubuntu
2025-10-03 06:37:44.381890 | controller | + functions-common:is_ubuntu:555           :   [[ -z rpm ]]
2025-10-03 06:37:44.384710 | controller | + functions-common:is_ubuntu:558           :   '[' rpm = deb ']'
2025-10-03 06:37:44.387640 | controller | + functions-common:install_package:1442    :   real_install_package ksmtuned
2025-10-03 06:37:44.390507 | controller | + functions-common:real_install_package:1429 :   is_ubuntu
2025-10-03 06:37:44.393449 | controller | + functions-common:is_ubuntu:555           :   [[ -z rpm ]]
2025-10-03 06:37:44.396177 | controller | + functions-common:is_ubuntu:558           :   '[' rpm = deb ']'
2025-10-03 06:37:44.399249 | controller | + functions-common:real_install_package:1431 :   is_fedora
2025-10-03 06:37:44.401886 | controller | + functions-common:is_fedora:535           :   [[ -z CentOSStream ]]
2025-10-03 06:37:44.405191 | controller | + functions-common:is_fedora:539           :   '[' CentOSStream = Fedora ']'
2025-10-03 06:37:44.408381 | controller | + functions-common:is_fedora:539           :   '[' CentOSStream = 'Red Hat' ']'
2025-10-03 06:37:44.411439 | controller | + functions-common:is_fedora:540           :   '[' CentOSStream = openEuler ']'
2025-10-03 06:37:44.414600 | controller | + functions-common:is_fedora:541           :   '[' CentOSStream = RedHatEnterpriseServer ']'
2025-10-03 06:37:44.417677 | controller | + functions-common:is_fedora:542           :   '[' CentOSStream = RedHatEnterprise ']'
2025-10-03 06:37:44.420095 | controller | + functions-common:is_fedora:543           :   '[' CentOSStream = RedHatEnterpriseLinux ']'
2025-10-03 06:37:44.423336 | controller | + functions-common:is_fedora:544           :   '[' CentOSStream = RockyLinux ']'
2025-10-03 06:37:44.426420 | controller | + functions-common:is_fedora:545           :   '[' CentOSStream = CentOS ']'
2025-10-03 06:37:44.429615 | controller | + functions-common:is_fedora:545           :   '[' CentOSStream = CentOSStream ']'
2025-10-03 06:37:44.432798 | controller | + functions-common:real_install_package:1432 :   yum_install ksmtuned
2025-10-03 06:37:44.436061 | controller | + functions-common:yum_install:1486        :   local result parse_yum_result
2025-10-03 06:37:44.439132 | controller | + functions-common:yum_install:1488        :   [[ False = \T\r\u\e ]]
2025-10-03 06:37:44.442404 | controller | + functions-common:yum_install:1490        :   time_start yum_install
2025-10-03 06:37:44.445689 | controller | + functions-common:time_start:2409         :   local name=yum_install
2025-10-03 06:37:44.448221 | controller | + functions-common:time_start:2410         :   local start_time=
2025-10-03 06:37:44.450563 | controller | + functions-common:time_start:2411         :   [[ -n '' ]]
2025-10-03 06:37:44.453765 | controller | ++ functions-common:time_start:2414         :   date +%s%3N
2025-10-03 06:37:44.458874 | controller | + functions-common:time_start:2414         :   _TIME_START[$name]=1759487864455
2025-10-03 06:37:44.462547 | controller | + functions-common:yum_install:1491        :   sudo_with_proxies dnf install -y ksmtuned
2025-10-03 06:37:44.466979 | controller | + functions-common:sudo_with_proxies:2377  :   local sudo
2025-10-03 06:37:44.470288 | controller | ++ functions-common:sudo_with_proxies:2379  :   id -u
2025-10-03 06:37:44.473506 | controller | + functions-common:sudo_with_proxies:2379  :   [[ 1003 = \0 ]]
2025-10-03 06:37:44.476336 | controller | + functions-common:sudo_with_proxies:2379  :   sudo=sudo
2025-10-03 06:37:44.480370 | controller | + functions-common:sudo_with_proxies:2381  :   sudo http_proxy= https_proxy= no_proxy= dnf install -y ksmtuned
2025-10-03 06:37:45.023251 | controller | Last metadata expiration check: 0:00:05 ago on Fri 03 Oct 2025 06:37:39 AM EDT.
2025-10-03 06:37:45.113444 | controller | Dependencies resolved.
2025-10-03 06:37:45.114873 | controller | ================================================================================
2025-10-03 06:37:45.114895 | controller |  Package          Architecture   Version                Repository         Size
2025-10-03 06:37:45.114913 | controller | ================================================================================
2025-10-03 06:37:45.114941 | controller | Installing:
2025-10-03 06:37:45.114959 | controller |  ksmtuned         x86_64         0.1.0-16.el10          appstream          24 k
2025-10-03 06:37:45.114994 | controller |
2025-10-03 06:37:45.115011 | controller | Transaction Summary
2025-10-03 06:37:45.115025 | controller | ================================================================================
2025-10-03 06:37:45.115042 | controller | Install  1 Package
2025-10-03 06:37:45.115099 | controller |
2025-10-03 06:37:45.115118 | controller | Total download size: 24 k
2025-10-03 06:37:45.115226 | controller | Installed size: 38 k
2025-10-03 06:37:45.115245 | controller | Downloading Packages:
2025-10-03 06:37:45.413829 | controller | ksmtuned-0.1.0-16.el10.x86_64.rpm               112 kB/s |  24 kB     00:00
2025-10-03 06:37:45.415377 | controller | --------------------------------------------------------------------------------
2025-10-03 06:37:45.415908 | controller | Total                                            81 kB/s |  24 kB     00:00
2025-10-03 06:37:45.440968 | controller | Running transaction check
2025-10-03 06:37:45.461106 | controller | Transaction check succeeded.
2025-10-03 06:37:45.461277 | controller | Running transaction test
2025-10-03 06:37:45.569125 | controller | Transaction test succeeded.
2025-10-03 06:37:45.569436 | controller | Running transaction
2025-10-03 06:37:45.692279 | controller |   Preparing        :                                                        1/1
2025-10-03 06:37:45.702243 | controller |   Installing       : ksmtuned-0.1.0-16.el10.x86_64                          1/1
2025-10-03 06:37:45.759087 | controller |   Running scriptlet: ksmtuned-0.1.0-16.el10.x86_64                          1/1
2025-10-03 06:37:45.759120 | controller | Created symlink '/etc/systemd/system/multi-user.target.wants/ksm.service' → '/usr/lib/systemd/system/ksm.service'.
2025-10-03 06:37:45.759129 | controller | Created symlink '/etc/systemd/system/multi-user.target.wants/ksmtuned.service' → '/usr/lib/systemd/system/ksmtuned.service'.
2025-10-03 06:37:45.759153 | controller |
2025-10-03 06:37:46.778475 | controller |
2025-10-03 06:37:46.873036 | controller | Installed:
2025-10-03 06:37:46.873143 | controller |   ksmtuned-0.1.0-16.el10.x86_64
2025-10-03 06:37:46.873160 | controller |
2025-10-03 06:37:46.873174 | controller | Complete!
2025-10-03 06:37:46.873203 | controller | + functions-common:yum_install:1492        :   time_stop yum_install
2025-10-03 06:37:46.875429 | controller | + functions-common:time_stop:2423          :   local name
2025-10-03 06:37:46.877370 | controller | + functions-common:time_stop:2424          :   local end_time
2025-10-03 06:37:46.880352 | controller | + functions-common:time_stop:2425          :   local elapsed_time
2025-10-03 06:37:46.883266 | controller | + functions-common:time_stop:2426          :   local total
2025-10-03 06:37:46.885613 | controller | + functions-common:time_stop:2427          :   local start_time
2025-10-03 06:37:46.888358 | controller | + functions-common:time_stop:2429          :   name=yum_install
2025-10-03 06:37:46.890270 | controller | + functions-common:time_stop:2430          :   start_time=1759487864455
2025-10-03 06:37:46.892353 | controller | + functions-common:time_stop:2432          :   [[ -z 1759487864455 ]]
2025-10-03 06:37:46.895879 | controller | ++ functions-common:time_stop:2435          :   date +%s%3N
2025-10-03 06:37:46.900474 | controller | + functions-common:time_stop:2435          :   end_time=1759487866897
2025-10-03 06:37:46.903324 | controller | + functions-common:time_stop:2436          :   elapsed_time=2442
2025-10-03 06:37:46.905806 | controller | + functions-common:time_stop:2437          :   total=920
2025-10-03 06:37:46.909575 | controller | + functions-common:time_stop:2439          :   _TIME_START[$name]=
2025-10-03 06:37:46.912728 | controller | + functions-common:time_stop:2440          :   _TIME_TOTAL[$name]=3362
2025-10-03 06:37:46.916615 | controller | + lib/host:configure_ksm:18                :   [[ -f /sys/kernel/mm/ksm/run ]]
2025-10-03 06:37:46.921241 | controller | ++ lib/host:configure_ksm:19                :   bool_to_int ENABLE_KSM
2025-10-03 06:37:46.921363 | controller | + lib/host:configure_ksm:19                :   sudo tee /sys/kernel/mm/ksm/run
2025-10-03 06:37:46.939039 | controller | + lib/host:configure_ksm:19                :   echo 0
2025-10-03 06:37:46.954422 | controller | 0
2025-10-03 06:37:46.960573 | controller | + lib/host:configure_host_mem:72           :   configure_sysctl_mem_parmaters
2025-10-03 06:37:46.963250 | controller | + lib/host:configure_sysctl_mem_parmaters:55 :   [[ True == \T\r\u\e ]]
2025-10-03 06:37:46.966027 | controller | + lib/host:configure_sysctl_mem_parmaters:57 :   sudo sysctl -w vm.dirty_ratio=60
2025-10-03 06:37:46.990935 | controller | vm.dirty_ratio = 60
2025-10-03 06:37:46.998911 | controller | + lib/host:configure_sysctl_mem_parmaters:58 :   sudo sysctl -w vm.dirty_background_ratio=10
2025-10-03 06:37:47.017531 | controller | vm.dirty_background_ratio = 10
2025-10-03 06:37:47.023062 | controller | + lib/host:configure_sysctl_mem_parmaters:59 :   sudo sysctl -w vm.vfs_cache_pressure=50
2025-10-03 06:37:47.052629 | controller | vm.vfs_cache_pressure = 50
2025-10-03 06:37:47.060078 | controller | + lib/host:configure_sysctl_mem_parmaters:64 :   sudo sysctl -w vm.swappiness=100
2025-10-03 06:37:47.086509 | controller | vm.swappiness = 100
2025-10-03 06:37:47.093159 | controller | + lib/host:configure_sysctl_mem_parmaters:65 :   sudo grep -R . /proc/sys/vm/
2025-10-03 06:37:47.112436 | controller | /proc/sys/vm/admin_reserve_kbytes:8192
2025-10-03 06:37:47.112896 | controller | grep: /proc/sys/vm/compact_memory: Permission denied
2025-10-03 06:37:47.112942 | controller | /proc/sys/vm/compact_unevictable_allowed:1
2025-10-03 06:37:47.112957 | controller | /proc/sys/vm/compaction_proactiveness:20
2025-10-03 06:37:47.112969 | controller | /proc/sys/vm/dirty_background_bytes:0
2025-10-03 06:37:47.112983 | controller | /proc/sys/vm/dirty_background_ratio:10
2025-10-03 06:37:47.112995 | controller | /proc/sys/vm/dirty_bytes:0
2025-10-03 06:37:47.113008 | controller | /proc/sys/vm/dirty_expire_centisecs:3000
2025-10-03 06:37:47.113021 | controller | /proc/sys/vm/dirty_ratio:60
2025-10-03 06:37:47.113034 | controller | /proc/sys/vm/dirty_writeback_centisecs:500
2025-10-03 06:37:47.113046 | controller | /proc/sys/vm/dirtytime_expire_seconds:43200
2025-10-03 06:37:47.113059 | controller | grep: /proc/sys/vm/drop_caches: Permission denied
2025-10-03 06:37:47.113078 | controller | /proc/sys/vm/enable_soft_offline:1
2025-10-03 06:37:47.113164 | controller | /proc/sys/vm/extfrag_threshold:500
2025-10-03 06:37:47.113240 | controller | /proc/sys/vm/hugetlb_optimize_vmemmap:0
2025-10-03 06:37:47.113310 | controller | /proc/sys/vm/hugetlb_shm_group:0
2025-10-03 06:37:47.113390 | controller | /proc/sys/vm/laptop_mode:0
2025-10-03 06:37:47.113458 | controller | /proc/sys/vm/legacy_va_layout:0
2025-10-03 06:37:47.113526 | controller | /proc/sys/vm/lowmem_reserve_ratio:256	256	32	0	0
2025-10-03 06:37:47.113593 | controller | /proc/sys/vm/max_map_count:1048576
2025-10-03 06:37:47.113660 | controller | /proc/sys/vm/memfd_noexec:0
2025-10-03 06:37:47.113726 | controller | /proc/sys/vm/memory_failure_early_kill:0
2025-10-03 06:37:47.114571 | controller | /proc/sys/vm/memory_failure_recovery:1
2025-10-03 06:37:47.118718 | controller | /proc/sys/vm/min_free_kbytes:67584
2025-10-03 06:37:47.118815 | controller | /proc/sys/vm/min_slab_ratio:5
2025-10-03 06:37:47.118833 | controller | /proc/sys/vm/min_unmapped_ratio:1
2025-10-03 06:37:47.118846 | controller | /proc/sys/vm/mmap_min_addr:65536
2025-10-03 06:37:47.118859 | controller | /proc/sys/vm/mmap_rnd_bits:28
2025-10-03 06:37:47.118872 | controller | /proc/sys/vm/mmap_rnd_compat_bits:8
2025-10-03 06:37:47.118885 | controller | /proc/sys/vm/nr_hugepages:0
2025-10-03 06:37:47.118898 | controller | /proc/sys/vm/nr_hugepages_mempolicy:0
2025-10-03 06:37:47.118910 | controller | /proc/sys/vm/nr_overcommit_hugepages:0
2025-10-03 06:37:47.118923 | controller | /proc/sys/vm/numa_stat:1
2025-10-03 06:37:47.118936 | controller | /proc/sys/vm/numa_zonelist_order:Node
2025-10-03 06:37:47.118948 | controller | /proc/sys/vm/oom_dump_tasks:1
2025-10-03 06:37:47.118961 | controller | /proc/sys/vm/oom_kill_allocating_task:0
2025-10-03 06:37:47.118974 | controller | /proc/sys/vm/overcommit_kbytes:0
2025-10-03 06:37:47.118986 | controller | /proc/sys/vm/overcommit_memory:0
2025-10-03 06:37:47.118999 | controller | /proc/sys/vm/overcommit_ratio:50
2025-10-03 06:37:47.119011 | controller | /proc/sys/vm/page-cluster:3
2025-10-03 06:37:47.119024 | controller | /proc/sys/vm/page_lock_unfairness:5
2025-10-03 06:37:47.119037 | controller | /proc/sys/vm/panic_on_oom:0
2025-10-03 06:37:47.119049 | controller | /proc/sys/vm/percpu_pagelist_high_fraction:0
2025-10-03 06:37:47.119062 | controller | /proc/sys/vm/stat_interval:1
2025-10-03 06:37:47.119074 | controller | /proc/sys/vm/swappiness:100
2025-10-03 06:37:47.119087 | controller | /proc/sys/vm/unprivileged_userfaultfd:0
2025-10-03 06:37:47.119100 | controller | /proc/sys/vm/user_reserve_kbytes:131072
2025-10-03 06:37:47.119112 | controller | /proc/sys/vm/vfs_cache_pressure:50
2025-10-03 06:37:47.119125 | controller | /proc/sys/vm/watermark_boost_factor:15000
2025-10-03 06:37:47.119138 | controller | /proc/sys/vm/watermark_scale_factor:10
2025-10-03 06:37:47.119150 | controller | /proc/sys/vm/zone_reclaim_mode:0
2025-10-03 06:37:47.119171 | controller | + lib/host:configure_sysctl_mem_parmaters:65 :   /bin/true
2025-10-03 06:37:47.123553 | controller | + lib/host:tune_host:97                    :   configure_host_net
2025-10-03 06:37:47.126027 | controller | + lib/host:configure_host_net:92           :   configure_sysctl_net_parmaters
2025-10-03 06:37:47.128621 | controller | + lib/host:configure_sysctl_net_parmaters:77 :   [[ True == \T\r\u\e ]]
2025-10-03 06:37:47.131334 | controller | + lib/host:configure_sysctl_net_parmaters:79 :   sudo sysctl -w net.ipv4.tcp_keepalive_time=60
2025-10-03 06:37:47.158846 | controller | net.ipv4.tcp_keepalive_time = 60
2025-10-03 06:37:47.164022 | controller | + lib/host:configure_sysctl_net_parmaters:80 :   sudo sysctl -w net.ipv4.tcp_keepalive_intvl=10
2025-10-03 06:37:47.187069 | controller | net.ipv4.tcp_keepalive_intvl = 10
2025-10-03 06:37:47.192353 | controller | + lib/host:configure_sysctl_net_parmaters:81 :   sudo sysctl -w net.ipv4.tcp_keepalive_probes=6
2025-10-03 06:37:47.217100 | controller | net.ipv4.tcp_keepalive_probes = 6
2025-10-03 06:37:47.223763 | controller | + lib/host:configure_sysctl_net_parmaters:83 :   sudo sysctl -w net.ipv4.tcp_fastopen=3
2025-10-03 06:37:47.245150 | controller | net.ipv4.tcp_fastopen = 3
2025-10-03 06:37:47.253208 | controller | + lib/host:configure_sysctl_net_parmaters:85 :   sudo grep -R . /proc/sys/net/ipv4/tcp_abort_on_overflow /proc/sys/net/ipv4/tcp_adv_win_scale /proc/sys/net/ipv4/tcp_allowed_congestion_control /proc/sys/net/ipv4/tcp_app_win /proc/sys/net/ipv4/tcp_autocorking /proc/sys/net/ipv4/tcp_available_congestion_control /proc/sys/net/ipv4/tcp_available_ulp /proc/sys/net/ipv4/tcp_backlog_ack_defer /proc/sys/net/ipv4/tcp_base_mss /proc/sys/net/ipv4/tcp_challenge_ack_limit /proc/sys/net/ipv4/tcp_child_ehash_entries /proc/sys/net/ipv4/tcp_comp_sack_delay_ns /proc/sys/net/ipv4/tcp_comp_sack_nr /proc/sys/net/ipv4/tcp_comp_sack_slack_ns /proc/sys/net/ipv4/tcp_congestion_control /proc/sys/net/ipv4/tcp_dsack /proc/sys/net/ipv4/tcp_early_demux /proc/sys/net/ipv4/tcp_early_retrans /proc/sys/net/ipv4/tcp_ecn /proc/sys/net/ipv4/tcp_ecn_fallback /proc/sys/net/ipv4/tcp_ehash_entries /proc/sys/net/ipv4/tcp_fack /proc/sys/net/ipv4/tcp_fastopen /proc/sys/net/ipv4/tcp_fastopen_blackhole_timeout_sec /proc/sys/net/ipv4/tcp_fastopen_key /proc/sys/net/ipv4/tcp_fin_timeout /proc/sys/net/ipv4/tcp_frto /proc/sys/net/ipv4/tcp_fwmark_accept /proc/sys/net/ipv4/tcp_invalid_ratelimit /proc/sys/net/ipv4/tcp_keepalive_intvl /proc/sys/net/ipv4/tcp_keepalive_probes /proc/sys/net/ipv4/tcp_keepalive_time /proc/sys/net/ipv4/tcp_l3mdev_accept /proc/sys/net/ipv4/tcp_limit_output_bytes /proc/sys/net/ipv4/tcp_low_latency /proc/sys/net/ipv4/tcp_max_orphans /proc/sys/net/ipv4/tcp_max_reordering /proc/sys/net/ipv4/tcp_max_syn_backlog /proc/sys/net/ipv4/tcp_max_tw_buckets /proc/sys/net/ipv4/tcp_mem /proc/sys/net/ipv4/tcp_migrate_req /proc/sys/net/ipv4/tcp_min_rtt_wlen /proc/sys/net/ipv4/tcp_min_snd_mss /proc/sys/net/ipv4/tcp_min_tso_segs /proc/sys/net/ipv4/tcp_moderate_rcvbuf /proc/sys/net/ipv4/tcp_mtu_probe_floor /proc/sys/net/ipv4/tcp_mtu_probing /proc/sys/net/ipv4/tcp_no_metrics_save /proc/sys/net/ipv4/tcp_no_ssthresh_metrics_save /proc/sys/net/ipv4/tcp_notsent_lowat /proc/sys/net/ipv4/tcp_orphan_retries /proc/sys/net/ipv4/tcp_pacing_ca_ratio /proc/sys/net/ipv4/tcp_pacing_ss_ratio /proc/sys/net/ipv4/tcp_pingpong_thresh /proc/sys/net/ipv4/tcp_plb_cong_thresh /proc/sys/net/ipv4/tcp_plb_enabled /proc/sys/net/ipv4/tcp_plb_idle_rehash_rounds /proc/sys/net/ipv4/tcp_plb_rehash_rounds /proc/sys/net/ipv4/tcp_plb_suspend_rto_sec /proc/sys/net/ipv4/tcp_probe_interval /proc/sys/net/ipv4/tcp_probe_threshold /proc/sys/net/ipv4/tcp_recovery /proc/sys/net/ipv4/tcp_reflect_tos /proc/sys/net/ipv4/tcp_reordering /proc/sys/net/ipv4/tcp_retrans_collapse /proc/sys/net/ipv4/tcp_retries1 /proc/sys/net/ipv4/tcp_retries2 /proc/sys/net/ipv4/tcp_rfc1337 /proc/sys/net/ipv4/tcp_rmem /proc/sys/net/ipv4/tcp_rto_min_us /proc/sys/net/ipv4/tcp_sack /proc/sys/net/ipv4/tcp_shrink_window /proc/sys/net/ipv4/tcp_slow_start_after_idle /proc/sys/net/ipv4/tcp_stdurg /proc/sys/net/ipv4/tcp_synack_retries /proc/sys/net/ipv4/tcp_syncookies /proc/sys/net/ipv4/tcp_syn_linear_timeouts /proc/sys/net/ipv4/tcp_syn_retries /proc/sys/net/ipv4/tcp_thin_linear_timeouts /proc/sys/net/ipv4/tcp_timestamps /proc/sys/net/ipv4/tcp_tso_rtt_log /proc/sys/net/ipv4/tcp_tso_win_divisor /proc/sys/net/ipv4/tcp_tw_reuse /proc/sys/net/ipv4/tcp_window_scaling /proc/sys/net/ipv4/tcp_wmem /proc/sys/net/ipv4/tcp_workaround_signed_windows
2025-10-03 06:37:47.282263 | controller | /proc/sys/net/ipv4/tcp_abort_on_overflow:0
2025-10-03 06:37:47.282337 | controller | /proc/sys/net/ipv4/tcp_adv_win_scale:1
2025-10-03 06:37:47.282361 | controller | /proc/sys/net/ipv4/tcp_allowed_congestion_control:reno cubic
2025-10-03 06:37:47.282387 | controller | /proc/sys/net/ipv4/tcp_app_win:31
2025-10-03 06:37:47.282413 | controller | /proc/sys/net/ipv4/tcp_autocorking:1
2025-10-03 06:37:47.282487 | controller | /proc/sys/net/ipv4/tcp_available_congestion_control:reno cubic
2025-10-03 06:37:47.282511 | controller | /proc/sys/net/ipv4/tcp_available_ulp:espintcp mptcp
2025-10-03 06:37:47.282531 | controller | /proc/sys/net/ipv4/tcp_backlog_ack_defer:1
2025-10-03 06:37:47.282555 | controller | /proc/sys/net/ipv4/tcp_base_mss:1024
2025-10-03 06:37:47.282574 | controller | /proc/sys/net/ipv4/tcp_challenge_ack_limit:2147483647
2025-10-03 06:37:47.282592 | controller | /proc/sys/net/ipv4/tcp_child_ehash_entries:0
2025-10-03 06:37:47.282610 | controller | /proc/sys/net/ipv4/tcp_comp_sack_delay_ns:1000000
2025-10-03 06:37:47.282629 | controller | /proc/sys/net/ipv4/tcp_comp_sack_nr:44
2025-10-03 06:37:47.282653 | controller | /proc/sys/net/ipv4/tcp_comp_sack_slack_ns:100000
2025-10-03 06:37:47.282671 | controller | /proc/sys/net/ipv4/tcp_congestion_control:cubic
2025-10-03 06:37:47.282690 | controller | /proc/sys/net/ipv4/tcp_dsack:1
2025-10-03 06:37:47.282714 | controller | /proc/sys/net/ipv4/tcp_early_demux:1
2025-10-03 06:37:47.282817 | controller | /proc/sys/net/ipv4/tcp_early_retrans:3
2025-10-03 06:37:47.282855 | controller | /proc/sys/net/ipv4/tcp_ecn:2
2025-10-03 06:37:47.282979 | controller | /proc/sys/net/ipv4/tcp_ecn_fallback:1
2025-10-03 06:37:47.283014 | controller | /proc/sys/net/ipv4/tcp_ehash_entries:131072
2025-10-03 06:37:47.283050 | controller | /proc/sys/net/ipv4/tcp_fack:0
2025-10-03 06:37:47.283075 | controller | /proc/sys/net/ipv4/tcp_fastopen:3
2025-10-03 06:37:47.283098 | controller | /proc/sys/net/ipv4/tcp_fastopen_blackhole_timeout_sec:0
2025-10-03 06:37:47.283155 | controller | /proc/sys/net/ipv4/tcp_fastopen_key:00000000-00000000-00000000-00000000
2025-10-03 06:37:47.283183 | controller | /proc/sys/net/ipv4/tcp_fin_timeout:60
2025-10-03 06:37:47.283207 | controller | /proc/sys/net/ipv4/tcp_frto:2
2025-10-03 06:37:47.283238 | controller | /proc/sys/net/ipv4/tcp_fwmark_accept:0
2025-10-03 06:37:47.283307 | controller | /proc/sys/net/ipv4/tcp_invalid_ratelimit:500
2025-10-03 06:37:47.283337 | controller | /proc/sys/net/ipv4/tcp_keepalive_intvl:10
2025-10-03 06:37:47.283810 | controller | /proc/sys/net/ipv4/tcp_keepalive_probes:6
2025-10-03 06:37:47.283866 | controller | /proc/sys/net/ipv4/tcp_keepalive_time:60
2025-10-03 06:37:47.283927 | controller | /proc/sys/net/ipv4/tcp_l3mdev_accept:0
2025-10-03 06:37:47.283975 | controller | /proc/sys/net/ipv4/tcp_limit_output_bytes:1048576
2025-10-03 06:37:47.283999 | controller | /proc/sys/net/ipv4/tcp_low_latency:0
2025-10-03 06:37:47.284018 | controller | /proc/sys/net/ipv4/tcp_max_orphans:65536
2025-10-03 06:37:47.284037 | controller | /proc/sys/net/ipv4/tcp_max_reordering:300
2025-10-03 06:37:47.284056 | controller | /proc/sys/net/ipv4/tcp_max_syn_backlog:1024
2025-10-03 06:37:47.284074 | controller | /proc/sys/net/ipv4/tcp_max_tw_buckets:65536
2025-10-03 06:37:47.284094 | controller | /proc/sys/net/ipv4/tcp_mem:186534	248712	373068
2025-10-03 06:37:47.284113 | controller | /proc/sys/net/ipv4/tcp_migrate_req:0
2025-10-03 06:37:47.284132 | controller | /proc/sys/net/ipv4/tcp_min_rtt_wlen:300
2025-10-03 06:37:47.284151 | controller | /proc/sys/net/ipv4/tcp_min_snd_mss:48
2025-10-03 06:37:47.284169 | controller | /proc/sys/net/ipv4/tcp_min_tso_segs:2
2025-10-03 06:37:47.284189 | controller | /proc/sys/net/ipv4/tcp_moderate_rcvbuf:1
2025-10-03 06:37:47.284207 | controller | /proc/sys/net/ipv4/tcp_mtu_probe_floor:48
2025-10-03 06:37:47.284226 | controller | /proc/sys/net/ipv4/tcp_mtu_probing:0
2025-10-03 06:37:47.284244 | controller | /proc/sys/net/ipv4/tcp_no_metrics_save:0
2025-10-03 06:37:47.284271 | controller | /proc/sys/net/ipv4/tcp_no_ssthresh_metrics_save:1
2025-10-03 06:37:47.284314 | controller | /proc/sys/net/ipv4/tcp_notsent_lowat:4294967295
2025-10-03 06:37:47.284336 | controller | /proc/sys/net/ipv4/tcp_orphan_retries:0
2025-10-03 06:37:47.284355 | controller | /proc/sys/net/ipv4/tcp_pacing_ca_ratio:120
2025-10-03 06:37:47.284373 | controller | /proc/sys/net/ipv4/tcp_pacing_ss_ratio:200
2025-10-03 06:37:47.284393 | controller | /proc/sys/net/ipv4/tcp_pingpong_thresh:1
2025-10-03 06:37:47.284411 | controller | /proc/sys/net/ipv4/tcp_plb_cong_thresh:128
2025-10-03 06:37:47.284431 | controller | /proc/sys/net/ipv4/tcp_plb_enabled:0
2025-10-03 06:37:47.284449 | controller | /proc/sys/net/ipv4/tcp_plb_idle_rehash_rounds:3
2025-10-03 06:37:47.284469 | controller | /proc/sys/net/ipv4/tcp_plb_rehash_rounds:12
2025-10-03 06:37:47.284488 | controller | /proc/sys/net/ipv4/tcp_plb_suspend_rto_sec:60
2025-10-03 06:37:47.284506 | controller | /proc/sys/net/ipv4/tcp_probe_interval:600
2025-10-03 06:37:47.284532 | controller | /proc/sys/net/ipv4/tcp_probe_threshold:8
2025-10-03 06:37:47.284552 | controller | /proc/sys/net/ipv4/tcp_recovery:1
2025-10-03 06:37:47.284571 | controller | /proc/sys/net/ipv4/tcp_reflect_tos:0
2025-10-03 06:37:47.284590 | controller | /proc/sys/net/ipv4/tcp_reordering:3
2025-10-03 06:37:47.284609 | controller | /proc/sys/net/ipv4/tcp_retrans_collapse:1
2025-10-03 06:37:47.284628 | controller | /proc/sys/net/ipv4/tcp_retries1:3
2025-10-03 06:37:47.284647 | controller | /proc/sys/net/ipv4/tcp_retries2:15
2025-10-03 06:37:47.284672 | controller | /proc/sys/net/ipv4/tcp_rfc1337:0
2025-10-03 06:37:47.284710 | controller | /proc/sys/net/ipv4/tcp_rmem:4096	131072	6291456
2025-10-03 06:37:47.284731 | controller | /proc/sys/net/ipv4/tcp_rto_min_us:200000
2025-10-03 06:37:47.284799 | controller | /proc/sys/net/ipv4/tcp_sack:1
2025-10-03 06:37:47.284827 | controller | /proc/sys/net/ipv4/tcp_shrink_window:0
2025-10-03 06:37:47.284854 | controller | /proc/sys/net/ipv4/tcp_slow_start_after_idle:1
2025-10-03 06:37:47.284875 | controller | /proc/sys/net/ipv4/tcp_stdurg:0
2025-10-03 06:37:47.284894 | controller | /proc/sys/net/ipv4/tcp_synack_retries:5
2025-10-03 06:37:47.284918 | controller | /proc/sys/net/ipv4/tcp_syncookies:1
2025-10-03 06:37:47.284937 | controller | /proc/sys/net/ipv4/tcp_syn_linear_timeouts:4
2025-10-03 06:37:47.284960 | controller | /proc/sys/net/ipv4/tcp_syn_retries:6
2025-10-03 06:37:47.285013 | controller | /proc/sys/net/ipv4/tcp_thin_linear_timeouts:0
2025-10-03 06:37:47.285043 | controller | /proc/sys/net/ipv4/tcp_timestamps:1
2025-10-03 06:37:47.285100 | controller | /proc/sys/net/ipv4/tcp_tso_rtt_log:9
2025-10-03 06:37:47.285131 | controller | /proc/sys/net/ipv4/tcp_tso_win_divisor:3
2025-10-03 06:37:47.285167 | controller | /proc/sys/net/ipv4/tcp_tw_reuse:2
2025-10-03 06:37:47.285193 | controller | /proc/sys/net/ipv4/tcp_window_scaling:1
2025-10-03 06:37:47.285244 | controller | /proc/sys/net/ipv4/tcp_wmem:4096	16384	4194304
2025-10-03 06:37:47.285272 | controller | /proc/sys/net/ipv4/tcp_workaround_signed_windows:0
2025-10-03 06:37:47.289219 | controller | + lib/host:configure_sysctl_net_parmaters:87 :   sudo sysctl -w net.core.default_qdisc=pfifo_fast
2025-10-03 06:37:47.319407 | controller | net.core.default_qdisc = pfifo_fast
2025-10-03 06:37:47.326929 | controller | + ./stack.sh:main:624                      :   fetch_plugins
2025-10-03 06:37:47.330271 | controller | + functions-common:fetch_plugins:1769      :   local plugins=,neutron
2025-10-03 06:37:47.333904 | controller | + functions-common:fetch_plugins:1770      :   local plugin
2025-10-03 06:37:47.337555 | controller | + functions-common:fetch_plugins:1773      :   [[ -z ,neutron ]]
2025-10-03 06:37:47.341637 | controller | + functions-common:fetch_plugins:1777      :   echo 'Fetching DevStack plugins'
2025-10-03 06:37:47.345707 | controller | Fetching DevStack plugins
2025-10-03 06:37:47.345797 | controller | + functions-common:fetch_plugins:1778      :   for plugin in ${plugins//,/ }
2025-10-03 06:37:47.349191 | controller | + functions-common:fetch_plugins:1779      :   git_clone_by_name neutron
2025-10-03 06:37:47.353176 | controller | + functions-common:git_clone_by_name:684   :   local name=neutron
2025-10-03 06:37:47.357025 | controller | + functions-common:git_clone_by_name:685   :   local repo=https://opendev.org/openstack/neutron
2025-10-03 06:37:47.361175 | controller | + functions-common:git_clone_by_name:686   :   local dir=/opt/stack/neutron
2025-10-03 06:37:47.364934 | controller | + functions-common:git_clone_by_name:687   :   local branch=master
2025-10-03 06:37:47.368796 | controller | + functions-common:git_clone_by_name:688   :   git_clone https://opendev.org/openstack/neutron /opt/stack/neutron master
2025-10-03 06:37:47.372230 | controller | + functions-common:git_clone:592           :   local git_remote=https://opendev.org/openstack/neutron
2025-10-03 06:37:47.375820 | controller | + functions-common:git_clone:593           :   local git_dest=/opt/stack/neutron
2025-10-03 06:37:47.378659 | controller | + functions-common:git_clone:594           :   local git_ref=master
2025-10-03 06:37:47.381439 | controller | + functions-common:git_clone:595           :   local orig_dir
2025-10-03 06:37:47.386332 | controller | ++ functions-common:git_clone:596           :   pwd
2025-10-03 06:37:47.390263 | controller | + functions-common:git_clone:596           :   orig_dir=/opt/stack/devstack
2025-10-03 06:37:47.393439 | controller | + functions-common:git_clone:597           :   local git_clone_flags=
2025-10-03 06:37:47.397857 | controller | ++ functions-common:git_clone:599           :   trueorfalse False RECLONE
2025-10-03 06:37:47.422464 | controller | + functions-common:git_clone:599           :   RECLONE=False
2025-10-03 06:37:47.425895 | controller | + functions-common:git_clone:600           :   [[ 0 -gt 0 ]]
2025-10-03 06:37:47.429507 | controller | + functions-common:git_clone:604           :   [[ False = \T\r\u\e ]]
2025-10-03 06:37:47.433960 | controller | + functions-common:git_clone:613           :   echo master
2025-10-03 06:37:47.434270 | controller | + functions-common:git_clone:613           :   egrep -q '^refs'
2025-10-03 06:37:47.437492 | controller | egrep: warning: egrep is obsolescent; using grep -E
2025-10-03 06:37:47.442204 | controller | + functions-common:git_clone:627           :   [[ ! -d /opt/stack/neutron ]]
2025-10-03 06:37:47.445619 | controller | + functions-common:git_clone:637           :   [[ False = \T\r\u\e ]]
2025-10-03 06:37:47.449783 | controller | + functions-common:git_clone:672           :   sudo git config --system --add safe.directory /opt/stack/neutron
2025-10-03 06:37:47.482434 | controller | + functions-common:git_clone:675           :   cd /opt/stack/neutron
2025-10-03 06:37:47.486198 | controller | + functions-common:git_clone:676           :   git show --oneline
2025-10-03 06:37:47.487552 | controller | + functions-common:git_clone:676           :   head -1
2025-10-03 06:37:47.505268 | controller | 9c5736b68c Merge "[OVN] Remove the check for external ports support"
2025-10-03 06:37:47.510127 | controller | + functions-common:git_clone:677           :   cd /opt/stack/devstack
2025-10-03 06:37:47.515318 | controller | + ./stack.sh:main:628                      :   run_phase override_defaults
2025-10-03 06:37:47.519922 | controller | + functions-common:run_phase:1851          :   local mode=override_defaults
2025-10-03 06:37:47.524076 | controller | + functions-common:run_phase:1852          :   local phase=
2025-10-03 06:37:47.528006 | controller | + functions-common:run_phase:1853          :   [[ -d /opt/stack/devstack/extras.d ]]
2025-10-03 06:37:47.532201 | controller | + functions-common:run_phase:1854          :   local extra_plugin_file_name
2025-10-03 06:37:47.536384 | controller | + functions-common:run_phase:1855          :   for extra_plugin_file_name in $TOP_DIR/extras.d/*.sh
2025-10-03 06:37:47.540691 | controller | + functions-common:run_phase:1860          :   local exceptions=80-tempest.sh
2025-10-03 06:37:47.544725 | controller | + functions-common:run_phase:1861          :   local extra
2025-10-03 06:37:47.549822 | controller | ++ functions-common:run_phase:1862          :   basename /opt/stack/devstack/extras.d/80-tempest.sh
2025-10-03 06:37:47.556669 | controller | + functions-common:run_phase:1862          :   extra=80-tempest.sh
2025-10-03 06:37:47.560928 | controller | + functions-common:run_phase:1863          :   [[ 80-tempest.sh =~ 80-tempest\.sh ]]
2025-10-03 06:37:47.565036 | controller | + functions-common:run_phase:1867          :   [[ -r /opt/stack/devstack/extras.d/80-tempest.sh ]]
2025-10-03 06:37:47.569281 | controller | + functions-common:run_phase:1867          :   source /opt/stack/devstack/extras.d/80-tempest.sh override_defaults
2025-10-03 06:37:47.573596 | controller | ++ extras.d/80-tempest.sh:source:3          :   is_service_enabled tempest
2025-10-03 06:37:47.600062 | controller | ++ functions-common:is_service_enabled:2079 :   return 0
2025-10-03 06:37:47.604002 | controller | ++ extras.d/80-tempest.sh:source:4          :   [[ override_defaults == \s\o\u\r\c\e ]]
2025-10-03 06:37:47.607912 | controller | ++ extras.d/80-tempest.sh:source:7          :   [[ override_defaults == \s\t\a\c\k ]]
2025-10-03 06:37:47.612094 | controller | ++ extras.d/80-tempest.sh:source:10         :   [[ override_defaults == \s\t\a\c\k ]]
2025-10-03 06:37:47.616155 | controller | ++ extras.d/80-tempest.sh:source:13         :   [[ override_defaults == \s\t\a\c\k ]]
2025-10-03 06:37:47.620048 | controller | ++ extras.d/80-tempest.sh:source:16         :   [[ override_defaults == \s\t\a\c\k ]]
2025-10-03 06:37:47.623945 | controller | ++ extras.d/80-tempest.sh:source:19         :   [[ override_defaults == \s\t\a\c\k ]]
2025-10-03 06:37:47.628329 | controller | ++ extras.d/80-tempest.sh:source:27         :   [[ override_defaults == \u\n\s\t\a\c\k ]]
2025-10-03 06:37:47.632363 | controller | ++ extras.d/80-tempest.sh:source:32         :   [[ override_defaults == \c\l\e\a\n ]]
2025-10-03 06:37:47.635983 | controller | + functions-common:run_phase:1872          :   [[ override_defaults == \s\o\u\r\c\e ]]
2025-10-03 06:37:47.640263 | controller | + functions-common:run_phase:1875          :   [[ override_defaults == \o\v\e\r\r\i\d\e\_\d\e\f\a\u\l\t\s ]]
2025-10-03 06:37:47.644216 | controller | + functions-common:run_phase:1876          :   plugin_override_defaults
2025-10-03 06:37:47.648475 | controller | + functions-common:plugin_override_defaults:1810 :   local plugins=,neutron
2025-10-03 06:37:47.651876 | controller | + functions-common:plugin_override_defaults:1811 :   local plugin
2025-10-03 06:37:47.655907 | controller | + functions-common:plugin_override_defaults:1814 :   [[ -z ,neutron ]]
2025-10-03 06:37:47.660020 | controller | + functions-common:plugin_override_defaults:1818 :   echo 'Overriding Configuration Defaults'
2025-10-03 06:37:47.663680 | controller | Overriding Configuration Defaults
2025-10-03 06:37:47.663727 | controller | + functions-common:plugin_override_defaults:1819 :   for plugin in ${plugins//,/ }
2025-10-03 06:37:47.667920 | controller | + functions-common:plugin_override_defaults:1820 :   local dir=/opt/stack/neutron
2025-10-03 06:37:47.671270 | controller | + functions-common:plugin_override_defaults:1822 :   [[ -f /opt/stack/neutron/devstack/override-defaults ]]
2025-10-03 06:37:47.675601 | controller | + ./stack.sh:main:631                      :   source /opt/stack/devstack/lib/apache
2025-10-03 06:37:47.710636 | controller | + ./stack.sh:main:634                      :   source /opt/stack/devstack/lib/tls
2025-10-03 06:37:47.714377 | controller | ++ lib/tls:source:38                        :   is_service_enabled tls-proxy
2025-10-03 06:37:47.739709 | controller | ++ functions-common:is_service_enabled:2079 :   return 0
2025-10-03 06:37:47.744724 | controller | +++ lib/tls:source:40                        :   ipv6_unquote 38.102.83.227
2025-10-03 06:37:47.749822 | controller | +++ functions-common:ipv6_unquote:2221       :   echo 38.102.83.227
2025-10-03 06:37:47.750395 | controller | +++ functions-common:ipv6_unquote:2221       :   tr -d '[]'
2025-10-03 06:37:47.757469 | controller | ++ lib/tls:source:40                        :   TLS_IP=38.102.83.227
2025-10-03 06:37:47.762664 | controller | +++ lib/tls:source:43                        :   hostname -f
2025-10-03 06:37:47.774128 | controller | ++ lib/tls:source:43                        :   DEVSTACK_HOSTNAME=np0005468665.novalocal
2025-10-03 06:37:47.778164 | controller | ++ lib/tls:source:44                        :   DEVSTACK_CERT_NAME=devstack-cert
2025-10-03 06:37:47.782008 | controller | ++ lib/tls:source:45                        :   DEVSTACK_CERT=/opt/stack/data/devstack-cert.pem
2025-10-03 06:37:47.785935 | controller | ++ lib/tls:source:48                        :   ROOT_CA_DIR=/opt/stack/data/CA/root-ca
2025-10-03 06:37:47.790816 | controller | ++ lib/tls:source:49                        :   INT_CA_DIR=/opt/stack/data/CA/int-ca
2025-10-03 06:37:47.794403 | controller | ++ lib/tls:source:51                        :   ORG_NAME=OpenStack
2025-10-03 06:37:47.799109 | controller | ++ lib/tls:source:52                        :   ORG_UNIT_NAME=DevStack
2025-10-03 06:37:47.802856 | controller | ++ lib/tls:source:55                        :   STUD_PROTO=--tls
2025-10-03 06:37:47.806805 | controller | ++ lib/tls:source:56                        :   STUD_CIPHERS='TLSv1+HIGH:!DES:!aNULL:!eNULL:@STRENGTH'
2025-10-03 06:37:47.810970 | controller | ++ lib/tls:source:63                        :   OPENSSL=/usr/bin/openssl
2025-10-03 06:37:47.818802 | controller | + ./stack.sh:main:637                      :   source /opt/stack/devstack/lib/infra
2025-10-03 06:37:47.840476 | controller | + ./stack.sh:main:638                      :   source /opt/stack/devstack/lib/libraries
2025-10-03 06:37:47.873615 | controller | + ./stack.sh:main:639                      :   source /opt/stack/devstack/lib/lvm
2025-10-03 06:37:47.898930 | controller | + ./stack.sh:main:640                      :   source /opt/stack/devstack/lib/horizon
2025-10-03 06:37:47.923963 | controller | + ./stack.sh:main:641                      :   source /opt/stack/devstack/lib/keystone
2025-10-03 06:37:47.984817 | controller | /opt/stack/devstack/lib/keystone: line 430: syntax error near unexpected token `<<<'
2025-10-03 06:37:47.986730 | controller | Error on exit
2025-10-03 06:37:48.852482 | controller | *** FINISHED ***
2025-10-03 10:37:49.319156 | controller | ERROR
2025-10-03 10:37:49.319493 | controller | {
2025-10-03 10:37:49.319564 | controller |   "delta": "0:00:15.969919",
2025-10-03 10:37:49.319611 | controller |   "end": "2025-10-03 06:37:48.864310",
2025-10-03 10:37:49.319655 | controller |   "msg": "non-zero return code",
2025-10-03 10:37:49.319750 | controller |   "rc": 2,
2025-10-03 10:37:49.319791 | controller |   "start": "2025-10-03 06:37:32.894391"
2025-10-03 10:37:49.319851 | controller | }
failure
2025-10-03 10:37:49.344556 | 
2025-10-03 10:37:49.344708 | PLAY RECAP
2025-10-03 10:37:49.344851 | controller | ok: 0 changed: 0 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0
2025-10-03 10:37:49.344913 | 
2025-10-03 10:37:49.462193 | RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/tempest/playbooks/devstack-tempest.yaml@master]
2025-10-03 10:37:49.470799 | POST-RUN START: [untrusted : opendev.org/openstack/tempest/playbooks/post-tempest.yaml@master]
2025-10-03 10:37:50.163437 | 
2025-10-03 10:37:50.163560 | PLAY [tempest]
2025-10-03 10:37:50.187459 | 
2025-10-03 10:37:50.187605 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-03 10:37:50.933448 | controller | changed: non-zero return code
2025-10-03 10:37:50.946516 | 
2025-10-03 10:37:50.946772 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-03 10:37:50.974867 | controller | skipping: Conditional result was False
2025-10-03 10:37:50.988600 | 
2025-10-03 10:37:50.988863 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-03 10:37:51.030482 | 
2025-10-03 10:37:51.030796 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-03 10:37:51.070548 | 
2025-10-03 10:37:51.070833 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-03 10:37:51.098160 | controller | skipping: Conditional result was False
2025-10-03 10:37:51.112333 | 
2025-10-03 10:37:51.112520 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-03 10:37:51.158329 | 
2025-10-03 10:37:51.158641 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-03 10:37:51.185926 | controller | skipping: Conditional result was False
2025-10-03 10:37:51.194005 | 
2025-10-03 10:37:51.194142 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-03 10:37:51.219221 | controller | skipping: Conditional result was False
2025-10-03 10:37:51.233626 | 
2025-10-03 10:37:51.233869 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-03 10:37:51.261269 | controller | skipping: Conditional result was False
2025-10-03 10:37:51.279299 | 
2025-10-03 10:37:51.279469 | TASK [process-stackviz : Devstack checks if stackviz archive exists]
2025-10-03 10:37:51.695877 | controller | ok
2025-10-03 10:37:51.707519 | 
2025-10-03 10:37:51.707675 | TASK [process-stackviz : debug]
2025-10-03 10:37:51.757915 | Stackviz archive could not be found in /opt/cache/files/stackviz-latest.tar.gz
2025-10-03 10:37:51.768780 | 
2025-10-03 10:37:51.768920 | TASK [process-stackviz : Check if subunit data exists]
2025-10-03 10:37:52.074199 | controller | ok
2025-10-03 10:37:52.081419 | 
2025-10-03 10:37:52.081518 | TASK [process-stackviz : debug]
2025-10-03 10:37:52.114423 | Subunit file could not be found at /opt/stack/tempest/testrepository.subunit
2025-10-03 10:37:52.121939 | 
2025-10-03 10:37:52.122033 | TASK [include_role : ensure-pip]
2025-10-03 10:37:52.138949 | controller | skipping: Conditional result was False
2025-10-03 10:37:52.149865 | 
2025-10-03 10:37:52.149977 | TASK [process-stackviz : pip]
2025-10-03 10:37:52.178223 | controller | skipping: Conditional result was False
2025-10-03 10:37:52.187219 | 
2025-10-03 10:37:52.187307 | TASK [process-stackviz : Deploy stackviz static html+js]
2025-10-03 10:37:52.721533 | controller | skipping: Conditional result was False
2025-10-03 10:37:52.736096 | 
2025-10-03 10:37:52.736246 | TASK [process-stackviz : Check if dstat data exists]
2025-10-03 10:37:52.764059 | controller | skipping: Conditional result was False
2025-10-03 10:37:52.780920 | 
2025-10-03 10:37:52.781129 | TASK [process-stackviz : Run stackviz with dstat]
2025-10-03 10:37:53.328610 | controller | skipping: Conditional result was False
2025-10-03 10:37:53.342179 | 
2025-10-03 10:37:53.342350 | TASK [process-stackviz : Run stackviz without dstat]
2025-10-03 10:37:53.916317 | controller | skipping: Conditional result was False
2025-10-03 10:37:53.955643 | 
2025-10-03 10:37:53.955797 | PLAY RECAP
2025-10-03 10:37:53.955862 | controller | ok: 5 changed: 1 unreachable: 0 failed: 0 skipped: 14 rescued: 0 ignored: 0
2025-10-03 10:37:53.955894 | 
2025-10-03 10:37:54.077551 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/tempest/playbooks/post-tempest.yaml@master]
2025-10-03 10:37:54.081711 | POST-RUN START: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2025-10-03 10:37:54.758053 | 
2025-10-03 10:37:54.758190 | PLAY [all]
2025-10-03 10:37:54.786369 | 
2025-10-03 10:37:54.786512 | TASK [export-devstack-journal : Ensure /home/zuul-worker/logs exists]
2025-10-03 10:37:55.452997 | controller | changed
2025-10-03 10:37:55.461038 | 
2025-10-03 10:37:55.461165 | TASK [export-devstack-journal : Export legacy stack screen log files]
2025-10-03 10:37:57.506038 | controller | ok: Runtime: 0:00:01.167895
2025-10-03 10:37:57.515067 | 
2025-10-03 10:37:57.515222 | TASK [export-devstack-journal : Export legacy syslog.txt]
2025-10-03 10:37:58.058892 | controller | ok: Runtime: 0:00:00.021364
2025-10-03 10:37:58.073289 | 
2025-10-03 10:37:58.073571 | TASK [export-devstack-journal : Export journal]
2025-10-03 10:37:58.630899 | controller | ok: Runtime: 0:00:00.024541
2025-10-03 10:37:58.637753 | 
2025-10-03 10:37:58.637858 | TASK [export-devstack-journal : Save journal README]
2025-10-03 10:37:59.844781 | controller | changed
2025-10-03 10:37:59.871814 | 
2025-10-03 10:37:59.872025 | TASK [apache-logs-conf : Ensure /home/zuul-worker/apache exists]
2025-10-03 10:38:00.167911 | controller | changed
2025-10-03 10:38:00.224269 | 
2025-10-03 10:38:00.224436 | TASK [apache-logs-conf : Find logs]
2025-10-03 10:38:00.263107 | 
2025-10-03 10:38:00.263361 | LOOP [apache-logs-conf : Dereference files]
2025-10-03 10:38:00.298968 | 
2025-10-03 10:38:00.299189 | LOOP [apache-logs-conf : Create hard links]
2025-10-03 10:38:00.333732 | 
2025-10-03 10:38:00.333944 | TASK [apache-logs-conf : Find logs]
2025-10-03 10:38:00.698241 | controller | Output suppressed because no_log was given
2025-10-03 10:38:00.709954 | 
2025-10-03 10:38:00.710084 | LOOP [apache-logs-conf : Dereference files]
2025-10-03 10:38:00.753856 | 
2025-10-03 10:38:00.754123 | LOOP [apache-logs-conf : Create hard links]
2025-10-03 10:38:00.798286 | 
2025-10-03 10:38:00.798608 | TASK [apache-logs-conf : Ensure /home/zuul-worker/apache_config apache_config exists]
2025-10-03 10:38:01.118405 | controller | changed
2025-10-03 10:38:01.132870 | 
2025-10-03 10:38:01.133049 | TASK [apache-logs-conf : Define config paths]
2025-10-03 10:38:01.172884 | controller | ok
2025-10-03 10:38:01.185391 | 
2025-10-03 10:38:01.185562 | TASK [apache-logs-conf : Discover configurations]
2025-10-03 10:38:01.478957 | controller | Output suppressed because no_log was given
2025-10-03 10:38:01.486888 | 
2025-10-03 10:38:01.487022 | LOOP [apache-logs-conf : Dereference configurations]
2025-10-03 10:38:01.520230 | 
2025-10-03 10:38:01.520415 | LOOP [apache-logs-conf : Link configurations]
2025-10-03 10:38:01.555826 | 
2025-10-03 10:38:01.555999 | TASK [capture-performance-data : Generate statistics]
2025-10-03 06:38:03.258150 | controller | /opt/stack/devstack//inc/python: line 43: -m: command not found
2025-10-03 06:38:03.269775 | controller | Using python 3.12 to install setuptools
2025-10-03 06:38:04.283655 | controller | Looking in indexes: http://mirror.regionone.vexxhost-nodepool-sf.rdoproject.org/pypi/simple, http://mirror.regionone.vexxhost-nodepool-sf.rdoproject.org/wheel/centos-10-x86_64
2025-10-03 06:38:04.293170 | controller | Requirement already satisfied: pip in /usr/lib/python3.12/site-packages (23.3.2)
2025-10-03 06:38:04.371608 | controller | Collecting pip
2025-10-03 06:38:04.374460 | controller |   Downloading http://mirror.regionone.vexxhost-nodepool-sf.rdoproject.org/pypifiles/packages/b7/3f/945ef7ab14dc4f9d7f40288d2df998d1837ee0888ec3659c813487572faa/pip-25.2-py3-none-any.whl.metadata (4.7 kB)
2025-10-03 06:38:04.382600 | controller | Requirement already satisfied: setuptools[core] in /usr/lib/python3.12/site-packages (69.0.3)
2025-10-03 06:38:04.605317 | controller | Collecting setuptools[core]
2025-10-03 06:38:04.608400 | controller |   Downloading http://mirror.regionone.vexxhost-nodepool-sf.rdoproject.org/pypifiles/packages/a3/dc/17031897dae0efacfea57dfd3a82fdd2a2aeb58e0ff71b77b87e44edc772/setuptools-80.9.0-py3-none-any.whl.metadata (6.6 kB)
2025-10-03 06:38:04.688295 | controller | Collecting packaging>=24.2 (from setuptools[core])
2025-10-03 06:38:04.690843 | controller |   Downloading http://mirror.regionone.vexxhost-nodepool-sf.rdoproject.org/pypifiles/packages/20/12/38679034af332785aac8774540895e234f4d07f7545804097de4b666afd8/packaging-25.0-py3-none-any.whl.metadata (3.3 kB)
2025-10-03 06:38:04.739790 | controller | Collecting more_itertools>=8.8 (from setuptools[core])
2025-10-03 06:38:04.743224 | controller |   Downloading http://mirror.regionone.vexxhost-nodepool-sf.rdoproject.org/pypifiles/packages/2b/9f/7ba6f94fc1e9ac3d2b853fdff3035fb2fa5afbed898c4a72b8a020610594/more_itertools-10.7.0-py3-none-any.whl.metadata (37 kB)
2025-10-03 06:38:04.792106 | controller | Collecting jaraco.text>=3.7 (from setuptools[core])
2025-10-03 06:38:04.795310 | controller |   Downloading http://mirror.regionone.vexxhost-nodepool-sf.rdoproject.org/pypifiles/packages/2f/29/350039bde32fbd7000e2fb81e1c4e42a857b5e77bcbaf6267c806c70ab9a/jaraco.text-4.0.0-py3-none-any.whl.metadata (3.7 kB)
2025-10-03 06:38:04.856627 | controller | Collecting wheel>=0.43.0 (from setuptools[core])
2025-10-03 06:38:04.859343 | controller |   Downloading http://mirror.regionone.vexxhost-nodepool-sf.rdoproject.org/pypifiles/packages/0b/2c/87f3254fd8ffd29e4c02732eee68a83a1d3c346ae39bc6822dcbcb697f2b/wheel-0.45.1-py3-none-any.whl.metadata (2.3 kB)
2025-10-03 06:38:04.897879 | controller | Collecting platformdirs>=4.2.2 (from setuptools[core])
2025-10-03 06:38:04.900072 | controller |   Downloading http://mirror.regionone.vexxhost-nodepool-sf.rdoproject.org/pypifiles/packages/fe/39/979e8e21520d4e47a0bbe349e2713c0aac6f3d853d0e5b34d76206c439aa/platformdirs-4.3.8-py3-none-any.whl.metadata (12 kB)
2025-10-03 06:38:04.933951 | controller | Collecting jaraco.functools>=4 (from setuptools[core])
2025-10-03 06:38:04.936535 | controller |   Downloading http://mirror.regionone.vexxhost-nodepool-sf.rdoproject.org/pypifiles/packages/f3/fd/179a20f832824514df39a90bb0e5372b314fea99f217f5ab942b10a8a4e8/jaraco_functools-4.2.1-py3-none-any.whl.metadata (2.9 kB)
2025-10-03 06:38:04.982829 | controller | Collecting jaraco.context>=4.1 (from jaraco.text>=3.7->setuptools[core])
2025-10-03 06:38:04.984945 | controller |   Downloading http://mirror.regionone.vexxhost-nodepool-sf.rdoproject.org/pypifiles/packages/ff/db/0c52c4cf5e4bd9f5d7135ec7669a3a767af21b3a308e1ed3674881e52b62/jaraco.context-6.0.1-py3-none-any.whl.metadata (4.1 kB)
2025-10-03 06:38:05.007403 | controller | Collecting autocommand (from jaraco.text>=3.7->setuptools[core])
2025-10-03 06:38:05.009490 | controller |   Downloading http://mirror.regionone.vexxhost-nodepool-sf.rdoproject.org/pypifiles/packages/b5/62/05203c39d21aa3171454a6c5391ea3b582a97bfb1bc1adad25628331a1cd/autocommand-2.2.2-py3-none-any.whl.metadata (15 kB)
2025-10-03 06:38:05.109311 | controller | Downloading http://mirror.regionone.vexxhost-nodepool-sf.rdoproject.org/pypifiles/packages/b7/3f/945ef7ab14dc4f9d7f40288d2df998d1837ee0888ec3659c813487572faa/pip-25.2-py3-none-any.whl (1.8 MB)
2025-10-03 06:38:05.129788 | controller |    ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 101.8 MB/s eta 0:00:00
2025-10-03 06:38:05.132200 | controller | Downloading http://mirror.regionone.vexxhost-nodepool-sf.rdoproject.org/pypifiles/packages/f3/fd/179a20f832824514df39a90bb0e5372b314fea99f217f5ab942b10a8a4e8/jaraco_functools-4.2.1-py3-none-any.whl (10 kB)
2025-10-03 06:38:05.142304 | controller | Downloading http://mirror.regionone.vexxhost-nodepool-sf.rdoproject.org/pypifiles/packages/2f/29/350039bde32fbd7000e2fb81e1c4e42a857b5e77bcbaf6267c806c70ab9a/jaraco.text-4.0.0-py3-none-any.whl (11 kB)
2025-10-03 06:38:05.149560 | controller | Downloading http://mirror.regionone.vexxhost-nodepool-sf.rdoproject.org/pypifiles/packages/2b/9f/7ba6f94fc1e9ac3d2b853fdff3035fb2fa5afbed898c4a72b8a020610594/more_itertools-10.7.0-py3-none-any.whl (65 kB)
2025-10-03 06:38:05.157517 | controller |    ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 65.3/65.3 kB 9.5 MB/s eta 0:00:00
2025-10-03 06:38:05.160098 | controller | Downloading http://mirror.regionone.vexxhost-nodepool-sf.rdoproject.org/pypifiles/packages/20/12/38679034af332785aac8774540895e234f4d07f7545804097de4b666afd8/packaging-25.0-py3-none-any.whl (66 kB)
2025-10-03 06:38:05.168958 | controller |    ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 8.4 MB/s eta 0:00:00
2025-10-03 06:38:05.171225 | controller | Downloading http://mirror.regionone.vexxhost-nodepool-sf.rdoproject.org/pypifiles/packages/fe/39/979e8e21520d4e47a0bbe349e2713c0aac6f3d853d0e5b34d76206c439aa/platformdirs-4.3.8-py3-none-any.whl (18 kB)
2025-10-03 06:38:05.179268 | controller | Downloading http://mirror.regionone.vexxhost-nodepool-sf.rdoproject.org/pypifiles/packages/0b/2c/87f3254fd8ffd29e4c02732eee68a83a1d3c346ae39bc6822dcbcb697f2b/wheel-0.45.1-py3-none-any.whl (72 kB)
2025-10-03 06:38:05.187402 | controller |    ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 72.5/72.5 kB 10.2 MB/s eta 0:00:00
2025-10-03 06:38:05.189604 | controller | Downloading http://mirror.regionone.vexxhost-nodepool-sf.rdoproject.org/pypifiles/packages/a3/dc/17031897dae0efacfea57dfd3a82fdd2a2aeb58e0ff71b77b87e44edc772/setuptools-80.9.0-py3-none-any.whl (1.2 MB)
2025-10-03 06:38:05.204682 | controller |    ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 93.7 MB/s eta 0:00:00
2025-10-03 06:38:05.206802 | controller | Downloading http://mirror.regionone.vexxhost-nodepool-sf.rdoproject.org/pypifiles/packages/ff/db/0c52c4cf5e4bd9f5d7135ec7669a3a767af21b3a308e1ed3674881e52b62/jaraco.context-6.0.1-py3-none-any.whl (6.8 kB)
2025-10-03 06:38:05.215087 | controller | Downloading http://mirror.regionone.vexxhost-nodepool-sf.rdoproject.org/pypifiles/packages/b5/62/05203c39d21aa3171454a6c5391ea3b582a97bfb1bc1adad25628331a1cd/autocommand-2.2.2-py3-none-any.whl (19 kB)
2025-10-03 06:38:05.425435 | controller | Installing collected packages: wheel, setuptools, platformdirs, pip, packaging, more_itertools, jaraco.context, autocommand, jaraco.functools, jaraco.text
2025-10-03 06:38:05.467407 | controller |   WARNING: The script wheel is installed in '/usr/local/bin' which is not on PATH.
2025-10-03 06:38:06.886247 | controller |   Consider adding this directory to PATH or, if you prefer to suppress this warning, use --no-warn-script-location.
2025-10-03 06:38:06.886354 | controller |   WARNING: The scripts pip, pip3 and pip3.12 are installed in '/usr/local/bin' which is not on PATH.
2025-10-03 06:38:07.097592 | controller |   Consider adding this directory to PATH or, if you prefer to suppress this warning, use --no-warn-script-location.
2025-10-03 06:38:07.097704 | controller | Successfully installed autocommand-2.2.2 jaraco.context-6.0.1 jaraco.functools-4.2.1 jaraco.text-4.0.0 more_itertools-10.7.0 packaging-25.0 pip-25.2 platformdirs-4.3.8 setuptools-80.9.0 wheel-0.45.1
2025-10-03 06:38:07.299860 | controller | WARNING: Running pip as the 'root' user can result in broken permissions and conflicting behaviour with the system package manager. It is recommended to use a virtual environment instead: https://pip.pypa.io/warnings/venv
2025-10-03 06:38:07.299989 | controller | /bin/bash: line 4: /opt/stack/data/venv/bin/python3: No such file or directory
2025-10-03 10:38:07.592085 | controller | ERROR
2025-10-03 10:38:07.592338 | controller | {
2025-10-03 10:38:07.592389 | controller |   "delta": "0:00:05.421395",
2025-10-03 10:38:07.592423 | controller |   "end": "2025-10-03 06:38:07.301577",
2025-10-03 10:38:07.592446 | controller |   "msg": "non-zero return code",
2025-10-03 10:38:07.592473 | controller |   "rc": 127,
2025-10-03 10:38:07.592504 | controller |   "start": "2025-10-03 06:38:01.880182"
2025-10-03 10:38:07.592538 | controller | }
2025-10-03 10:38:07.592581 | controller | ERROR: Ignoring Errors
2025-10-03 10:38:07.606731 | 
2025-10-03 10:38:07.606828 | TASK [devstack-project-conf : Ensure /home/zuul-worker/etc exists]
2025-10-03 10:38:07.971372 | controller | changed
2025-10-03 10:38:07.984058 | 
2025-10-03 10:38:07.984415 | LOOP [devstack-project-conf : Check which projects have a config folder]
2025-10-03 10:38:11.807963 | controller | Output suppressed because no_log was given
2025-10-03 10:38:11.827194 | 
2025-10-03 10:38:11.827364 | LOOP [devstack-project-conf : Copy configuration files]
2025-10-03 10:38:11.876865 | controller | skipping: Conditional result was False
2025-10-03 10:38:11.877181 | 
2025-10-03 10:38:11.881549 | controller | skipping: Conditional result was False
2025-10-03 10:38:11.887199 | controller | skipping: Conditional result was False
2025-10-03 10:38:11.893266 | controller | skipping: Conditional result was False
2025-10-03 10:38:11.893980 | controller | skipping: Conditional result was False
2025-10-03 10:38:11.905302 | controller | skipping: Conditional result was False
2025-10-03 10:38:11.905987 | controller | skipping: Conditional result was False
2025-10-03 10:38:11.914276 | controller | skipping: Conditional result was False
2025-10-03 10:38:11.915038 | controller | skipping: Conditional result was False
2025-10-03 10:38:11.920756 | controller | skipping: Conditional result was False
2025-10-03 10:38:11.921361 | controller | skipping: Conditional result was False
2025-10-03 10:38:11.926294 | controller | skipping: Conditional result was False
2025-10-03 10:38:11.926901 | controller | skipping: Conditional result was False
2025-10-03 10:38:11.958887 | 
2025-10-03 10:38:11.959104 | TASK [devstack-project-conf : Check if openstack has a config folder]
2025-10-03 10:38:12.278017 | controller | ok
2025-10-03 10:38:12.284357 | 
2025-10-03 10:38:12.284482 | TASK [devstack-project-conf : Copy configuration files]
2025-10-03 10:38:12.832289 | controller | skipping: Conditional result was False
2025-10-03 10:38:12.843477 | 
2025-10-03 10:38:12.843596 | TASK [capture-system-logs : Stage various logs and reports]
2025-10-03 06:38:13.302156 | controller | which: no python2 in (/sbin:/bin:/usr/sbin:/usr/bin)
2025-10-03 06:38:15.643251 | controller | grep: /home/zuul-worker/apache/*.log: No such file or directory
2025-10-03 10:38:15.915473 | controller | ok: Runtime: 0:00:02.394503
2025-10-03 10:38:15.939745 | 
2025-10-03 10:38:15.939926 | LOOP [stage-output : Register sources]
2025-10-03 10:38:31.926722 | controller | Output suppressed because no_log was given
2025-10-03 10:38:31.943570 | 
2025-10-03 10:38:31.943871 | TASK [stage-output : Check sudo]
2025-10-03 10:38:32.491186 | controller | ok: Runtime: 0:00:00.036466
2025-10-03 10:38:32.498002 | 
2025-10-03 10:38:32.498102 | LOOP [stage-output : Set source and destination for files and folders]
2025-10-03 10:38:32.612118 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.612447 | 
2025-10-03 10:38:32.613702 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.623071 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.679928 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.680422 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.681308 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.681828 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.682331 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.688514 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.688991 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.689440 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.696011 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.701328 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.701781 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.702232 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.719428 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.730632 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.731275 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.731725 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.757048 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.757612 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.788108 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.835724 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.855469 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.890746 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.918305 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.918980 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.920355 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.920890 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.936949 | controller | Output suppressed because no_log was given
2025-10-03 10:38:32.950033 | 
2025-10-03 10:38:32.950172 | TASK [stage-output : Build a list of source, dest dictionaries]
2025-10-03 10:38:33.092518 | controller | ok
2025-10-03 10:38:33.103443 | 
2025-10-03 10:38:33.103580 | LOOP [stage-output : Ensure target folders exist]
2025-10-03 10:38:33.474878 | controller | changed: "docs"
2025-10-03 10:38:33.736835 | controller | changed: "artifacts"
2025-10-03 10:38:34.026550 | controller | ok: "logs"
2025-10-03 10:38:34.048468 | 
2025-10-03 10:38:34.048692 | LOOP [stage-output : Copy files and folders to staging folder]
2025-10-03 10:38:34.442002 | controller | ok: Item: Runtime: 0:00:00.015814
2025-10-03 10:38:34.442250 | controller | changed: All items complete
2025-10-03 10:38:34.442281 | 
2025-10-03 10:38:34.749642 | controller | ok: Item: Runtime: 0:00:00.007964
2025-10-03 10:38:35.099375 | controller | ok: Item: Runtime: 0:00:00.008313
2025-10-03 10:38:35.447071 | controller | ok: Item: Runtime: 0:00:00.008710
2025-10-03 10:38:35.794471 | controller | ok: Item: Runtime: 0:00:00.011601
2025-10-03 10:38:36.122967 | controller | ok: Item: Runtime: 0:00:00.006840
2025-10-03 10:38:36.466191 | controller | ok: Item: Runtime: 0:00:00.006959
2025-10-03 10:38:36.764002 | controller | ok: Item: Runtime: 0:00:00.007557
2025-10-03 10:38:37.082256 | controller | ok: Item: Runtime: 0:00:00.008024
2025-10-03 10:38:37.401764 | controller | ok: Item: Runtime: 0:00:00.005103
2025-10-03 10:38:37.747624 | controller | ok: Item: Runtime: 0:00:00.007824
2025-10-03 10:38:38.062758 | controller | ok: Item: Runtime: 0:00:00.007878
2025-10-03 10:38:38.348157 | controller | ok: Item: Runtime: 0:00:00.006270
2025-10-03 10:38:38.685043 | controller | ok: Item: Runtime: 0:00:00.009202
2025-10-03 10:38:39.019240 | controller | ok: Item: Runtime: 0:00:00.006352
2025-10-03 10:38:39.347641 | controller | ok: Item: Runtime: 0:00:00.004267
2025-10-03 10:38:39.638393 | controller | ok: Item: Runtime: 0:00:00.004610
2025-10-03 10:38:39.929541 | controller | ok: Item: Runtime: 0:00:00.011795
2025-10-03 10:38:40.242398 | controller | ok: Item: Runtime: 0:00:00.007750
2025-10-03 10:38:40.543211 | controller | ok: Item: Runtime: 0:00:00.005223
2025-10-03 10:38:40.883146 | controller | ok: Item: Runtime: 0:00:00.009823
2025-10-03 10:38:40.897338 | 
2025-10-03 10:38:40.897434 | TASK [stage-output : Make all log files readable]
2025-10-03 10:38:41.223407 | controller | changed
2025-10-03 10:38:41.230979 | 
2025-10-03 10:38:41.231124 | TASK [stage-output : Rename log files that match extensions_to_txt]
2025-10-03 10:38:41.765987 | controller | changed: Renamed files for staging.
2025-10-03 10:38:41.775258 | 
2025-10-03 10:38:41.775377 | TASK [stage-output : Discover log files for compression]
2025-10-03 10:38:41.801073 | controller | skipping: Conditional result was False
2025-10-03 10:38:41.810845 | 
2025-10-03 10:38:41.810972 | LOOP [stage-output : Archive everything from logs]
2025-10-03 10:38:41.857628 | 
2025-10-03 10:38:41.857897 | TASK [fetch-devstack-log-dir : Collect devstack logs]
2025-10-03 10:38:42.659247 | controller | changed:
2025-10-03 10:38:42.659488 | controller | cd+++++++++ logs/
2025-10-03 10:38:42.659528 | controller | >f+++++++++ logs/_.localrc_auto.txt
2025-10-03 10:38:42.659557 | controller | >f+++++++++ logs/audit_log.txt
2025-10-03 10:38:42.659583 | controller | >f+++++++++ logs/deprecations_log.txt
2025-10-03 10:38:42.659607 | controller | >f+++++++++ logs/devstack.journal.README.txt
2025-10-03 10:38:42.659632 | controller | >f+++++++++ logs/devstack.journal.gz
2025-10-03 10:38:42.659655 | controller | >f+++++++++ logs/devstacklog.txt
2025-10-03 10:38:42.659708 | controller | >f+++++++++ logs/devstacklog.txt.summary
2025-10-03 10:38:42.659734 | controller | >f+++++++++ logs/df.txt
2025-10-03 10:38:42.659758 | controller | >f+++++++++ logs/iptables.txt
2025-10-03 10:38:42.659781 | controller | >f+++++++++ logs/listen53.txt
2025-10-03 10:38:42.659803 | controller | >f+++++++++ logs/local_conf.txt
2025-10-03 10:38:42.659827 | controller | >f+++++++++ logs/performance.json
2025-10-03 10:38:42.659850 | controller | >f+++++++++ logs/pip3-freeze.txt
2025-10-03 10:38:42.659872 | controller | >f+++++++++ logs/resolv_conf.txt
2025-10-03 10:38:42.659895 | controller | >f+++++++++ logs/rpm-qa.txt
2025-10-03 10:38:42.659917 | controller | >f+++++++++ logs/services.txt
2025-10-03 10:38:42.659939 | controller | >f+++++++++ logs/sudoers
2025-10-03 10:38:42.659961 | controller | >f+++++++++ logs/syslog.txt
2025-10-03 10:38:42.659983 | controller | >f+++++++++ logs/worlddump-latest.txt
2025-10-03 10:38:42.660005 | controller | cd+++++++++ logs/apache/
2025-10-03 10:38:42.660027 | controller | cd+++++++++ logs/apache_config/
2025-10-03 10:38:42.660049 | controller | cd+++++++++ logs/etc/
2025-10-03 10:38:42.660072 | controller | cd+++++++++ logs/lvm/
2025-10-03 10:38:42.660094 | controller | >f+++++++++ logs/lvm/lvm_conf.txt
2025-10-03 10:38:42.660117 | controller | >f+++++++++ logs/lvm/lvmlocal_conf.txt
2025-10-03 10:38:42.660142 | controller | cd+++++++++ logs/lvm/archive/
2025-10-03 10:38:42.660165 | controller | cd+++++++++ logs/lvm/backup/
2025-10-03 10:38:42.660187 | controller | cd+++++++++ logs/lvm/cache/
2025-10-03 10:38:42.660210 | controller | cd+++++++++ logs/lvm/devices/
2025-10-03 10:38:42.660233 | controller | cd+++++++++ logs/lvm/profile/
2025-10-03 10:38:42.660261 | controller | >f+++++++++ logs/lvm/profile/cache-mq.profile
2025-10-03 10:38:42.660285 | controller | >f+++++++++ logs/lvm/profile/cache-smq.profile
2025-10-03 10:38:42.660310 | controller | >f+++++++++ logs/lvm/profile/command_profile_template.profile
2025-10-03 10:38:42.660333 | controller | >f+++++++++ logs/lvm/profile/lvmdbusd.profile
2025-10-03 10:38:42.660356 | controller | >f+++++++++ logs/lvm/profile/metadata_profile_template.profile
2025-10-03 10:38:42.660379 | controller | >f+++++++++ logs/lvm/profile/thin-generic.profile
2025-10-03 10:38:42.660402 | controller | >f+++++++++ logs/lvm/profile/thin-performance.profile
2025-10-03 10:38:42.660429 | controller | >f+++++++++ logs/lvm/profile/vdo-small.profile
2025-10-03 10:38:42.660454 | controller | cd+++++++++ logs/sudoers.d/
2025-10-03 10:38:42.660477 | controller | >f+++++++++ logs/sudoers.d/50_stack_sh
2025-10-03 10:38:42.660501 | controller | >f+++++++++ logs/sudoers.d/51_tempest_sh
2025-10-03 10:38:42.660525 | controller | >f+++++++++ logs/sudoers.d/90-cloud-init-users
2025-10-03 10:38:42.660555 | controller | >f+++++++++ logs/sudoers.d/zuul
2025-10-03 10:38:42.676353 | 
2025-10-03 10:38:42.676439 | TASK [Check if a tempest log exits]
2025-10-03 10:38:43.052422 | controller | ok
2025-10-03 10:38:43.057946 | 
2025-10-03 10:38:43.058009 | TASK [Link post-devstack tempest.log]
2025-10-03 10:38:43.082636 | controller | skipping: Conditional result was False
2025-10-03 10:38:43.089204 | 
2025-10-03 10:38:43.089270 | TASK [Capture most recent qemu crash dump, if any]
2025-10-03 06:38:43.494631 | controller | No match found.
2025-10-03 10:38:43.621797 | controller | ERROR
2025-10-03 10:38:43.622075 | controller | {
2025-10-03 10:38:43.622111 | controller |   "delta": "0:00:00.031231",
2025-10-03 10:38:43.622137 | controller |   "end": "2025-10-03 06:38:43.496062",
2025-10-03 10:38:43.622159 | controller |   "msg": "non-zero return code",
2025-10-03 10:38:43.622181 | controller |   "rc": 1,
2025-10-03 10:38:43.622203 | controller |   "start": "2025-10-03 06:38:43.464831"
2025-10-03 10:38:43.622224 | controller | }
2025-10-03 10:38:43.622251 | controller | ERROR: Ignoring Errors
2025-10-03 10:38:43.645798 | 
2025-10-03 10:38:43.645905 | PLAY RECAP
2025-10-03 10:38:43.645948 | controller | ok: 26 changed: 17 unreachable: 0 failed: 0 skipped: 12 rescued: 0 ignored: 2
2025-10-03 10:38:43.645969 | 
2025-10-03 10:38:43.767996 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/openstack/devstack/playbooks/post.yaml@master]
2025-10-03 10:38:43.778201 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-03 10:38:44.436471 | 
2025-10-03 10:38:44.436641 | PLAY [all]
2025-10-03 10:38:44.456590 | 
2025-10-03 10:38:44.456707 | TASK [include_role : fetch-output]
2025-10-03 10:38:44.496764 | controller | ok
2025-10-03 10:38:44.517017 | 
2025-10-03 10:38:44.517224 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-03 10:38:44.564292 | controller | skipping: Conditional result was False
2025-10-03 10:38:44.570488 | 
2025-10-03 10:38:44.570595 | TASK [fetch-output : Set log path for single node]
2025-10-03 10:38:44.601464 | controller | ok
2025-10-03 10:38:44.606875 | 
2025-10-03 10:38:44.606949 | LOOP [fetch-output : Ensure local output dirs]
2025-10-03 10:38:44.974961 | controller -> localhost | ok: "/var/lib/zuul/builds/2b2fd07d71034204a10c916c074d6573/work/logs"
2025-10-03 10:38:45.186097 | controller -> localhost | changed: "/var/lib/zuul/builds/2b2fd07d71034204a10c916c074d6573/work/artifacts"
2025-10-03 10:38:45.415728 | controller -> localhost | changed: "/var/lib/zuul/builds/2b2fd07d71034204a10c916c074d6573/work/docs"
2025-10-03 10:38:45.428452 | 
2025-10-03 10:38:45.428607 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-03 10:38:46.129637 | controller | changed: .d..t...... ./
2025-10-03 10:38:46.129924 | controller | changed: All items complete
2025-10-03 10:38:46.129970 | 
2025-10-03 10:38:46.649769 | controller | changed: .d..t...... ./
2025-10-03 10:38:47.197808 | controller | changed: .d..t...... ./
2025-10-03 10:38:47.213301 | 
2025-10-03 10:38:47.213427 | TASK [include_role : fetch-output-openshift]
2025-10-03 10:38:47.237921 | controller | skipping: Conditional result was False
2025-10-03 10:38:47.244495 | 
2025-10-03 10:38:47.244597 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-03 10:38:47.667430 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.009393
2025-10-03 10:38:47.911743 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.022770
2025-10-03 10:38:47.967086 | 
2025-10-03 10:38:47.967243 | PLAY [all]
2025-10-03 10:38:47.984891 | 
2025-10-03 10:38:47.985027 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-03 10:38:48.702196 | controller | changed
2025-10-03 10:38:48.750890 | 
2025-10-03 10:38:48.751011 | PLAY RECAP
2025-10-03 10:38:48.751068 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-03 10:38:48.751097 | 
2025-10-03 10:38:48.889344 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-03 10:38:48.894496 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-03 10:38:49.590601 | 
2025-10-03 10:38:49.590741 | PLAY [localhost]
2025-10-03 10:38:49.631084 | 
2025-10-03 10:38:49.631225 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-03 10:38:49.997058 | localhost | changed
2025-10-03 10:38:50.002066 | 
2025-10-03 10:38:50.002153 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-03 10:38:50.031409 | localhost | ok
2025-10-03 10:38:50.039916 | 
2025-10-03 10:38:50.040029 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-03 10:38:50.397752 | localhost | changed
2025-10-03 10:38:50.402566 | 
2025-10-03 10:38:50.402633 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-03 10:38:51.140262 | localhost | changed
2025-10-03 10:38:51.145644 | 
2025-10-03 10:38:51.145786 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-03 10:38:51.548545 | localhost | Identity added: /var/lib/zuul/builds/2b2fd07d71034204a10c916c074d6573/work/tmp/ansible.3_p65tzh (/var/lib/zuul/builds/2b2fd07d71034204a10c916c074d6573/work/tmp/ansible.3_p65tzh)
2025-10-03 10:38:51.548834 | localhost | ok: Runtime: 0:00:00.007424
2025-10-03 10:38:51.553328 | 
2025-10-03 10:38:51.553395 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-03 10:38:51.831390 | localhost | ok: Runtime: 0:00:00.009510
2025-10-03 10:38:51.843077 | 
2025-10-03 10:38:51.843266 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-03 10:38:51.952729 | localhost | changed
2025-10-03 10:38:51.963601 | 
2025-10-03 10:38:51.963857 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-03 10:38:52.537925 | localhost | changed
2025-10-03 10:38:52.561203 | 
2025-10-03 10:38:52.561317 | PLAY [localhost]
2025-10-03 10:38:52.573213 | 
2025-10-03 10:38:52.573292 | TASK [Generate bulk log download script]
2025-10-03 10:38:52.591654 | localhost | ok
2025-10-03 10:38:52.605303 | 
2025-10-03 10:38:52.605385 | TASK [local-log-download : Check API endpoint is defined]
2025-10-03 10:38:52.643527 | localhost | ok: All assertions passed
2025-10-03 10:38:52.648015 | 
2025-10-03 10:38:52.648077 | TASK [local-log-download : Create download script]
2025-10-03 10:38:53.081257 | localhost -> localhost | changed
2025-10-03 10:38:53.105727 | 
2025-10-03 10:38:53.105867 | TASK [Register quick-download link]
2025-10-03 10:38:53.126606 | localhost | ok
2025-10-03 10:38:53.150499 | 
2025-10-03 10:38:53.150631 | PLAY [logserver.rdoproject.org]
2025-10-03 10:38:53.165169 | 
2025-10-03 10:38:53.165309 | TASK [Set zuul-log-path fact]
2025-10-03 10:38:53.187243 | logserver.rdoproject.org | ok
2025-10-03 10:38:53.203531 | 
2025-10-03 10:38:53.203698 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-03 10:38:53.243079 | logserver.rdoproject.org | ok
2025-10-03 10:38:53.249406 | 
2025-10-03 10:38:53.249477 | TASK [upload-logs : Create log directories]
2025-10-03 10:38:54.194046 | logserver.rdoproject.org | changed
2025-10-03 10:38:54.197445 | 
2025-10-03 10:38:54.197511 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-03 10:38:54.509382 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.009959
2025-10-03 10:38:54.514847 | 
2025-10-03 10:38:54.514942 | TASK [upload-logs : Upload logs to log server]
2025-10-03 10:38:55.280629 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-03 10:38:55.293340 | 
2025-10-03 10:38:55.293435 | LOOP [upload-logs : Compress console log and json output]
2025-10-03 10:38:55.349915 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 10:38:55.360721 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 10:38:55.368504 | 
2025-10-03 10:38:55.368704 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-03 10:38:55.415201 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 10:38:55.415517 | 
2025-10-03 10:38:55.421585 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 10:38:55.436493 | 
2025-10-03 10:38:55.436721 | LOOP [upload-logs : Upload console log and json output]