Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1119879

Summary: Image could not be found after upload when ceph backend
Product: Red Hat OpenStack Reporter: bkopilov <bkopilov>
Component: openstack-cinderAssignee: Eric Harney <eharney>
Status: CLOSED UPSTREAM QA Contact: nlevinki <nlevinki>
Severity: high Docs Contact:
Priority: unspecified    
Version: 5.0 (RHEL 7)CC: eharney, fpercoco, scohen, yeylon
Target Milestone: ---   
Target Release: 5.0 (RHEL 7)   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2014-07-16 16:03:23 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
/var/log and /etc/ logs from automation none

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.