Amit, Thanks again for your response. I *believe* things are/were set up correctly per the install guide. That guide just shows how to create a new setup, but doesn't show how to verify an existing user/role. I was able to find this command that I think shows all the user/role assignments that are currently set up: [root@l21651 ~(keystone_admin)]# openstack role assignment list --names +----------+--------------------+-------+------------------+--------+--------+-----------+ | Role | User | Group | Project | Domain | System | Inherited | +----------+--------------------+-------+------------------+--------+--------+-----------+ | admin | placement@Default | | services@Default | | | False | | admin | glance@Default | | services@Default | | | False | | admin | gnocchi@Default | | services@Default | | | False | | admin | nova@Default | | services@Default | | | False | | user | demo@Default | | demo@Default | | | False | | _member_ | demo@Default | | demo@Default | | | False | | admin | ceilometer@Default | | services@Default | | | False | | admin | aodh@Default | | services@Default | | | False | | admin | admin@Default | | admin@Default | | | False | | admin | neutron@Default | | services@Default | | | False | | admin | cinder@Default | | services@Default | | | False | | admin | swift@Default | | services@Default | | | False | | admin | admin@Default | | | | all | False | +----------+--------------------+-------+------------------+--------+--------+-----------+ I am running as admin, so I *should* have all the rights needed for creating snapshots, correct? Here is my file I source to run commands (password is redacted) unset OS_SERVICE_TOKEN export OS_USERNAME=admin export OS_PASSWORD='<redacted>' export OS_REGION_NAME=RegionOne export OS_AUTH_URL=http://10.61.157.80:5000/v3 export PS1='[\u@\h \W(keystone_admin)]\$ ' export OS_PROJECT_NAME=admin export OS_USER_DOMAIN_NAME=Default export OS_PROJECT_DOMAIN_NAME=Default export OS_IDENTITY_API_VERSION=3 I did turn up the debugging in all the config files, and restarted services to make sure it took effect. I am still getting the same error. here is the command I ran to create the image: openstack server image create --debug cirrosinstance That appeared to complete successfully from the commandline, but the snapshots from my attempts are all in an error state still: [root@l21651 ~(keystone_admin)]# openstack volume snapshot list +--------------------------------------+-----------------------------+-------------+--------+------+ | ID | Name | Description | Status | Size | +--------------------------------------+-----------------------------+-------------+--------+------+ | 4b603a9d-81ec-498c-8039-0abbc67023dc | snapshot for cirrosinstance | | error | 1 | | cfcdf62d-142e-4e10-9db8-f87975d29289 | snapshot for cirrosinstance | | error | 1 | | 838ac161-04ed-42d5-8a6b-4b283599fffa | snapshot for cirrosinstance | | error | 1 | +--------------------------------------+-----------------------------+-------------+--------+------+ Here are all the log entries from the controller (I didn't see any on the compute nodes) related to one of the attempts: /var/log/cinder/api.log:2024-09-12 16:00:52.551 3606 DEBUG cinder.api.middleware.request_id [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-57287960-b85f-4913-b3ed-bbb5894824c0 - - - - - -] RequestId filter calling following filter/app _context_setter /usr/lib/python3.9/site-packages/cinder/api/middleware/request_id.py:62 /var/log/cinder/api.log:2024-09-12 16:00:52.749 3606 WARNING keystonemiddleware.auth_token [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-57287960-b85f-4913-b3ed-bbb5894824c0 - - - - - -] A valid token was submitted as a service token, but it was not a valid service token. This is incorrect but backwards compatible behaviour. This will be removed in future releases. /var/log/cinder/api.log:2024-09-12 16:00:52.932 3606 INFO cinder.api.openstack.wsgi [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-57287960-b85f-4913-b3ed-bbb5894824c0 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] GET http://10.61.157.80:8776/v3/limits /var/log/cinder/api.log:2024-09-12 16:00:52.932 3606 DEBUG cinder.api.openstack.wsgi [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-57287960-b85f-4913-b3ed-bbb5894824c0 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Empty body provided in request get_body /usr/lib/python3.9/site-packages/cinder/api/openstack/wsgi.py:715 /var/log/cinder/api.log:2024-09-12 16:00:52.932 3606 DEBUG cinder.api.openstack.wsgi [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-57287960-b85f-4913-b3ed-bbb5894824c0 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Calling method 'index' _process_stack /usr/lib/python3.9/site-packages/cinder/api/openstack/wsgi.py:868 /var/log/cinder/api.log:2024-09-12 16:00:52.953 3606 INFO cinder.api.openstack.wsgi [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-57287960-b85f-4913-b3ed-bbb5894824c0 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] http://10.61.157.80:8776/v3/limits returned with HTTP 200 /var/log/cinder/api.log:2024-09-12 16:00:52.954 3606 INFO eventlet.wsgi.server [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-57287960-b85f-4913-b3ed-bbb5894824c0 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] 10.61.157.80 "GET /v3/limits HTTP/1.1" status: 200 len: 629 time: 0.4035914 /var/log/cinder/api.log:2024-09-12 16:00:52.999 3606 DEBUG cinder.api.middleware.request_id [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-3cbe7b96-c40f-4a0f-8120-c5bcf28a760a - - - - - -] RequestId filter calling following filter/app _context_setter /usr/lib/python3.9/site-packages/cinder/api/middleware/request_id.py:62 /var/log/cinder/api.log:2024-09-12 16:00:53.001 3606 INFO cinder.api.openstack.wsgi [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-3cbe7b96-c40f-4a0f-8120-c5bcf28a760a 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] GET http://10.61.157.80:8776/v3/volumes/0aaa3dfe-ba0e-4306-b37a-10d847b1c264 /var/log/cinder/api.log:2024-09-12 16:00:53.002 3606 DEBUG cinder.api.openstack.wsgi [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-3cbe7b96-c40f-4a0f-8120-c5bcf28a760a 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Empty body provided in request get_body /usr/lib/python3.9/site-packages/cinder/api/openstack/wsgi.py:715 /var/log/cinder/api.log:2024-09-12 16:00:53.002 3606 DEBUG cinder.api.openstack.wsgi [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-3cbe7b96-c40f-4a0f-8120-c5bcf28a760a 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Calling method 'show' _process_stack /usr/lib/python3.9/site-packages/cinder/api/openstack/wsgi.py:868 /var/log/cinder/api.log:2024-09-12 16:00:53.017 3606 INFO cinder.volume.api [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-3cbe7b96-c40f-4a0f-8120-c5bcf28a760a 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Volume info retrieved successfully. /var/log/cinder/api.log:2024-09-12 16:00:53.023 3606 INFO cinder.api.openstack.wsgi [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-3cbe7b96-c40f-4a0f-8120-c5bcf28a760a 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] http://10.61.157.80:8776/v3/volumes/0aaa3dfe-ba0e-4306-b37a-10d847b1c264 returned with HTTP 200 /var/log/cinder/api.log:2024-09-12 16:00:53.024 3606 INFO eventlet.wsgi.server [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-3cbe7b96-c40f-4a0f-8120-c5bcf28a760a 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] 10.61.157.80 "GET /v3/volumes/0aaa3dfe-ba0e-4306-b37a-10d847b1c264 HTTP/1.1" status: 200 len: 1992 time: 0.0256529 /var/log/cinder/api.log:2024-09-12 16:00:53.029 3606 DEBUG cinder.api.middleware.request_id [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 - - - - - -] RequestId filter calling following filter/app _context_setter /usr/lib/python3.9/site-packages/cinder/api/middleware/request_id.py:62 /var/log/cinder/api.log:2024-09-12 16:00:53.031 3606 INFO cinder.api.openstack.wsgi [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] POST http://10.61.157.80:8776/v3/snapshots /var/log/cinder/api.log:2024-09-12 16:00:53.032 3606 DEBUG cinder.api.openstack.wsgi [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Action: 'create', calling method: create, body: {"snapshot": {"volume_id": "0aaa3dfe-ba0e-4306-b37a-10d847b1c264", "force": true, "name": "snapshot for cirrosinstance", "description": "", "metadata": {}}} _process_stack /usr/lib/python3.9/site-packages/cinder/api/openstack/wsgi.py:866 /var/log/cinder/api.log:2024-09-12 16:00:53.048 3606 INFO cinder.volume.api [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Volume info retrieved successfully. /var/log/cinder/api.log:2024-09-12 16:00:53.049 3606 INFO cinder.api.v3.snapshots [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Create snapshot from volume 0aaa3dfe-ba0e-4306-b37a-10d847b1c264 /var/log/cinder/api.log:2024-09-12 16:00:53.088 3606 DEBUG cinder.quota [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Created reservations ['e24a54da-152f-47b8-80e1-4ee3c1a2e057', '2770eb0b-b210-4e56-824f-52a64c0ec7c3', 'b78e98c7-2b8f-4298-9626-1c7cc1f559b9', 'd9524731-94ca-49ce-b997-57683896a7aa'] reserve /usr/lib/python3.9/site-packages/cinder/quota.py:755 /var/log/cinder/api.log:2024-09-12 16:00:53.122 3606 INFO cinder.volume.api [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Snapshot force create request issued successfully. /var/log/cinder/api.log:2024-09-12 16:00:53.123 3606 INFO cinder.api.openstack.wsgi [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] http://10.61.157.80:8776/v3/snapshots returned with HTTP 202 /var/log/cinder/api.log:2024-09-12 16:00:53.124 3606 INFO eventlet.wsgi.server [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] 10.61.157.80 "POST /v3/snapshots HTTP/1.1" status: 202 len: 617 time: 0.0946217 /var/log/cinder/scheduler.log:2024-09-12 16:00:53.133 1646 DEBUG cinder.scheduler.host_manager [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Updating capabilities for l21651@lvm#lvm: {'pool_name': 'lvm', 'total_capacity_gb': 19.57, 'free_capacity_gb': 19.57, 'reserved_percentage': 0, 'location_info': 'LVMVolumeDriver:l21651:cinder-volumes:thin:0', 'QoS_support': False, 'provisioned_capacity_gb': 0.0, 'max_over_subscription_ratio': '20.0', 'thin_provisioning_support': True, 'thick_provisioning_support': False, 'total_volumes': 1, 'filter_function': None, 'goodness_function': None, 'multiattach': True, 'backend_state': 'up', 'allocated_capacity_gb': 0, 'cacheable': True, 'volume_backend_name': 'lvm', 'storage_protocol': ['iSCSI', 'iscsi'], 'vendor_name': 'Open Source', 'driver_version': '3.0.0', 'timestamp': datetime.datetime(2024, 9, 12, 22, 0, 8, 38146)} update_from_volume_capability /usr/lib/python3.9/site-packages/cinder/scheduler/host_manager.py:415 /var/log/cinder/scheduler.log:2024-09-12 16:00:53.133 1646 DEBUG cinder.scheduler.host_manager [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Updating capabilities for l21651@nfs#nfs: {'volume_backend_name': 'nfs', 'vendor_name': 'Open Source', 'driver_version': '1.4.0', 'storage_protocol': ['NFS', 'nfs'], 'total_capacity_gb': 100.0, 'free_capacity_gb': 99.8924560546875, 'reserved_percentage': 0, 'QoS_support': False, 'sparse_copy_volume': True, 'provisioned_capacity_gb': 25.0, 'max_over_subscription_ratio': 20.0, 'thin_provisioning_support': True, 'thick_provisioning_support': False, 'allocated_capacity_gb': 2, 'filter_function': None, 'goodness_function': None, 'timestamp': datetime.datetime(2024, 9, 12, 21, 59, 53, 443615)} update_from_volume_capability /usr/lib/python3.9/site-packages/cinder/scheduler/host_manager.py:415 /var/log/cinder/scheduler.log:2024-09-12 16:00:53.134 1646 DEBUG cinder.scheduler.base_filter [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Starting with 2 host(s) get_filtered_objects /usr/lib/python3.9/site-packages/cinder/scheduler/base_filter.py:97 /var/log/cinder/scheduler.log:2024-09-12 16:00:53.134 1646 DEBUG cinder.scheduler.base_filter [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Filter AvailabilityZoneFilter returned 2 host(s) get_filtered_objects /usr/lib/python3.9/site-packages/cinder/scheduler/base_filter.py:125 /var/log/cinder/scheduler.log:2024-09-12 16:00:53.134 1646 DEBUG cinder.scheduler.filters.capacity_filter [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Checking if host l21651@nfs#nfs can create a 1 GB volume (None) backend_passes /usr/lib/python3.9/site-packages/cinder/scheduler/filters/capacity_filter.py:57 /var/log/cinder/scheduler.log:2024-09-12 16:00:53.135 1646 DEBUG cinder.scheduler.filters.capacity_filter [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Storage Capacity factors {'total_capacity': 100.0, 'free_capacity': 99.8924560546875, 'reserved_capacity': 0, 'total_reserved_available_capacity': 100.0, 'max_over_subscription_ratio': 20.0, 'total_available_capacity': 2000.0, 'provisioned_capacity': 25.0, 'calculated_free_capacity': 1975.0, 'virtual_free_capacity': 1975.0, 'free_percent': 98.75, 'provisioned_ratio': 0.01, 'provisioned_type': 'thin'} backend_passes /usr/lib/python3.9/site-packages/cinder/scheduler/filters/capacity_filter.py:137 /var/log/cinder/scheduler.log:2024-09-12 16:00:53.135 1646 DEBUG cinder.scheduler.filters.capacity_filter [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Checking provisioning for request of 1 GB. Backend: host 'l21651@nfs#nfs': free_capacity_gb: 99.8924560546875, total_capacity_gb: 100.0, allocated_capacity_gb: 2, max_over_subscription_ratio: 20.0, reserved_percentage: 0, provisioned_capacity_gb: 25.0, thin_provisioning_support: True, thick_provisioning_support: False, pools: {}, updated at: 2024-09-12 21:59:53.443615 backend_passes /usr/lib/python3.9/site-packages/cinder/scheduler/filters/capacity_filter.py:155 /var/log/cinder/scheduler.log:2024-09-12 16:00:53.135 1646 DEBUG cinder.scheduler.filters.capacity_filter [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Space information for volume creation on host l21651@nfs#nfs (requested / avail): 1/1975.0 backend_passes /usr/lib/python3.9/site-packages/cinder/scheduler/filters/capacity_filter.py:186 /var/log/cinder/scheduler.log:2024-09-12 16:00:53.135 1646 DEBUG cinder.scheduler.filters.capacity_filter [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Checking if host l21651@lvm#lvm can create a 1 GB volume (None) backend_passes /usr/lib/python3.9/site-packages/cinder/scheduler/filters/capacity_filter.py:57 /var/log/cinder/scheduler.log:2024-09-12 16:00:53.136 1646 DEBUG cinder.scheduler.filters.capacity_filter [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Storage Capacity factors {'total_capacity': 19.57, 'free_capacity': 19.57, 'reserved_capacity': 0, 'total_reserved_available_capacity': 19.57, 'max_over_subscription_ratio': 20.0, 'total_available_capacity': 391.4, 'provisioned_capacity': 0.0, 'calculated_free_capacity': 391.4, 'virtual_free_capacity': 391.4, 'free_percent': 100.0, 'provisioned_ratio': 0.0, 'provisioned_type': 'thin'} backend_passes /usr/lib/python3.9/site-packages/cinder/scheduler/filters/capacity_filter.py:137 /var/log/cinder/scheduler.log:2024-09-12 16:00:53.136 1646 DEBUG cinder.scheduler.filters.capacity_filter [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Checking provisioning for request of 1 GB. Backend: host 'l21651@lvm#lvm': free_capacity_gb: 19.57, total_capacity_gb: 19.57, allocated_capacity_gb: 0, max_over_subscription_ratio: 20.0, reserved_percentage: 0, provisioned_capacity_gb: 0.0, thin_provisioning_support: True, thick_provisioning_support: False, pools: {}, updated at: 2024-09-12 22:00:08.038146 backend_passes /usr/lib/python3.9/site-packages/cinder/scheduler/filters/capacity_filter.py:155 /var/log/cinder/scheduler.log:2024-09-12 16:00:53.136 1646 DEBUG cinder.scheduler.filters.capacity_filter [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Space information for volume creation on host l21651@lvm#lvm (requested / avail): 1/391.4 backend_passes /usr/lib/python3.9/site-packages/cinder/scheduler/filters/capacity_filter.py:186 /var/log/cinder/scheduler.log:2024-09-12 16:00:53.136 1646 DEBUG cinder.scheduler.base_filter [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Filter CapacityFilter returned 2 host(s) get_filtered_objects /usr/lib/python3.9/site-packages/cinder/scheduler/base_filter.py:125 /var/log/cinder/scheduler.log:2024-09-12 16:00:53.136 1646 DEBUG cinder.scheduler.base_filter [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Filter CapabilitiesFilter returned 2 host(s) get_filtered_objects /usr/lib/python3.9/site-packages/cinder/scheduler/base_filter.py:125 /var/log/cinder/scheduler.log:2024-09-12 16:00:53.136 1646 DEBUG cinder.scheduler.filter_scheduler [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Filtered [host 'l21651@nfs#nfs': free_capacity_gb: 99.8924560546875, total_capacity_gb: 100.0, allocated_capacity_gb: 2, max_over_subscription_ratio: 20.0, reserved_percentage: 0, provisioned_capacity_gb: 25.0, thin_provisioning_support: True, thick_provisioning_support: False, pools: {}, updated at: 2024-09-12 21:59:53.443615, host 'l21651@lvm#lvm': free_capacity_gb: 19.57, total_capacity_gb: 19.57, allocated_capacity_gb: 0, max_over_subscription_ratio: 20.0, reserved_percentage: 0, provisioned_capacity_gb: 0.0, thin_provisioning_support: True, thick_provisioning_support: False, pools: {}, updated at: 2024-09-12 22:00:08.038146] _get_weighted_candidates /usr/lib/python3.9/site-packages/cinder/scheduler/filter_scheduler.py:358 /var/log/cinder/scheduler.log:2024-09-12 16:00:53.137 1646 DEBUG cinder.scheduler.base_weight [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Weigher CapacityWeigher returned, weigher value is {max: 1975.0, min: 391.4} get_weighed_objects /usr/lib/python3.9/site-packages/cinder/scheduler/base_weight.py:156 /var/log/cinder/scheduler.log:2024-09-12 16:00:53.137 1646 DEBUG cinder.scheduler.host_manager [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Weighed [WeighedHost [host: l21651@nfs#nfs, weight: 1.0], WeighedHost [host: l21651@lvm#lvm, weight: 0.0]] get_weighed_backends /usr/lib/python3.9/site-packages/cinder/scheduler/host_manager.py:565 /var/log/cinder/scheduler.log:2024-09-12 16:00:53.137 1646 DEBUG cinder.scheduler.host_manager [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Consumed 1 GB from backend: host 'l21651@nfs#nfs': free_capacity_gb: 98.8924560546875, total_capacity_gb: 100.0, allocated_capacity_gb: 3, max_over_subscription_ratio: 20.0, reserved_percentage: 0, provisioned_capacity_gb: 26.0, thin_provisioning_support: True, thick_provisioning_support: False, pools: {}, updated at: 2024-09-12 22:00:53.137624 consume_from_volume /usr/lib/python3.9/site-packages/cinder/scheduler/host_manager.py:354 /var/log/cinder/volume.log:2024-09-12 16:00:53.190 3607 DEBUG cinder.coordination [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Acquiring lock "/var/lib/cinder/cinder-nfs-0aaa3dfe-ba0e-4306-b37a-10d847b1c264" by "create_snapshot" __acquire /usr/lib/python3.9/site-packages/cinder/coordination.py:143 /var/log/cinder/volume.log:2024-09-12 16:00:53.191 3607 DEBUG cinder.coordination [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Lock "/var/lib/cinder/cinder-nfs-0aaa3dfe-ba0e-4306-b37a-10d847b1c264" acquired by "create_snapshot" :: waited 0.002s __acquire /usr/lib/python3.9/site-packages/cinder/coordination.py:146 /var/log/cinder/volume.log:2024-09-12 16:00:53.192 3607 DEBUG cinder.volume.drivers.remotefs [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Creating online snapshot 4b603a9d-81ec-498c-8039-0abbc67023dc of volume 0aaa3dfe-ba0e-4306-b37a-10d847b1c264 _create_snapshot /usr/lib/python3.9/site-packages/cinder/volume/drivers/remotefs.py:1695 /var/log/cinder/volume.log:2024-09-12 16:00:53.224 3607 DEBUG oslo_concurrency.processutils [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Running cmd (subprocess): /usr/bin/python3 -m oslo_concurrency.prlimit --as=1073741824 --cpu=60 -- sudo cinder-rootwrap /etc/cinder/rootwrap.conf env LC_ALL=C qemu-img info -f raw --output=json --force-share /var/lib/cinder/mnt/56522c30c45d0a9afe5818208e55a58b/volume-0aaa3dfe-ba0e-4306-b37a-10d847b1c264 execute /usr/lib/python3.9/site-packages/oslo_concurrency/processutils.py:384 /var/log/cinder/volume.log:2024-09-12 16:00:53.804 3607 DEBUG oslo_concurrency.processutils [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] CMD "/usr/bin/python3 -m oslo_concurrency.prlimit --as=1073741824 --cpu=60 -- sudo cinder-rootwrap /etc/cinder/rootwrap.conf env LC_ALL=C qemu-img info -f raw --output=json --force-share /var/lib/cinder/mnt/56522c30c45d0a9afe5818208e55a58b/volume-0aaa3dfe-ba0e-4306-b37a-10d847b1c264" returned: 0 in 0.580s execute /usr/lib/python3.9/site-packages/oslo_concurrency/processutils.py:422 /var/log/cinder/volume.log:2024-09-12 16:00:53.806 3607 DEBUG oslo_concurrency.processutils [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Running cmd (subprocess): /usr/bin/python3 -m oslo_concurrency.prlimit --as=1073741824 --cpu=60 -- sudo cinder-rootwrap /etc/cinder/rootwrap.conf env LC_ALL=C qemu-img info -f luks --output=json --force-share /var/lib/cinder/mnt/56522c30c45d0a9afe5818208e55a58b/volume-0aaa3dfe-ba0e-4306-b37a-10d847b1c264 execute /usr/lib/python3.9/site-packages/oslo_concurrency/processutils.py:384 /var/log/cinder/volume.log:2024-09-12 16:00:54.321 3607 DEBUG oslo_concurrency.processutils [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] CMD "/usr/bin/python3 -m oslo_concurrency.prlimit --as=1073741824 --cpu=60 -- sudo cinder-rootwrap /etc/cinder/rootwrap.conf env LC_ALL=C qemu-img info -f luks --output=json --force-share /var/lib/cinder/mnt/56522c30c45d0a9afe5818208e55a58b/volume-0aaa3dfe-ba0e-4306-b37a-10d847b1c264" returned: 1 in 0.515s execute /usr/lib/python3.9/site-packages/oslo_concurrency/processutils.py:422 /var/log/cinder/volume.log:2024-09-12 16:00:54.322 3607 DEBUG oslo_concurrency.processutils [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] '/usr/bin/python3 -m oslo_concurrency.prlimit --as=1073741824 --cpu=60 -- sudo cinder-rootwrap /etc/cinder/rootwrap.conf env LC_ALL=C qemu-img info -f luks --output=json --force-share /var/lib/cinder/mnt/56522c30c45d0a9afe5818208e55a58b/volume-0aaa3dfe-ba0e-4306-b37a-10d847b1c264' failed. Not Retrying. execute /usr/lib/python3.9/site-packages/oslo_concurrency/processutils.py:473 /var/log/cinder/volume.log:2024-09-12 16:00:54.323 3607 DEBUG oslo_concurrency.processutils [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf qemu-img create -f qcow2 -o backing_file=/var/lib/cinder/mnt/56522c30c45d0a9afe5818208e55a58b/volume-0aaa3dfe-ba0e-4306-b37a-10d847b1c264,backing_fmt=raw /var/lib/cinder/mnt/56522c30c45d0a9afe5818208e55a58b/volume-0aaa3dfe-ba0e-4306-b37a-10d847b1c264.4b603a9d-81ec-498c-8039-0abbc67023dc 1G execute /usr/lib/python3.9/site-packages/oslo_concurrency/processutils.py:384 /var/log/cinder/volume.log:2024-09-12 16:00:54.807 3607 DEBUG oslo_concurrency.processutils [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] CMD "sudo cinder-rootwrap /etc/cinder/rootwrap.conf qemu-img create -f qcow2 -o backing_file=/var/lib/cinder/mnt/56522c30c45d0a9afe5818208e55a58b/volume-0aaa3dfe-ba0e-4306-b37a-10d847b1c264,backing_fmt=raw /var/lib/cinder/mnt/56522c30c45d0a9afe5818208e55a58b/volume-0aaa3dfe-ba0e-4306-b37a-10d847b1c264.4b603a9d-81ec-498c-8039-0abbc67023dc 1G" returned: 0 in 0.484s execute /usr/lib/python3.9/site-packages/oslo_concurrency/processutils.py:422 /var/log/cinder/volume.log:2024-09-12 16:00:54.808 3607 DEBUG oslo_concurrency.processutils [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf qemu-img rebase -u -b volume-0aaa3dfe-ba0e-4306-b37a-10d847b1c264 -F raw /var/lib/cinder/mnt/56522c30c45d0a9afe5818208e55a58b/volume-0aaa3dfe-ba0e-4306-b37a-10d847b1c264.4b603a9d-81ec-498c-8039-0abbc67023dc execute /usr/lib/python3.9/site-packages/oslo_concurrency/processutils.py:384 /var/log/cinder/volume.log:2024-09-12 16:00:55.203 3607 DEBUG oslo_concurrency.processutils [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] CMD "sudo cinder-rootwrap /etc/cinder/rootwrap.conf qemu-img rebase -u -b volume-0aaa3dfe-ba0e-4306-b37a-10d847b1c264 -F raw /var/lib/cinder/mnt/56522c30c45d0a9afe5818208e55a58b/volume-0aaa3dfe-ba0e-4306-b37a-10d847b1c264.4b603a9d-81ec-498c-8039-0abbc67023dc" returned: 0 in 0.394s execute /usr/lib/python3.9/site-packages/oslo_concurrency/processutils.py:422 /var/log/cinder/volume.log:2024-09-12 16:00:55.204 3607 WARNING cinder.volume.drivers.remotefs [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] /var/lib/cinder/mnt/56522c30c45d0a9afe5818208e55a58b/volume-0aaa3dfe-ba0e-4306-b37a-10d847b1c264.4b603a9d-81ec-498c-8039-0abbc67023dc is being set with open permissions: ugo+rw /var/log/cinder/volume.log:2024-09-12 16:00:55.204 3607 DEBUG oslo_concurrency.processutils [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf chmod ugo+rw /var/lib/cinder/mnt/56522c30c45d0a9afe5818208e55a58b/volume-0aaa3dfe-ba0e-4306-b37a-10d847b1c264.4b603a9d-81ec-498c-8039-0abbc67023dc execute /usr/lib/python3.9/site-packages/oslo_concurrency/processutils.py:384 /var/log/cinder/volume.log:2024-09-12 16:00:55.586 3607 DEBUG oslo_concurrency.processutils [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] CMD "sudo cinder-rootwrap /etc/cinder/rootwrap.conf chmod ugo+rw /var/lib/cinder/mnt/56522c30c45d0a9afe5818208e55a58b/volume-0aaa3dfe-ba0e-4306-b37a-10d847b1c264.4b603a9d-81ec-498c-8039-0abbc67023dc" returned: 0 in 0.382s execute /usr/lib/python3.9/site-packages/oslo_concurrency/processutils.py:422 /var/log/cinder/volume.log:2024-09-12 16:00:55.588 3607 DEBUG cinder.compute.nova [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Creating Keystone token plugin using URL: http://10.61.157.80:5000 novaclient /usr/lib/python3.9/site-packages/cinder/compute/nova.py:106 /var/log/cinder/volume.log:2024-09-12 16:00:55.713 3607 ERROR cinder.volume.drivers.remotefs [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Call to Nova to create snapshot failed: keystoneauth1.exceptions.http.BadRequest: Expecting to find domain in project. The server could not comply with the request since it is either malformed or otherwise incorrect. The client is assumed to be in error. (HTTP 400) (Request-ID: req-6cc2a596-b980-43b9-b3dc-5eff336a4949) /var/log/cinder/volume.log:2024-09-12 16:00:55.714 3607 DEBUG cinder.coordination [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Lock "/var/lib/cinder/cinder-nfs-0aaa3dfe-ba0e-4306-b37a-10d847b1c264" released by "create_snapshot" :: held 2.523s __release /usr/lib/python3.9/site-packages/cinder/coordination.py:157 /var/log/cinder/volume.log:2024-09-12 16:00:55.721 3607 INFO cinder.message.api [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Creating message record for request_id = req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 /var/log/cinder/volume.log:2024-09-12 16:00:55.730 3607 ERROR oslo_messaging.rpc.server [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Exception during message handling: keystoneauth1.exceptions.http.BadRequest: Expecting to find domain in project. The server could not comply with the request since it is either malformed or otherwise incorrect. The client is assumed to be in error. (HTTP 400) (Request-ID: req-6cc2a596-b980-43b9-b3dc-5eff336a4949) /var/log/glance/api.log:2024-09-12 16:00:53.966 3622 INFO eventlet.wsgi.server [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] 10.61.157.80 - - [12/Sep/2024 16:00:53] "GET /v2/schemas/image HTTP/1.1" 200 6283 0.822451 /var/log/glance/api.log:2024-09-12 16:00:53.970 3622 DEBUG glance.api.middleware.version_negotiation [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Determining version of request: GET /v2/schemas/image Accept: */* process_request /usr/lib/python3.9/site-packages/glance/api/middleware/version_negotiation.py:44 /var/log/glance/api.log:2024-09-12 16:00:53.970 3622 DEBUG glance.api.middleware.version_negotiation [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Using url versioning process_request /usr/lib/python3.9/site-packages/glance/api/middleware/version_negotiation.py:57 /var/log/glance/api.log:2024-09-12 16:00:53.970 3622 DEBUG glance.api.middleware.version_negotiation [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Matched version: v2 process_request /usr/lib/python3.9/site-packages/glance/api/middleware/version_negotiation.py:69 /var/log/glance/api.log:2024-09-12 16:00:53.971 3622 DEBUG glance.api.middleware.version_negotiation [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] new path /v2/schemas/image process_request /usr/lib/python3.9/site-packages/glance/api/middleware/version_negotiation.py:70 /var/log/glance/api.log:2024-09-12 16:00:53.973 3622 INFO eventlet.wsgi.server [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] 10.61.157.80 - - [12/Sep/2024 16:00:53] "GET /v2/schemas/image HTTP/1.1" 200 6283 0.003874 /var/log/glance/api.log:2024-09-12 16:00:54.037 3622 DEBUG glance.api.middleware.version_negotiation [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Determining version of request: POST /v2/images Accept: */* process_request /usr/lib/python3.9/site-packages/glance/api/middleware/version_negotiation.py:44 /var/log/glance/api.log:2024-09-12 16:00:54.038 3622 DEBUG glance.api.middleware.version_negotiation [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Using url versioning process_request /usr/lib/python3.9/site-packages/glance/api/middleware/version_negotiation.py:57 /var/log/glance/api.log:2024-09-12 16:00:54.038 3622 DEBUG glance.api.middleware.version_negotiation [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Matched version: v2 process_request /usr/lib/python3.9/site-packages/glance/api/middleware/version_negotiation.py:69 /var/log/glance/api.log:2024-09-12 16:00:54.038 3622 DEBUG glance.api.middleware.version_negotiation [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] new path /v2/images process_request /usr/lib/python3.9/site-packages/glance/api/middleware/version_negotiation.py:70 /var/log/glance/api.log:2024-09-12 16:00:54.082 3622 INFO eventlet.wsgi.server [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] 10.61.157.80 - - [12/Sep/2024 16:00:54] "POST /v2/images HTTP/1.1" 201 2105 0.045671 /var/log/glance/api.log:2024-09-12 16:00:54.093 3622 DEBUG glance.api.middleware.version_negotiation [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Determining version of request: PUT /v2/images/bb02f9bc-203a-4655-af53-c6e8f6f231e0/file Accept: */* process_request /usr/lib/python3.9/site-packages/glance/api/middleware/version_negotiation.py:44 /var/log/glance/api.log:2024-09-12 16:00:54.093 3622 DEBUG glance.api.middleware.version_negotiation [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Using url versioning process_request /usr/lib/python3.9/site-packages/glance/api/middleware/version_negotiation.py:57 /var/log/glance/api.log:2024-09-12 16:00:54.093 3622 DEBUG glance.api.middleware.version_negotiation [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Matched version: v2 process_request /usr/lib/python3.9/site-packages/glance/api/middleware/version_negotiation.py:69 /var/log/glance/api.log:2024-09-12 16:00:54.094 3622 DEBUG glance.api.middleware.version_negotiation [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] new path /v2/images/bb02f9bc-203a-4655-af53-c6e8f6f231e0/file process_request /usr/lib/python3.9/site-packages/glance/api/middleware/version_negotiation.py:70 /var/log/glance/api.log:2024-09-12 16:00:54.102 3622 DEBUG glance.common.utils [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Sorted locations: [] sort_image_locations /usr/lib/python3.9/site-packages/glance/common/utils.py:736 /var/log/glance/api.log:2024-09-12 16:00:54.103 3622 INFO glance.api.v2.image_data [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Unable to create trust: no such option collect_timing in group [keystone_authtoken] Use the existing user token. /var/log/glance/api.log:2024-09-12 16:00:54.126 3622 DEBUG glance.location [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Enabling in-flight format inspection for qcow2 set_data /usr/lib/python3.9/site-packages/glance/location.py:581 /var/log/glance/api.log:2024-09-12 16:00:54.127 3622 DEBUG glance_store._drivers.filesystem [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Wrote 0 bytes to /var/lib/glance/images/bb02f9bc-203a-4655-af53-c6e8f6f231e0 with checksum d41d8cd98f00b204e9800998ecf8427e and multihash cf83e1357eefb8bdf1542850d66d8007d620e4050b5715dc83f4a921d36ce9ce47d0d13c5d85f2b0ff8318d2877eec2f63b931bd47417a81a538327af927da3e add /usr/lib/python3.9/site-packages/glance_store/_drivers/filesystem.py:773 /var/log/glance/api.log:2024-09-12 16:00:54.127 3622 WARNING glance.location [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Image format qcow2 did not match; unable to calculate virtual size /var/log/glance/api.log:2024-09-12 16:00:54.166 3622 DEBUG glance_store.multi_backend [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Skipping store.set_acls... not implemented set_acls_for_multi_store /usr/lib/python3.9/site-packages/glance_store/multi_backend.py:548 /var/log/glance/api.log:2024-09-12 16:00:54.169 3622 INFO eventlet.wsgi.server [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] 10.61.157.80 - - [12/Sep/2024 16:00:54] "PUT /v2/images/bb02f9bc-203a-4655-af53-c6e8f6f231e0/file HTTP/1.1" 204 213 0.076184 /var/log/glance/api.log:2024-09-12 16:00:54.175 3622 DEBUG glance.api.middleware.version_negotiation [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Determining version of request: GET /v2/images/bb02f9bc-203a-4655-af53-c6e8f6f231e0 Accept: */* process_request /usr/lib/python3.9/site-packages/glance/api/middleware/version_negotiation.py:44 /var/log/glance/api.log:2024-09-12 16:00:54.175 3622 DEBUG glance.api.middleware.version_negotiation [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Using url versioning process_request /usr/lib/python3.9/site-packages/glance/api/middleware/version_negotiation.py:57 /var/log/glance/api.log:2024-09-12 16:00:54.176 3622 DEBUG glance.api.middleware.version_negotiation [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Matched version: v2 process_request /usr/lib/python3.9/site-packages/glance/api/middleware/version_negotiation.py:69 /var/log/glance/api.log:2024-09-12 16:00:54.176 3622 DEBUG glance.api.middleware.version_negotiation [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] new path /v2/images/bb02f9bc-203a-4655-af53-c6e8f6f231e0 process_request /usr/lib/python3.9/site-packages/glance/api/middleware/version_negotiation.py:70 /var/log/glance/api.log:2024-09-12 16:00:54.188 3622 DEBUG glance.common.utils [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Sorted locations: [{'id': 12, 'url': 'file:///var/lib/glance/images/bb02f9bc-203a-4655-af53-c6e8f6f231e0', 'metadata': {'store': 'file'}, 'status': 'active'}] sort_image_locations /usr/lib/python3.9/site-packages/glance/common/utils.py:736 /var/log/glance/api.log:2024-09-12 16:00:54.190 3622 INFO eventlet.wsgi.server [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] 10.61.157.80 - - [12/Sep/2024 16:00:54] "GET /v2/images/bb02f9bc-203a-4655-af53-c6e8f6f231e0 HTTP/1.1" 200 2037 0.015839 /var/log/glance/api.log:2024-09-12 16:00:54.195 3622 DEBUG glance.api.middleware.version_negotiation [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Determining version of request: GET /v2/schemas/image Accept: */* process_request /usr/lib/python3.9/site-packages/glance/api/middleware/version_negotiation.py:44 /var/log/glance/api.log:2024-09-12 16:00:54.195 3622 DEBUG glance.api.middleware.version_negotiation [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Using url versioning process_request /usr/lib/python3.9/site-packages/glance/api/middleware/version_negotiation.py:57 /var/log/glance/api.log:2024-09-12 16:00:54.196 3622 DEBUG glance.api.middleware.version_negotiation [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Matched version: v2 process_request /usr/lib/python3.9/site-packages/glance/api/middleware/version_negotiation.py:69 /var/log/glance/api.log:2024-09-12 16:00:54.196 3622 DEBUG glance.api.middleware.version_negotiation [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] new path /v2/schemas/image process_request /usr/lib/python3.9/site-packages/glance/api/middleware/version_negotiation.py:70 /var/log/glance/api.log:2024-09-12 16:00:54.199 3622 INFO eventlet.wsgi.server [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] 10.61.157.80 - - [12/Sep/2024 16:00:54] "GET /v2/schemas/image HTTP/1.1" 200 6283 0.004117 /var/log/nova/nova-api.log:2024-09-12 16:00:52.467 4059 DEBUG nova.api.openstack.wsgi [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Action: 'action', calling method: <bound method ServersController._action_create_image of <nova.api.openstack.compute.servers.ServersController object at 0x7fe02caee610>>, body: {"createImage": {"name": "cirrosinstance"}} _process_stack /usr/lib/python3.9/site-packages/nova/api/openstack/wsgi.py:511 /var/log/nova/nova-api.log:2024-09-12 16:00:52.478 4059 DEBUG nova.compute.api [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] [instance: 372d943f-f566-48e5-ab3c-da1773f7b8b6] Fetching instance by UUID get /usr/lib/python3.9/site-packages/nova/compute/api.py:2978 /var/log/nova/nova-api.log:2024-09-12 16:00:52.482 4059 DEBUG oslo_concurrency.lockutils [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Acquiring lock "d3f08bea-8e00-4a4d-b90f-adf8de60f882" by "nova.context.set_target_cell.<locals>.get_or_set_cached_cell_and_set_connections" inner /usr/lib/python3.9/site-packages/oslo_concurrency/lockutils.py:404 /var/log/nova/nova-api.log:2024-09-12 16:00:52.483 4059 DEBUG oslo_concurrency.lockutils [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Lock "d3f08bea-8e00-4a4d-b90f-adf8de60f882" acquired by "nova.context.set_target_cell.<locals>.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python3.9/site-packages/oslo_concurrency/lockutils.py:409 /var/log/nova/nova-api.log:2024-09-12 16:00:52.483 4059 DEBUG oslo_concurrency.lockutils [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Lock "d3f08bea-8e00-4a4d-b90f-adf8de60f882" "released" by "nova.context.set_target_cell.<locals>.get_or_set_cached_cell_and_set_connections" :: held 0.000s inner /usr/lib/python3.9/site-packages/oslo_concurrency/lockutils.py:423 /var/log/nova/nova-api.log:2024-09-12 16:00:52.484 4059 DEBUG oslo_concurrency.lockutils [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Acquiring lock "d3f08bea-8e00-4a4d-b90f-adf8de60f882" by "nova.context.set_target_cell.<locals>.get_or_set_cached_cell_and_set_connections" inner /usr/lib/python3.9/site-packages/oslo_concurrency/lockutils.py:404 /var/log/nova/nova-api.log:2024-09-12 16:00:52.485 4059 DEBUG oslo_concurrency.lockutils [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Lock "d3f08bea-8e00-4a4d-b90f-adf8de60f882" acquired by "nova.context.set_target_cell.<locals>.get_or_set_cached_cell_and_set_connections" :: waited 0.001s inner /usr/lib/python3.9/site-packages/oslo_concurrency/lockutils.py:409 /var/log/nova/nova-api.log:2024-09-12 16:00:52.485 4059 DEBUG oslo_concurrency.lockutils [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] Lock "d3f08bea-8e00-4a4d-b90f-adf8de60f882" "released" by "nova.context.set_target_cell.<locals>.get_or_set_cached_cell_and_set_connections" :: held 0.001s inner /usr/lib/python3.9/site-packages/oslo_concurrency/lockutils.py:423 /var/log/nova/nova-api.log:2024-09-12 16:00:52.955 4059 INFO nova.compute.api [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] [instance: 372d943f-f566-48e5-ab3c-da1773f7b8b6] Attempting to quiesce instance before volume snapshot. /var/log/nova/nova-api.log:2024-09-12 16:00:52.976 4059 INFO nova.compute.api [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] [instance: 372d943f-f566-48e5-ab3c-da1773f7b8b6] Skipping quiescing instance: QEMU guest agent is not enabled. /var/log/nova/nova-api.log:2024-09-12 16:00:53.025 4059 DEBUG nova.compute.api [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] [instance: 372d943f-f566-48e5-ab3c-da1773f7b8b6] Creating snapshot from volume 0aaa3dfe-ba0e-4306-b37a-10d847b1c264. snapshot_instance /usr/lib/python3.9/site-packages/nova/compute/api.py:3512 /var/log/nova/nova-api.log:2024-09-12 16:00:54.203 4059 INFO nova.api.openstack.requestlog [None req-c2de5695-40eb-42c6-8b8b-b5278b222da7 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - default default] 10.61.157.80 "POST /v2.1/servers/372d943f-f566-48e5-ab3c-da1773f7b8b6/action" status: 202 len: 52 microversion: 2.45 time: 1.899570 As you can see there are only two logs with an ERROR state, and both appear to be related to identity as you mentioned: /var/log/cinder/volume.log:2024-09-12 16:00:55.713 3607 ERROR cinder.volume.drivers.remotefs [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Call to Nova to create snapshot failed: keystoneauth1.exceptions.http.BadRequest: Expecting to find domain in project. The server could not comply with the request since it is either malformed or otherwise incorrect. The client is assumed to be in error. (HTTP 400) (Request-ID: req-6cc2a596-b980-43b9-b3dc-5eff336a4949) /var/log/cinder/volume.log:2024-09-12 16:00:55.730 3607 ERROR oslo_messaging.rpc.server [req-c2de5695-40eb-42c6-8b8b-b5278b222da7 req-07ccc3d6-dbfd-4ef4-b11a-253c44cba180 956bef8f3ca34d9bbb5b3bb8876890fd b3001e31df2947e78c5fda1e0d8479b0 - - - -] Exception during message handling: keystoneauth1.exceptions.http.BadRequest: Expecting to find domain in project. The server could not comply with the request since it is either malformed or otherwise incorrect. The client is assumed to be in error. (HTTP 400) (Request-ID: req-6cc2a596-b980-43b9-b3dc-5eff336a4949) I did some digging, and found a few sites that talk about needing to have these set (which I already do) export OS_PROJECT_DOMAIN_NAME=Default export OS_IDENTITY_API_VERSION=3 I thought it might be a case sensitivity thing, as the domain listed for each user from the openstack user list --long command is "default". . .But I changed that in my sourced file for authentication, and re-authenticated, and that didn't make any difference Where else should I look? Thanks again for all your help!