glance image-import failure with all-stores

Bug #2025653 reported by Simon Dodsley
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Glance
Invalid
Undecided
Unassigned

Bug Description

devstack build of master from 6/30/23

Glance is configured with 3 cinder stores and an image has been uploaded to one of these stores.

When trying to copy the image to all the stores image-import fails with logged error of:

    glance_store.exceptions.StoreAddDisabled: Configuration for store failed. Adding images to this store is disabled.

Command issued was:

   glance image-import 7934ed5e-9958-47e2-9a6a-5aab9a33dfca --all-stores true --import-method copy-image

Image information:

stack@multi1:~$ glance image-show 7934ed5e-9958-47e2-9a6a-5aab9a33dfca
+----------------------------------+----------------------------------------------------------------------------------+
| Property | Value |
+----------------------------------+----------------------------------------------------------------------------------+
| checksum | a3bf59112e4930ef32397be81c761a80 |
| container_format | bare |
| created_at | 2023-06-30T16:32:14Z |
| disk_format | raw |
| id | 7934ed5e-9958-47e2-9a6a-5aab9a33dfca |
| locations | [{"url": "cinder://pure2/7f299476-9245-4648-9e2e-a9cca62f9354", "metadata": |
| | {"store": "pure2"}}] |
| min_disk | 0 |
| min_ram | 0 |
| name | Ubuntu 22.04 (on pure2) |
| os_glance_failed_import | |
| os_glance_importing_to_stores | pure1,pure3 |
| os_hash_algo | sha512 |
| os_hash_value | 0bbfdb7382c8767f60d8bb6da703819dc6fdaef36e6e544740eb5fffcb677d11ba23c3eed9e885b8 |
| | b82d8444a7adcfd8712c2dc4dcb8f9589f5a9787a6879aa1 |
| os_hidden | False |
| owner | 6f9ddcf4d9f148789b03a20447a39f8c |
| owner_specified.openstack.md5 | |
| owner_specified.openstack.object | images/Ubuntu 22.04 |
| owner_specified.openstack.sha256 | |
| protected | False |
| size | 2361393152 |
| status | active |
| stores | pure2 |
| tags | [] |
| updated_at | 2023-07-03T13:46:25Z |
| virtual_size | 2361393152 |
| visibility | public |
+----------------------------------+----------------------------------------------------------------------------------+

Glance stores information:

stack@multi1:~$ glance stores-info
+----------+----------------------------------------------------------------------------------+
| Property | Value |
+----------+----------------------------------------------------------------------------------+
| stores | [{"id": "pure1", "description": "Pure Array 1"}, {"id": "pure2", "description": |
| | "Pure Array 2", "default": "true"}, {"id": "pure3", "description": "Pure"}] |
+----------+----------------------------------------------------------------------------------+

Full logfile extract for the command, including traceback:

Jul 03 13:46:24 multi1 <email address hidden>[1317056]: DEBUG glance.api.v2.images [None req-73d6a2cb-b73c-4193-ad65-9d76e58f1e60 admin admin] Removing store 'pure2' from all stores as image is already available in that store. {{(pid=1317056) import_image /opt/stack/glance/glance/api/v2/images.py:404}}
Jul 03 13:46:24 multi1 <email address hidden>[1317056]: DEBUG glance.domain [None req-73d6a2cb-b73c-4193-ad65-9d76e58f1e60 admin admin] Loading taskflow executor {{(pid=1317056) new_task_executor /opt/stack/glance/glance/domain/__init__.py:530}}
Jul 03 13:46:25 multi1 <email address hidden>[1317056]: DEBUG oslo_concurrency.lockutils [None req-73d6a2cb-b73c-4193-ad65-9d76e58f1e60 admin admin] Acquiring lock "tasks_pool" by "glance.api.common.memoize.<locals>.memoizer_wrapper.<locals>.memoizer" {{(pid=1317056) inner /usr/local/lib/python3.10/dist-packages/oslo_concurrency/lockutils.py:404}}
Jul 03 13:46:25 multi1 <email address hidden>[1317056]: DEBUG oslo_concurrency.lockutils [None req-73d6a2cb-b73c-4193-ad65-9d76e58f1e60 admin admin] Lock "tasks_pool" acquired by "glance.api.common.memoize.<locals>.memoizer_wrapper.<locals>.memoizer" :: waited 0.001s {{(pid=1317056) inner /usr/local/lib/python3.10/dist-packages/oslo_concurrency/lockutils.py:409}}
Jul 03 13:46:25 multi1 <email address hidden>[1317056]: DEBUG glance.api.common [None req-73d6a2cb-b73c-4193-ad65-9d76e58f1e60 admin admin] Initializing named threadpool 'tasks_pool' {{(pid=1317056) _get_thread_pool /opt/stack/glance/glance/api/common.py:232}}
Jul 03 13:46:25 multi1 <email address hidden>[1317056]: DEBUG glance.async_ [None req-73d6a2cb-b73c-4193-ad65-9d76e58f1e60 admin admin] Creating threadpool model 'ThreadPoolExecutor' with size 16 {{(pid=1317056) __init__ /opt/stack/glance/glance/async_/__init__.py:100}}
Jul 03 13:46:25 multi1 <email address hidden>[1317056]: DEBUG oslo_concurrency.lockutils [None req-73d6a2cb-b73c-4193-ad65-9d76e58f1e60 admin admin] Lock "tasks_pool" "released" by "glance.api.common.memoize.<locals>.memoizer_wrapper.<locals>.memoizer" :: held 0.001s {{(pid=1317056) inner /usr/local/lib/python3.10/dist-packages/oslo_concurrency/lockutils.py:423}}
Jul 03 13:46:25 multi1 <email address hidden>[1317056]: DEBUG glance.async_ [None req-73d6a2cb-b73c-4193-ad65-9d76e58f1e60 admin admin] Spawning with ThreadPoolExecutor: <bound method TaskProxy.run of <glance.notifier.TaskProxy object at 0x7ff7e2b01d80>>((<glance.async_.taskflow_executor.TaskExecutor object at 0x7ff7e3d20160>,), {}) {{(pid=1317056) spawn /opt/stack/glance/glance/async_/__init__.py:106}}
Jul 03 13:46:25 multi1 <email address hidden>[1317056]: [pid: 1317056|app: 0|req: 3/5] 127.0.0.1 () {40 vars in 798 bytes} [Mon Jul 3 13:46:24 2023] POST /v2/images/7934ed5e-9958-47e2-9a6a-5aab9a33dfca/import => generated 0 bytes in 1121 msecs (HTTP/1.1 202) 4 headers in 169 bytes (1 switches on core 0)
Jul 03 13:46:25 multi1 <email address hidden>[1317057]: DEBUG glance.api.middleware.version_negotiation [None req-6af47ed9-c017-435e-b9f7-dcfa8c05b1ef admin admin] Determining version of request: GET /v2/images/7934ed5e-9958-47e2-9a6a-5aab9a33dfca Accept: */* {{(pid=1317057) process_request /opt/stack/glance/glance/api/middleware/version_negotiation.py:44}}
Jul 03 13:46:25 multi1 <email address hidden>[1317057]: DEBUG glance.api.middleware.version_negotiation [None req-6af47ed9-c017-435e-b9f7-dcfa8c05b1ef admin admin] Using url versioning {{(pid=1317057) process_request /opt/stack/glance/glance/api/middleware/version_negotiation.py:57}}
Jul 03 13:46:25 multi1 <email address hidden>[1317057]: DEBUG glance.api.middleware.version_negotiation [None req-6af47ed9-c017-435e-b9f7-dcfa8c05b1ef admin admin] Matched version: v2 {{(pid=1317057) process_request /opt/stack/glance/glance/api/middleware/version_negotiation.py:69}}
Jul 03 13:46:25 multi1 <email address hidden>[1317056]: INFO glance.domain [-] Task [ddce12c3-943b-4dd7-bec3-5c0e787dd38b] status changing from pending to processing
Jul 03 13:46:25 multi1 <email address hidden>[1317057]: DEBUG glance.api.middleware.version_negotiation [None req-6af47ed9-c017-435e-b9f7-dcfa8c05b1ef admin admin] new path /v2/images/7934ed5e-9958-47e2-9a6a-5aab9a33dfca {{(pid=1317057) process_request /opt/stack/glance/glance/api/middleware/version_negotiation.py:70}}
Jul 03 13:46:25 multi1 <email address hidden>[1317056]: DEBUG glance.async_.taskflow_executor [-] Taskflow executor picked up the execution of task ID ddce12c3-943b-4dd7-bec3-5c0e787dd38b of task type api_image_import {{(pid=1317056) _run /opt/stack/glance/glance/async_/taskflow_executor.py:160}}
Jul 03 13:46:25 multi1 <email address hidden>[1317056]: DEBUG glance.async_.flows.api_image_import [-] Skipping plugins on 'copy-image' job. {{(pid=1317056) get_flow /opt/stack/glance/glance/async_/flows/api_image_import.py:963}}
Jul 03 13:46:25 multi1 <email address hidden>[1317056]: DEBUG glance.async_.flows.api_image_import [-] Image 7934ed5e-9958-47e2-9a6a-5aab9a33dfca os_glance_importing_to_stores=pure1,pure3,pure4 {{(pid=1317056) merge_store_list /opt/stack/glance/glance/async_/flows/api_image_import.py:278}}
Jul 03 13:46:25 multi1 <email address hidden>[1317056]: DEBUG glance.async_.flows.api_image_import [-] Stores pure1,pure3 not in os_glance_failed_import for image 7934ed5e-9958-47e2-9a6a-5aab9a33dfca {{(pid=1317056) merge_store_list /opt/stack/glance/glance/async_/flows/api_image_import.py:266}}
Jul 03 13:46:25 multi1 <email address hidden>[1317056]: DEBUG glance.async_.flows.api_image_import [-] Image 7934ed5e-9958-47e2-9a6a-5aab9a33dfca os_glance_failed_import= {{(pid=1317056) merge_store_list /opt/stack/glance/glance/async_/flows/api_image_import.py:278}}
Jul 03 13:46:25 multi1 <email address hidden>[1317057]: INFO dbcounter [None req-28d2c86a-16c5-4d74-b89b-89907c91bde2 admin admin] Registered counter for database glance
Jul 03 13:46:25 multi1 <email address hidden>[1317056]: DEBUG glance_store.multi_backend [-] Skipping store.set_acls... not implemented {{(pid=1317056) set_acls_for_multi_store /usr/local/lib/python3.10/dist-packages/glance_store/multi_backend.py:548}}
Jul 03 13:46:25 multi1 <email address hidden>[1317057]: DEBUG oslo_db.sqlalchemy.engines [None req-28d2c86a-16c5-4d74-b89b-89907c91bde2 admin admin] MySQL server mode set to STRICT_TRANS_TABLES,STRICT_ALL_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,TRADITIONAL,NO_ENGINE_SUBSTITUTION {{(pid=1317057) _check_effective_sql_mode /usr/local/lib/python3.10/dist-packages/oslo_db/sqlalchemy/engines.py:335}}
Jul 03 13:46:25 multi1 <email address hidden>[1317057]: DEBUG dbcounter [-] [1317057] Writer thread running {{(pid=1317057) stat_writer /usr/local/lib/python3.10/dist-packages/dbcounter.py:102}}
Jul 03 13:46:25 multi1 <email address hidden>[1317057]: [pid: 1317057|app: 0|req: 3/6] 127.0.0.1 () {38 vars in 771 bytes} [Mon Jul 3 13:46:25 2023] GET /v2/images/7934ed5e-9958-47e2-9a6a-5aab9a33dfca => generated 1218 bytes in 207 msecs (HTTP/1.1 200) 4 headers in 158 bytes (1 switches on core 0)
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: DEBUG glance.async_ [-] Creating threadpool model 'ThreadPoolExecutor' with size 10 {{(pid=1317056) __init__ /opt/stack/glance/glance/async_/__init__.py:100}}
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: DEBUG glance.async_.taskflow_executor [-] Flow 'api_image_import' (9caae932-939f-407c-8a00-b93248e06676) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=1317056) _flow_receiver /usr/local/lib/python3.10/dist-packages/taskflow/listeners/logging.py:141}}
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: DEBUG glance.async_.taskflow_executor [-] Task 'api_image_import-ImageLock-ddce12c3-943b-4dd7-bec3-5c0e787dd38b' (dc32edb3-4866-4a02-8daf-f13081bd062c) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=1317056) _task_receiver /usr/local/lib/python3.10/dist-packages/taskflow/listeners/logging.py:190}}
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: DEBUG glance.async_.flows.api_image_import [-] Image 7934ed5e-9958-47e2-9a6a-5aab9a33dfca import task ddce12c3-943b-4dd7-bec3-5c0e787dd38b lock confirmed {{(pid=1317056) execute /opt/stack/glance/glance/async_/flows/api_image_import.py:478}}
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: DEBUG glance.async_.taskflow_executor [-] Task 'api_image_import-ImageLock-ddce12c3-943b-4dd7-bec3-5c0e787dd38b' (dc32edb3-4866-4a02-8daf-f13081bd062c) transitioned into state 'SUCCESS' from state 'RUNNING' with result 'None' {{(pid=1317056) _task_receiver /usr/local/lib/python3.10/dist-packages/taskflow/listeners/logging.py:178}}
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: DEBUG glance.async_.taskflow_executor [-] Task 'api_image_import-CopyImage-ddce12c3-943b-4dd7-bec3-5c0e787dd38b' (bff3ab85-19c6-4ead-960b-7bf58c1a38aa) transitioned into state 'RUNNING' from state 'PENDING' {{(pid=1317056) _task_receiver /usr/local/lib/python3.10/dist-packages/taskflow/listeners/logging.py:190}}
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: DEBUG glance_store._drivers.cinder.store [-] Cinderclient connection created for user glance using URL: http://10.21.200.135/identity. {{(pid=1317056) get_cinderclient /usr/local/lib/python3.10/dist-packages/glance_store/_drivers/cinder/store.py:632}}
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: DEBUG glance.async_.flows._internal_plugins.copy_image [-] Found image, copying it in staging area {{(pid=1317056) _copy_to_staging_store /opt/stack/glance/glance/async_/flows/_internal_plugins/copy_image.py:121}}
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: WARNING glance.async_.taskflow_executor [-] Task 'api_image_import-CopyImage-ddce12c3-943b-4dd7-bec3-5c0e787dd38b' (bff3ab85-19c6-4ead-960b-7bf58c1a38aa) transitioned into state 'FAILURE' from state 'RUNNING'
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: 4 predecessors (most recent first):
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: Flow 'api_image_import'
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: |__Atom 'api_image_import-ImageLock-ddce12c3-943b-4dd7-bec3-5c0e787dd38b' {'intention': 'EXECUTE', 'state': 'SUCCESS', 'requires': {}, 'provides': None}
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: |__Atom 'api_image_import_retry' {'intention': 'EXECUTE', 'state': 'SUCCESS', 'requires': {}, 'provides': [(None, {})]}
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: |__Flow 'api_image_import': glance_store.exceptions.StoreAddDisabled: Configuration for store failed. Adding images to this store is disabled.
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: ERROR glance.async_.taskflow_executor Traceback (most recent call last):
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: ERROR glance.async_.taskflow_executor File "/usr/local/lib/python3.10/dist-packages/taskflow/engines/action_engine/executor.py", line 52, in _execute_task
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: ERROR glance.async_.taskflow_executor result = task.execute(**arguments)
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: ERROR glance.async_.taskflow_executor File "/opt/stack/glance/glance/async_/flows/_internal_plugins/copy_image.py", line 50, in execute
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: ERROR glance.async_.taskflow_executor return self._execute(action)
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: ERROR glance.async_.taskflow_executor File "/opt/stack/glance/glance/async_/flows/_internal_plugins/copy_image.py", line 92, in _execute
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: ERROR glance.async_.taskflow_executor return self._copy_to_staging_store(loc)
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: ERROR glance.async_.taskflow_executor File "/opt/stack/glance/glance/async_/flows/_internal_plugins/copy_image.py", line 122, in _copy_to_staging_store
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: ERROR glance.async_.taskflow_executor return self.staging_store.add(self.image_id, image_data, size)[0]
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: ERROR glance.async_.taskflow_executor File "/usr/local/lib/python3.10/dist-packages/glance_store/driver.py", line 294, in add_adapter
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: ERROR glance.async_.taskflow_executor metadata_dict) = store_add_fun(*args, **kwargs)
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: ERROR glance.async_.taskflow_executor File "/usr/local/lib/python3.10/dist-packages/glance_store/capabilities.py", line 174, in op_checker
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: ERROR glance.async_.taskflow_executor raise op_exec_map[op](**kwargs)
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: ERROR glance.async_.taskflow_executor glance_store.exceptions.StoreAddDisabled: Configuration for store failed. Adding images to this store is disabled.
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: ERROR glance.async_.taskflow_executor
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: DEBUG glance.async_.taskflow_executor [-] Task 'api_image_import-CopyImage-ddce12c3-943b-4dd7-bec3-5c0e787dd38b' (bff3ab85-19c6-4ead-960b-7bf58c1a38aa) transitioned into state 'REVERTING' from state 'FAILURE' {{(pid=1317056) _task_receiver /usr/local/lib/python3.10/dist-packages/taskflow/listeners/logging.py:190}}
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: ERROR glance.async_.flows._internal_plugins.copy_image [-] Task: ddce12c3-943b-4dd7-bec3-5c0e787dd38b failed to copy image 7934ed5e-9958-47e2-9a6a-5aab9a33dfca.
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: WARNING glance.async_.taskflow_executor [-] Task 'api_image_import-CopyImage-ddce12c3-943b-4dd7-bec3-5c0e787dd38b' (bff3ab85-19c6-4ead-960b-7bf58c1a38aa) transitioned into state 'REVERTED' from state 'REVERTING' with result 'None'
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: DEBUG glance.async_.taskflow_executor [-] Task 'api_image_import-ImageLock-ddce12c3-943b-4dd7-bec3-5c0e787dd38b' (dc32edb3-4866-4a02-8daf-f13081bd062c) transitioned into state 'REVERTING' from state 'SUCCESS' {{(pid=1317056) _task_receiver /usr/local/lib/python3.10/dist-packages/taskflow/listeners/logging.py:190}}
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: DEBUG glance.async_.flows.api_image_import [-] Image 7934ed5e-9958-47e2-9a6a-5aab9a33dfca import task ddce12c3-943b-4dd7-bec3-5c0e787dd38b dropped its lock after failure {{(pid=1317056) revert /opt/stack/glance/glance/async_/flows/api_image_import.py:497}}
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: WARNING glance.async_.taskflow_executor [-] Task 'api_image_import-ImageLock-ddce12c3-943b-4dd7-bec3-5c0e787dd38b' (dc32edb3-4866-4a02-8daf-f13081bd062c) transitioned into state 'REVERTED' from state 'REVERTING' with result 'None'
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: WARNING glance.async_.taskflow_executor [-] Flow 'api_image_import' (9caae932-939f-407c-8a00-b93248e06676) transitioned into state 'REVERTED' from state 'RUNNING'
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: ERROR glance.async_.taskflow_executor [-] Failed to execute task ddce12c3-943b-4dd7-bec3-5c0e787dd38b: Configuration for store failed. Adding images to this store is disabled.: glance_store.exceptions.StoreAddDisabled: Configuration for store failed. Adding images to this store is disabled.
Jul 03 13:46:26 multi1 <email address hidden>[1317056]: INFO glance.domain [-] Task [ddce12c3-943b-4dd7-bec3-5c0e787dd38b] status changing from processing to failure
Jul 03 13:46:35 multi1 <email address hidden>[1317057]: DEBUG dbcounter [-] [1317057] Writing DB stats glance:SELECT=5 {{(pid=1317057) stat_writer /usr/local/lib/python3.10/dist-packages/dbcounter.py:117}}
Jul 03 13:46:36 multi1 <email address hidden>[1317056]: DEBUG dbcounter [-] [1317056] Writing DB stats glance:SELECT=74,glance:UPDATE=6,glance:INSERT=3,glance:DELETE=1 {{(pid=1317056) stat_writer /usr/local/lib/python3.10/dist-packages/dbcounter.py:117}}

Revision history for this message
Simon Dodsley (simon-dodsley) wrote :

My bad - failed to configure the staging area for multistore glance

Please ignore

Changed in glance:
status: New → Invalid
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.