Bug 1119879 - Image could not be found after upload when ceph backend
Summary: Image could not be found after upload when ceph backend
Keywords:
Status: CLOSED UPSTREAM
Alias: None
Product: Red Hat OpenStack
Classification: Red Hat
Component: openstack-cinder
Version: 5.0 (RHEL 7)
Hardware: Unspecified
OS: Unspecified
unspecified
high
Target Milestone: ---
: 5.0 (RHEL 7)
Assignee: Eric Harney
QA Contact: nlevinki
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2014-07-15 17:53 UTC by bkopilov
Modified: 2016-04-27 04:21 UTC (History)
4 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2014-07-16 16:03:23 UTC


Attachments (Terms of Use)
/var/log and /etc/ logs from automation (9.03 MB, application/gzip)
2014-07-15 17:53 UTC, bkopilov
no flags Details

Description bkopilov 2014-07-15 17:53:58 UTC
Created attachment 918210 [details]
/var/log and /etc/ logs from automation

Description of problem:
ALL in one setup.
Ceph backend configured for glance and cinder at the same time .
Running automation tests tempest code .

failed tests :
tempest.api.volume.test_volumes_actions.VolumesActionsTest.test_volume_upload


From volume logs :
Encoding: chunked' -H 'X-Auth-Token: MIIPigYJKoZIhvcNAQcCoIIPezCCD3cCAQExCTAHBgUrDgMCGjCCDeAGCSqGSIb3DQEHAaCCDdEEgg3NeyJhY2Nlc3MiOiB7InRva2VuIjogeyJpc3N1ZWRfYXQiOiAiMjAxNC0wNy0xNVQxNDoxMTo0OC44NTAzNzQiLCAiZXhwaXJlcyI6ICIyMDE0LTA3LTE1VDE1OjExOjQ4WiIsICJpZCI6ICJwbGFjZWhvbGRlciIsICJ0ZW5hbnQiOiB7ImRlc2NyaXB0aW9uIjogIlZvbHVtZXNBY3Rpb25zVGVzdFhNTC0xMDk1MzU0NjUzLWRlc2MiLCAiZW5hYmxlZCI6IHRydWUsICJpZCI6ICI4ZDQ0ZDNjMGIxMTE0NjIxYjMwNjUzY2I0OTA2M2Q5OSIsICJuYW1lIjogIlZvbHVtZXNBY3Rpb25zVGVzdFhNTC0xMDk1MzU0NjUzIn19LCAic2VydmljZUNhdGFsb2ciOiBbeyJlbmRwb2ludHMiOiBbeyJhZG1pblVSTCI6ICJodHRwOi8vMTkyLjE2OC4yLjIwOjg3NzQvdjIvOGQ0NGQzYzBiMTExNDYyMWIzMDY1M2NiNDkwNjNkOTkiLCAicmVnaW9uIjogIlJlZ2lvbk9uZSIsICJpbnRlcm5hbFVSTCI6ICJodHRwOi8vMTkyLjE2OC4yLjIwOjg3NzQvdjIvOGQ0NGQzYzBiMTExNDYyMWIzMDY1M2NiNDkwNjNkOTkiLCAiaWQiOiAiMTU4OGUwMjhmM2YzNGJhMmI1NGQ2ZjBjNmNmOTQzMmYiLCAicHVibGljVVJMIjogImh0dHA6Ly8xOTIuMTY4LjIuMjA6ODc3NC92Mi84ZDQ0ZDNjMGIxMTE0NjIxYjMwNjUzY2I0OTA2M2Q5OSJ9XSwgImVuZHBvaW50c19saW5rcyI6IFtdLCAidHlwZSI6ICJjb21wdXRlIiwgIm5hbWUiOiAibm92YSJ9LCB7ImVuZHBvaW50cyI6IFt7ImFkbWluVVJMIjogImh0dHA6Ly8xOTIuMTY4LjIuMjA6OTY5Ni8iLCAicmVnaW9uIjogIlJlZ2lvbk9uZSIsICJpbnRlcm5hbFVSTCI6ICJodHRwOi8vMTkyLjE2OC4yLjIwOjk2OTYvIiwgImlkIjogIjNmY2U3NWY2ODk5MjRkMTlhMDBkN2M1ZThjNjUzNzM4IiwgInB1YmxpY1VSTCI6ICJodHRwOi8vMTkyLjE2OC4yLjIwOjk2OTYvIn1dLCAiZW5kcG9pbnRzX2xpbmtzIjogW10sICJ0eXBlIjogIm5ldHdvcmsiLCAibmFtZSI6ICJuZXV0cm9uIn0sIHsiZW5kcG9pbnRzIjogW3siYWRtaW5VUkwiOiAiaHR0cDovLzE5Mi4xNjguMi4yMDo4Nzc2L3YyLzhkNDRkM2MwYjExMTQ2MjFiMzA2NTNjYjQ5MDYzZDk5IiwgInJlZ2lvbiI6ICJSZWdpb25PbmUiLCAiaW50ZXJuYWxVUkwiOiAiaHR0cDovLzE5Mi4xNjguMi4yMDo4Nzc2L3YyLzhkNDRkM2MwYjExMTQ2MjFiMzA2NTNjYjQ5MDYzZDk5IiwgImlkIjogIjVlYzMwMTNmMTczMjRkODE5MjgzMmExYzE3YWMxNzJmIiwgInB1YmxpY1VSTCI6ICJodHRwOi8vMTkyLjE2OC4yLjIwOjg3NzYvdjIvOGQ0NGQzYzBiMTExNDYyMWIzMDY1M2NiNDkwNjNkOTkifV0sICJlbmRwb2ludHNfbGlua3MiOiBbXSwgInR5cGUiOiAidm9sdW1ldjIiLCAibmFtZSI6ICJjaW5kZXJfdjIifSwgeyJlbmRwb2ludHMiOiBbeyJhZG1pblVSTCI6ICJodHRwOi8vMTkyLjE2OC4yLjIwOjgwODAiLCAicmVnaW9uIjogIlJlZ2lvbk9uZSIsICJpbnRlcm5hbFVSTCI6ICJodHRwOi8vMTkyLjE2OC4yLjIwOjgwODAiLCAiaWQiOiAiNGRiMGRlZTExOGI0NGRhYjliM2ExM2UzNTViNGViOTUiLCAicHVibGljVVJMIjogImh0dHA6Ly8xOTIuMTY4LjIuMjA6ODA4MCJ9XSwgImVuZHBvaW50c19saW5rcyI6IFtdLCAidHlwZSI6ICJzMyIsICJuYW1lIjogInN3aWZ0X3MzIn0sIHsiZW5kcG9pbnRzIjogW3siYWRtaW5VUkwiOiAiaHR0cDovLzE5Mi4xNjguMi4yMDo5MjkyIiwgInJlZ2lvbiI6ICJSZWdpb25PbmUiLCAiaW50ZXJuYWxVUkwiOiAiaHR0cDovLzE5Mi4xNjguMi4yMDo5MjkyIiwgImlkIjogIjIxMmRkMThkZGRlNDQ4ODNiYTExYmFhMTAxNTNhNTgwIiwgInB1YmxpY1VSTCI6ICJodHRwOi8vMTkyLjE2OC4yLjIwOjkyOTIifV0sICJlbmRwb2ludHNfbGlua3MiOiBbXSwgInR5cGUiOiAiaW1hZ2UiLCAibmFtZSI6ICJnbGFuY2UifSwgeyJlbmRwb2ludHMiOiBbeyJhZG1pblVSTCI6ICJodHRwOi8vMTkyLjE2OC4yLjIwOjg3NzYvdjEvOGQ0NGQzYzBiMTExNDYyMWIzMDY1M2NiNDkwNjNkOTkiLCAicmVnaW9uIjogIlJlZ2lvbk9uZSIsICJpbnRlcm5hbFVSTCI6ICJodHRwOi8vMTkyLjE2OC4yLjIwOjg3NzYvdjEvOGQ0NGQzYzBiMTExNDYyMWIzMDY1M2NiNDkwNjNkOTkiLCAiaWQiOiAiMGNkODYwYWQ1ZWM4NGM4YjlmMTVhOWYzMTNiNmI3ZjMiLCAicHVibGljVVJMIjogImh0dHA6Ly8xOTIuMTY4LjIuMjA6ODc3Ni92MS84ZDQ0ZDNjMGIxMTE0NjIxYjMwNjUzY2I0OTA2M2Q5OSJ9XSwgImVuZHBvaW50c19saW5rcyI6IFtdLCAidHlwZSI6ICJ2b2x1bWUiLCAibmFtZSI6ICJjaW5kZXIifSwgeyJlbmRwb2ludHMiOiBbeyJhZG1pblVSTCI6ICJodHRwOi8vMTkyLjE2OC4yLjIwOjg3NzMvc2VydmljZXMvQWRtaW4iLCAicmVnaW9uIjogIlJlZ2lvbk9uZSIsICJpbnRlcm5hbFVSTCI6ICJodHRwOi8vMTkyLjE2OC4yLjIwOjg3NzMvc2VydmljZXMvQ2xvdWQiLCAiaWQiOiAiMDhkMGY4ZTA0NTJkNGMxNDk2ZGEzZDg0ZjNiNzhjYWQiLCAicHVibGljVVJMIjogImh0dHA6Ly8xOTIuMTY4LjIuMjA6ODc3My9zZXJ2aWNlcy9DbG91ZCJ9XSwgImVuZHBvaW50c19saW5rcyI6IFtdLCAidHlwZSI6ICJlYzIiLCAibmFtZSI6ICJub3ZhX2VjMiJ9LCB7ImVuZHBvaW50cyI6IFt7ImFkbWluVVJMIjogImh0dHA6Ly8xOTIuMTY4LjIuMjA6ODA4MC8iLCAicmVnaW9uIjogIlJlZ2lvbk9uZSIsICJpbnRlcm5hbFVSTCI6ICJodHRwOi8vMTkyLjE2OC4yLjIwOjgwODAvdjEvQVVUSF84ZDQ0ZDNjMGIxMTE0NjIxYjMwNjUzY2I0OTA2M2Q5OSIsICJpZCI6ICIwNmZhNjM5MDM4ZGM0YzY4OTkxZjQzMTA2NzVkMDYxMyIsICJwdWJsaWNVUkwiOiAiaHR0cDovLzE5Mi4xNjguMi4yMDo4MDgwL3YxL0FVVEhfOGQ0NGQzYzBiMTExNDYyMWIzMDY1M2NiNDkwNjNkOTkifV0sICJlbmRwb2ludHNfbGlua3MiOiBbXSwgInR5cGUiOiAib2JqZWN0LXN0b3JlIiwgIm5hbWUiOiAic3dpZnQifSwgeyJlbmRwb2ludHMiOiBbeyJhZG1pblVSTCI6ICJodHRwOi8vMTkyLjE2OC4yLjIwOjM1MzU3L3YyLjAiLCAicmVnaW9uIjogIlJlZ2lvbk9uZSIsICJpbnRlcm5hbFVSTCI6ICJodHRwOi8vMTkyLjE2OC4yLjIwOjUwMDAvdjIuMCIsICJpZCI6ICIyNDE4NDVlMjI5ZmE0ZjM4ODNmYTg5ZmYyMzIwNmExOSIsICJwdWJsaWNVUkwiOiAiaHR0cDovLzE5Mi4xNjguMi4yMDo1MDAwL3YyLjAifV0sICJlbmRwb2ludHNfbGlua3MiOiBbXSwgInR5cGUiOiAiaWRlbnRpdHkiLCAibmFtZSI6ICJrZXlzdG9uZSJ9XSwgInVzZXIiOiB7InVzZXJuYW1lIjogIlZvbHVtZXNBY3Rpb25zVGVzdFhNTC0xMTQ4NjU4NTU0IiwgInJvbGVzX2xpbmtzIjogW10sICJpZCI6ICI4ZTE4NWE2MDU1ZDk0NWM5ODA5OGU3MTUxMTM3YjUyZCIsICJyb2xlcyI6IFt7Im5hbWUiOiAiX21lbWJlcl8ifSwgeyJuYW1lIjogIlN3aWZ0T3BlcmF0b3IifV0sICJuYW1lIjogIlZvbHVtZXNBY3Rpb25zVGVzdFhNTC0xMTQ4NjU4NTU0In0sICJtZXRhZGF0YSI6IHsiaXNfYWRtaW4iOiAwLCAicm9sZXMiOiBbIjlmZTJmZjllZTQzODRiMTg5NGE5MDg3OGQzZTkyYmFiIiwgIjcyNTYzZTEzZTQxNDQ2MzA4ZGQ4YTc1NDk1ZTAyNDNjIl19fX0xggGBMIIBfQIBATBcMFcxCzAJBgNVBAYTAlVTMQ4wDAYDVQQIDAVVbnNldDEOMAwGA1UEBwwFVW5zZXQxDjAMBgNVBAoMBVVuc2V0MRgwFgYDVQQDDA93d3cuZXhhbXBsZS5jb20CAQEwBwYFKw4DAhowDQYJKoZIhvcNAQEBBQAEggEADEapCoqzgwAAnAoXW3SUFJuRrdhwGyXeoc+C4kLuIlJUUdZN8rNDr884lldwxlFmmJLDDTpcbSRuskttfciUy0UjeuaMi-SJQrAxiuvKaN-waKsf1UdafCHqNgQF+EuPDfqECpc6i66gNi3alzW2JkzoBcgk7ZndHZAxJ9MOZWD4fEgm2I0Gg0zQGRbmNEMJ6HoQDRIAsY6oogKhURoClE6Z8oAEsdfmK9Vxqa46r3g7Fe5UlTxEidTvN39GoI29waxicJ8nCzmlzBYmO01cYZf4T9KYTYmo3eURGXpSd9u+V9Cml3wiU577dSZ10p+sZvYfF0mCL0RGMKuBUmoLGA==' -H 'Content-Type: application/octet-stream' -H 'User-Agent: python-glanceclient' -d '<open file u'/tmp/volume-f3868ee2-9339-472c-81bc-3d54fd3a46d2-6931741c-53c2-43f5-9983-a8bbcf04bc40', mode 'r' at 0x3ba0540>' http://192.168.2.20:9292/v2/images/6931741c-53c2-43f5-9983-a8bbcf04bc40/file log_curl_request /usr/lib/python2.7/site-packages/glanceclient/common/http.py:142
2014-07-15 10:12:19.357 18558 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._publish_service_capabilities run_periodic_tasks /usr/lib/python2.7/site-packages/cinder/openstack/common/periodic_task.py:178
2014-07-15 10:12:19.358 18558 DEBUG cinder.manager [-] Notifying Schedulers of capabilities ... _publish_service_capabilities /usr/lib/python2.7/site-packages/cinder/manager.py:128
2014-07-15 10:12:19.372 18558 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._report_driver_status run_periodic_tasks /usr/lib/python2.7/site-packages/cinder/openstack/common/periodic_task.py:178
2014-07-15 10:12:19.372 18558 INFO cinder.volume.manager [-] Updating volume status
2014-07-15 10:13:19.358 18558 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._publish_service_capabilities run_periodic_tasks /usr/lib/python2.7/site-packages/cinder/openstack/common/periodic_task.py:178
2014-07-15 10:13:19.359 18558 DEBUG cinder.manager [-] Notifying Schedulers of capabilities ... _publish_service_capabilities /usr/lib/python2.7/site-packages/cinder/manager.py:128
2014-07-15 10:13:19.368 18558 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._report_driver_status run_periodic_tasks /usr/lib/python2.7/site-packages/cinder/openstack/common/periodic_task.py:178
2014-07-15 10:13:19.369 18558 INFO cinder.volume.manager [-] Updating volume status
2014-07-15 10:14:19.358 18558 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._publish_service_capabilities run_periodic_tasks /usr/lib/python2.7/site-packages/cinder/openstack/common/periodic_task.py:178
2014-07-15 10:14:19.359 18558 DEBUG cinder.manager [-] Notifying Schedulers of capabilities ... _publish_service_capabilities /usr/lib/python2.7/site-packages/cinder/manager.py:128
2014-07-15 10:14:19.367 18558 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._report_driver_status run_periodic_tasks /usr/lib/python2.7/site-packages/cinder/openstack/common/periodic_task.py:178
2014-07-15 10:14:19.367 18558 INFO cinder.volume.manager [-] Updating volume status
2014-07-15 10:15:19.359 18558 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._publish_service_capabilities run_periodic_tasks /usr/lib/python2.7/site-packages/cinder/openstack/common/periodic_task.py:178
2014-07-15 10:15:19.360 18558 DEBUG cinder.manager [-] Notifying Schedulers of capabilities ... _publish_service_capabilities /usr/lib/python2.7/site-packages/cinder/manager.py:128
2014-07-15 10:15:19.364 18558 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._report_driver_status run_periodic_tasks /usr/lib/python2.7/site-packages/cinder/openstack/common/periodic_task.py:178
2014-07-15 10:15:19.365 18558 INFO cinder.volume.manager [-] Updating volume status
2014-07-15 10:16:19.360 18558 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._publish_service_capabilities run_periodic_tasks /usr/lib/python2.7/site-packages/cinder/openstack/common/periodic_task.py:178
2014-07-15 10:16:19.360 18558 DEBUG cinder.manager [-] Notifying Schedulers of capabilities ... _publish_service_capabilities /usr/lib/python2.7/site-packages/cinder/manager.py:128
2014-07-15 10:16:19.371 18558 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._report_driver_status run_periodic_tasks /usr/lib/python2.7/site-packages/cinder/openstack/common/periodic_task.py:178
2014-07-15 10:16:19.372 18558 INFO cinder.volume.manager [-] Updating volume status
2014-07-15 10:17:19.360 18558 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._publish_service_capabilities run_periodic_tasks /usr/lib/python2.7/site-packages/cinder/openstack/common/periodic_task.py:178
2014-07-15 10:17:19.360 18558 DEBUG cinder.manager [-] Notifying Schedulers of capabilities ... _publish_service_capabilities /usr/lib/python2.7/site-packages/cinder/manager.py:128
2014-07-15 10:17:19.367 18558 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._report_driver_status run_periodic_tasks /usr/lib/python2.7/site-packages/cinder/openstack/common/periodic_task.py:178
2014-07-15 10:17:19.368 18558 INFO cinder.volume.manager [-] Updating volume status
2014-07-15 10:18:19.362 18558 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._publish_service_capabilities run_periodic_tasks /usr/lib/python2.7/site-packages/cinder/openstack/common/periodic_task.py:178
2014-07-15 10:18:19.363 18558 DEBUG cinder.manager [-] Notifying Schedulers of capabilities ... _publish_service_capabilities /usr/lib/python2.7/site-packages/cinder/manager.py:128
2014-07-15 10:18:19.371 18558 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._report_driver_status run_periodic_tasks /usr/lib/python2.7/site-packages/cinder/openstack/common/periodic_task.py:178
2014-07-15 10:18:19.371 18558 INFO cinder.volume.manager [-] Updating volume status
2014-07-15 10:19:19.362 18558 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._publish_service_capabilities run_periodic_tasks /usr/lib/python2.7/site-packages/cinder/openstack/common/periodic_task.py:178
2014-07-15 10:19:19.363 18558 DEBUG cinder.manager [-] Notifying Schedulers of capabilities ... _publish_service_capabilities /usr/lib/python2.7/site-packages/cinder/manager.py:128
2014-07-15 10:19:19.366 18558 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._report_driver_status run_periodic_tasks /usr/lib/python2.7/site-packages/cinder/openstack/common/periodic_task.py:178
2014-07-15 10:19:19.367 18558 INFO cinder.volume.manager [-] Updating volume status
2014-07-15 10:20:00.094 18558 DEBUG glanceclient.common.http [req-c954e296-26b5-4e67-98d0-b6ec9eeac3a5 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] 
HTTP/1.1 410 Gone
date: Tue, 15 Jul 2014 14:20:00 GMT
content-length: 232
content-type: text/plain; charset=UTF-8
x-openstack-request-id: req-15ecac81-da92-45cd-abb8-76cff563aeed

410 Gone

Image 6931741c-53c2-43f5-9983-a8bbcf04bc40 could not be found after upload.The image may have been deleted during the upload: No image found with ID 6931741c-53c2-43f5-9983-a8bbcf04bc40 Cleaning up the chunks uploaded

   
 log_http_response /usr/lib/python2.7/site-packages/glanceclient/common/http.py:152
2014-07-15 10:20:00.095 18558 ERROR glanceclient.common.http [req-c954e296-26b5-4e67-98d0-b6ec9eeac3a5 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] Request returned failure status.
2014-07-15 10:20:00.257 18558 ERROR oslo.messaging.rpc.dispatcher [req-c954e296-26b5-4e67-98d0-b6ec9eeac3a5 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] Exception during message handling: 410 Gone
Image 6931741c-53c2-43f5-9983-a8bbcf04bc40 could not be found after upload.The image may have been deleted during the upload: No image found with ID 6931741c-53c2-43f5-9983-a8bbcf04bc40 Cleaning up the chunks uploaded
    (HTTP N/A)
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 133, in _dispatch_and_reply
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher     incoming.message))
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 176, in _dispatch
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher     return self._do_dispatch(endpoint, method, ctxt, args)
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 122, in _do_dispatch
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher     result = getattr(endpoint, method)(ctxt, **new_args)
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 719, in copy_volume_to_image
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher     payload['message'] = unicode(error)
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/openstack/common/excutils.py", line 68, in __exit__
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 713, in copy_volume_to_image
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher     image_meta)
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/rbd.py", line 808, in copy_volume_to_image
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher     image_meta, tmp_file)
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/image/image_utils.py", line 238, in upload_volume
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher     image_service.update(context, image_id, {}, image_file)
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/image/glance.py", line 311, in update
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher     _reraise_translated_image_exception(image_id)
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/image/glance.py", line 306, in update
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher     image_meta['data'])
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/image/glance.py", line 158, in call
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher     return getattr(client.images, method)(*args, **kwargs)
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/glanceclient/v2/images.py", line 110, in upload
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher     body=image_data)
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/glanceclient/common/http.py", line 289, in raw_request
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher     return self._http_request(url, method, **kwargs)
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/glanceclient/common/http.py", line 249, in _http_request
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher     raise exc.from_response(resp, body_str)
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher HTTPException: 410 Gone
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher Image 6931741c-53c2-43f5-9983-a8bbcf04bc40 could not be found after upload.The image may have been deleted during the upload: No image found with ID 6931741c-53c2-43f5-9983-a8bbcf04bc40 Cleaning up the chunks uploaded
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher     (HTTP N/A)
2014-07-15 10:20:00.257 18558 TRACE oslo.messaging.rpc.dispatcher 
2014-07-15 10:20:00.279 18558 ERROR oslo.messaging._drivers.common [req-c954e296-26b5-4e67-98d0-b6ec9eeac3a5 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] Returning exception 410 Gone
Image 6931741c-53c2-43f5-9983-a8bbcf04bc40 could not be found after upload.The image may have been deleted during the upload: No image found with ID 6931741c-53c2-43f5-9983-a8bbcf04bc40 Cleaning up the chunks uploaded
    (HTTP N/A) to caller
2014-07-15 10:20:00.279 18558 ERROR oslo.messaging._drivers.common [req-c954e296-26b5-4e67-98d0-b6ec9eeac3a5 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] ['Traceback (most recent call last):\n', '  File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 133, in _dispatch_and_reply\n    incoming.message))\n', '  File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 176, in _dispatch\n    return self._do_dispatch(endpoint, method, ctxt, args)\n', '  File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 122, in _do_dispatch\n    result = getattr(endpoint, method)(ctxt, **new_args)\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 719, in copy_volume_to_image\n    payload[\'message\'] = unicode(error)\n', '  File "/usr/lib/python2.7/site-packages/cinder/openstack/common/excutils.py", line 68, in __exit__\n    six.reraise(self.type_, self.value, self.tb)\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 713, in copy_volume_to_image\n    image_meta)\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/rbd.py", line 808, in copy_volume_to_image\n    image_meta, tmp_file)\n', '  File "/usr/lib/python2.7/site-packages/cinder/image/image_utils.py", line 238, in upload_volume\n    image_service.update(context, image_id, {}, image_file)\n', '  File "/usr/lib/python2.7/site-packages/cinder/image/glance.py", line 311, in update\n    _reraise_translated_image_exception(image_id)\n', '  File "/usr/lib/python2.7/site-packages/cinder/image/glance.py", line 306, in update\n    image_meta[\'data\'])\n', '  File "/usr/lib/python2.7/site-packages/cinder/image/glance.py", line 158, in call\n    return getattr(client.images, method)(*args, **kwargs)\n', '  File "/usr/lib/python2.7/site-packages/glanceclient/v2/images.py", line 110, in upload\n    body=image_data)\n', '  File "/usr/lib/python2.7/site-packages/glanceclient/common/http.py", line 289, in raw_request\n    return self._http_request(url, method, **kwargs)\n', '  File "/usr/lib/python2.7/site-packages/glanceclient/common/http.py", line 249, in _http_request\n    raise exc.from_response(resp, body_str)\n', 'HTTPException: 410 Gone\nImage 6931741c-53c2-43f5-9983-a8bbcf04bc40 could not be found after upload.The image may have been deleted during the upload: No image found with ID 6931741c-53c2-43f5-9983-a8bbcf04bc40 Cleaning up the chunks uploaded\n    (HTTP N/A)\n']
2014-07-15 10:20:19.366 18558 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._publish_service_capabilities run_periodic_tasks /usr/lib/python2.7/site-packages/cinder/openstack/common/periodic_task.py:178

Version-Release number of selected component (if applicable):


How reproducible:
Configure ceph as backend ,  glance and cinder .
Run tempest :

the python-client code that fails :
 def test_volume_upload(self):
        # NOTE(gfidente): the volume uploaded in Glance comes from setUpClass,
        # it is shared with the other tests. After it is uploaded in Glance,
        # there is no way to delete it from Cinder, so we delete it from Glance
        # using the Glance image_client and from Cinder via tearDownClass.
        image_name = data_utils.rand_name('Image-')
        resp, body = self.client.upload_volume(self.volume['id'],
                                               image_name,
                                               CONF.volume.disk_format)
        image_id = body["image_id"]
        self.addCleanup(self.image_client.delete_image, image_id)
        self.assertEqual(202, resp.status)
        self.image_client.wait_for_image_status(image_id, 'active')
        self.client.wait_for_volume_status(self.volume['id'], 'available')

Steps to Reproduce:
1.
2.
3.

Actual results:


Expected results:


Additional info:

Comment 3 Eric Harney 2014-07-16 15:34:42 UTC
I think this is a failure on the Glance side... I'm not sure from the log what the exact reason is but it looks like a failure to write data to the rbd backend.  It looks like there may be a bug in error handling for this case, though.

2014-07-15 10:19:48.814 18627 DEBUG glance.store.rbd [15ecac81-da92-45cd-abb8-76cff563aeed 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] resizing image to 2097152 KiB add /usr/lib/python2.7/site-packages/glance/store/rbd.py:354
2014-07-15 10:19:49.193 18627 DEBUG glance.store.rbd [15ecac81-da92-45cd-abb8-76cff563aeed 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] writing chunk at offset 2139095040 add /usr/lib/python2.7/site-packages/glance/store/rbd.py:357
2014-07-15 10:19:51.954 18627 DEBUG glance.db.sqlalchemy.api [15ecac81-da92-45cd-abb8-76cff563aeed 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] No image found with ID 6931741c-53c2-43f5-9983-a8bbcf04bc40 _image_get /usr/lib/python2.7/site-packages/glance/db/sqlalchemy/api.py:182
2014-07-15 10:19:51.955 18627 WARNING glance.api.v2.image_data [15ecac81-da92-45cd-abb8-76cff563aeed 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] Image 6931741c-53c2-43f5-9983-a8bbcf04bc40 could not be found after upload.The image may have been deleted during the upload: No image found with ID 6931741c-53c2-43f5-9983-a8bbcf04bc40 Cleaning up the chunks uploaded
2014-07-15 10:20:00.082 18627 ERROR glance.api.v2.image_data [15ecac81-da92-45cd-abb8-76cff563aeed 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] Failed to upload image data due to HTTP error

A delete happens somewhere before the _restore() is called which results in:
InvalidImageStatusTransition: Image status transition from deleted to queued is not allowed

Comment 4 Flavio Percoco 2014-07-16 16:03:23 UTC
This is not a Glance issue. TBH, it sounds more like a tempest race condition. I think the scenario causing this issue is:

1. Image created
2. Volume upload called
3. Test ends before the volume upload completes and deletes the image.

Here's a chunk of log that supports the above scenario:

2014-07-15 10:18:52.877 18626 DEBUG routes.middleware [afd7910a-653a-49ff-b382-323e21b0b74b 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] Matched DELETE /images/6931741c-53c2-43f5-9983-a8bbcf04bc40 __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:100
2014-07-15 10:18:52.878 18626 DEBUG routes.middleware [afd7910a-653a-49ff-b382-323e21b0b74b 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] Route path: '/images/{id}', defaults: {'action': u'delete', 'controller': <glance.common.wsgi.Resource object at 0x2754710>} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:102
2014-07-15 10:18:52.878 18626 DEBUG routes.middleware [afd7910a-653a-49ff-b382-323e21b0b74b 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] Match dict: {'action': u'delete', 'controller': <glance.common.wsgi.Resource object at 0x2754710>, 'id': u'6931741c-53c2-43f5-9983-a8bbcf04bc40'} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:103
2014-07-15 10:18:52.878 18626 DEBUG glance.common.client [afd7910a-653a-49ff-b382-323e21b0b74b 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] Constructed URL: http://0.0.0.0:9191/images/6931741c-53c2-43f5-9983-a8bbcf04bc40 _construct_url /usr/lib/python2.7/site-packages/glance/common/client.py:411
2014-07-15 10:18:52.896 18626 DEBUG glance.registry.client.v1.client [afd7910a-653a-49ff-b382-323e21b0b74b 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] Registry request GET /images/6931741c-53c2-43f5-9983-a8bbcf04bc40 HTTP 200 request id req-db87266e-0eee-4dfe-a07b-66032d1b9de5 do_request /usr/lib/python2.7/site-packages/glance/registry/client/v1/client.py:114
2014-07-15 10:18:52.896 18626 DEBUG glance.registry.client.v1.api [afd7910a-653a-49ff-b382-323e21b0b74b 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] Updating image metadata for image 6931741c-53c2-43f5-9983-a8bbcf04bc40... update_image_metadata /usr/lib/python2.7/site-packages/glance/registry/client/v1/api.py:166
2014-07-15 10:18:52.897 18626 DEBUG glance.common.client [afd7910a-653a-49ff-b382-323e21b0b74b 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] Constructed URL: http://0.0.0.0:9191/images/6931741c-53c2-43f5-9983-a8bbcf04bc40 _construct_url /usr/lib/python2.7/site-packages/glance/common/client.py:411
2014-07-15 10:18:52.925 18626 DEBUG glance.registry.client.v1.client [afd7910a-653a-49ff-b382-323e21b0b74b 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] Registry request PUT /images/6931741c-53c2-43f5-9983-a8bbcf04bc40 HTTP 200 request id req-2f1bded0-0d62-4b3a-916c-936a41647c39 do_request /usr/lib/python2.7/site-packages/glance/registry/client/v1/client.py:114
2014-07-15 10:18:52.925 18626 DEBUG glance.registry.client.v1.api [afd7910a-653a-49ff-b382-323e21b0b74b 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] Deleting image metadata for image 6931741c-53c2-43f5-9983-a8bbcf04bc40... delete_image_metadata /usr/lib/python2.7/site-packages/glance/registry/client/v1/api.py:173
2014-07-15 10:18:52.926 18626 DEBUG glance.common.client [afd7910a-653a-49ff-b382-323e21b0b74b 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] Constructed URL: http://0.0.0.0:9191/images/6931741c-53c2-43f5-9983-a8bbcf04bc40 _construct_url /usr/lib/python2.7/site-packages/glance/common/client.py:411
2014-07-15 10:18:52.945 18626 DEBUG glance.registry.client.v1.client [afd7910a-653a-49ff-b382-323e21b0b74b 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] Registry request DELETE /images/6931741c-53c2-43f5-9983-a8bbcf04bc40 HTTP 200 request id req-59e72df9-c6be-40bd-996d-7c6a1d25faf4 do_request /usr/lib/python2.7/site-packages/glance/registry/client/v1/client.py:114
2014-07-15 10:18:52.946 18626 INFO glance.wsgi.server [afd7910a-653a-49ff-b382-323e21b0b74b 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] 192.168.2.20 - - [15/Jul/2014 10:18:52] "DELETE /v1/images/6931741c-53c2-43f5-9983-a8bbcf04bc40 HTTP/1.1" 200 200 0.072712
2014-07-15 10:18:53.365 18627 DEBUG glance.store.rbd [15ecac81-da92-45cd-abb8-76cff563aeed 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] resizing image to 1851392 KiB add /usr/lib/python2.7/site-packages/glance/store/rbd.py:354
2014-07-15 10:18:53.444 18627 DEBUG glance.store.rbd [15ecac81-da92-45cd-abb8-76cff563aeed 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] writing chunk at offset 1887436800 add /usr/lib/python2.7/site-packages/glance/store/rbd.py:357
2014-07-15 10:18:54.410 18627 DEBUG glance.store.rbd [15ecac81-da92-45cd-abb8-76cff563aeed 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] resizing image to 1859584 KiB add /usr/lib/python2.7/site-packages/glance/store/rbd.py:354
2014-07-15 10:18:55.298 18627 DEBUG glance.store.rbd [15ecac81-da92-45cd-abb8-76cff563aeed 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] writing chunk at offset 1895825408 add /usr/lib/python2.7/site-packages/glance/store/rbd.py:357
2014-07-15 10:18:56.274 18627 DEBUG glance.store.rbd [15ecac81-da92-45cd-abb8-76cff563aeed 8e185a6055d945c98098e7151137b52d 8d44d3c0b1114621b30653cb49063d99 - - -] resizing image to 1867776 KiB add /usr/lib/python2.7/site-packages/glance/store/rbd.py:354

Please, open the bug upstream on tempest to have tempest folks digging into this.


Note You need to log in before you can comment on or make changes to this bug.