yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1388912] [NEW] Snapshot with image size 0 bits

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Boris Tassou <boris.tassou@xxxxxxxxx>
Date: Mon, 03 Nov 2014 16:50:24 -0000
Reply-to: Bug 1388912 <1388912@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

Hello,

We have a problem when we generate a snapshot.

Informations:
- nova --version 2.17.0
- cinder --version 1.0.8
- glance --version 0.12.0

Our problem:

To create a snapshot, we use the CLI by nova image-create.

To verify the snapshot, we go in Images tab et click on the image of the
snapshot, but in the specification we have a size of 0 bits :

Spécifications

Taille 
0 octet 
Format du Conteneur 
AUCUN 
Format du Disque 
AUCUN 

With the cli, we see the lvm snapshot but we can't found any image of the snapshot (qcow i presume).
With glance image-list or cinder list, we can't see the snapshot to.

To backup our VM, whe use cinder in CLI with cinder upload-image, that's
okay, it's worked.

I activate debug/verbose for nova/cinder/glance but we haven't any
explicit error in the log files.

When we create a snapshot, i took some logs of nova, cinder and glance.

Do you have an idea of the problem?

Logs for Nova:
2014-10-31 16:40:52.533 3777 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:666
2014-10-31 16:40:52.534 3777 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:725
2014-10-31 16:40:52.534 3777 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1124
2014-10-31 16:40:52.535 3777 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1234
2014-10-31 16:40:52.535 3777 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 1e7cb96667d049ccbcbd4aac84ca71b2 with project_id : 003048198aa94a0bb07b00802931d332 and roles: _member_  _build_user_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1021
2014-10-31 16:40:52.537 3777 DEBUG routes.middleware [-] Matched GET /003048198aa94a0bb07b00802931d332/servers/5749c7ac-7567-4b4d-a3ec-9bf248e4c450 __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
2014-10-31 16:40:52.537 3777 DEBUG routes.middleware [-] Route path: '/{project_id}/servers/:(id)', defaults: {'action': u'show', 'controller': <nova.api.openstack.wsgi.Resource object at 0x7fb12a909d10>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
2014-10-31 16:40:52.537 3777 DEBUG routes.middleware [-] Match dict: {'action': u'show', 'controller': <nova.api.openstack.wsgi.Resource object at 0x7fb12a909d10>, 'project_id': u'003048198aa94a0bb07b00802931d332', 'id': u'5749c7ac-7567-4b4d-a3ec-9bf248e4c450'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
2014-10-31 16:40:52.538 3777 DEBUG nova.api.openstack.wsgi [req-06cc551d-72f8-4fa7-b65d-022fa03b656e 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332] Calling method '<bound method Controller.show of <nova.api.openstack.compute.servers.Controller object at 0x7fb12b429c10>>' (Content-type='None', Accept='application/json') _process_stack /usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py:945
2014-10-31 16:40:52.595 3777 INFO nova.osapi_compute.wsgi.server [req-06cc551d-72f8-4fa7-b65d-022fa03b656e 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332] 62.210.200.76 "GET /v2/003048198aa94a0bb07b00802931d332/servers/5749c7ac-7567-4b4d-a3ec-9bf248e4c450 HTTP/1.1" status: 200 len: 1920 time: 0.0621860
2014-10-31 16:40:57.563 3777 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:666
2014-10-31 16:40:57.564 3777 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:725
2014-10-31 16:40:57.564 3777 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1124
2014-10-31 16:40:57.565 3777 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1234
2014-10-31 16:40:57.565 3777 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 1e7cb96667d049ccbcbd4aac84ca71b2 with project_id : 003048198aa94a0bb07b00802931d332 and roles: _member_  _build_user_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1021
2014-10-31 16:40:57.567 3777 DEBUG routes.middleware [-] Matched POST /003048198aa94a0bb07b00802931d332/servers/5749c7ac-7567-4b4d-a3ec-9bf248e4c450/action __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
2014-10-31 16:40:57.567 3777 DEBUG routes.middleware [-] Route path: '/{project_id}/servers/:(id)/action', defaults: {'action': u'action', 'controller': <nova.api.openstack.wsgi.Resource object at 0x7fb12a909d10>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
2014-10-31 16:40:57.567 3777 DEBUG routes.middleware [-] Match dict: {'action': u'action', 'controller': <nova.api.openstack.wsgi.Resource object at 0x7fb12a909d10>, 'project_id': u'003048198aa94a0bb07b00802931d332', 'id': u'5749c7ac-7567-4b4d-a3ec-9bf248e4c450'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
2014-10-31 16:40:57.568 3777 DEBUG nova.api.openstack.wsgi [req-041f497f-687d-4309-a90f-49c76d889ee4 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332] Action: 'action', body: {"createImage": {"name": "Unbound-snapshot", "metadata": {}}} _process_stack /usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py:940
2014-10-31 16:40:57.568 3777 DEBUG nova.api.openstack.wsgi [req-041f497f-687d-4309-a90f-49c76d889ee4 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332] Calling method '<bound method Controller._action_create_image of <nova.api.openstack.compute.contrib.keypairs.Controller object at 0x7fb12a527bd0>>' (Content-type='application/json', Accept='application/json') _process_stack /usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py:945
2014-10-31 16:40:57.622 3777 DEBUG nova.volume.cinder [req-041f497f-687d-4309-a90f-49c76d889ee4 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332] Cinderclient connection created using URL: http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332 cinderclient /usr/lib/python2.7/dist-packages/nova/volume/cinder.py:93
2014-10-31 16:40:57.623 3777 INFO urllib3.connectionpool [-] Starting new HTTP connection (1): 62.210.200.76
2014-10-31 16:40:57.711 3777 DEBUG urllib3.connectionpool [-] "GET /v1/003048198aa94a0bb07b00802931d332/volumes/05afbc5f-7bef-4427-a898-3b480d3bd72b HTTP/1.1" 200 905 _make_request /usr/lib/python2.7/dist-packages/urllib3/connectionpool.py:353
2014-10-31 16:40:57.715 3777 DEBUG nova.volume.cinder [req-041f497f-687d-4309-a90f-49c76d889ee4 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332] Cinderclient connection created using URL: http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332 cinderclient /usr/lib/python2.7/dist-packages/nova/volume/cinder.py:93
2014-10-31 16:40:57.716 3777 INFO urllib3.connectionpool [-] Starting new HTTP connection (1): 62.210.200.76
2014-10-31 16:40:57.804 3777 DEBUG urllib3.connectionpool [-] "GET /v1/003048198aa94a0bb07b00802931d332/volumes/05afbc5f-7bef-4427-a898-3b480d3bd72b HTTP/1.1" 200 905 _make_request /usr/lib/python2.7/dist-packages/urllib3/connectionpool.py:353
2014-10-31 16:40:57.806 3777 DEBUG nova.volume.cinder [req-041f497f-687d-4309-a90f-49c76d889ee4 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332] Cinderclient connection created using URL: http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332 cinderclient /usr/lib/python2.7/dist-packages/nova/volume/cinder.py:93
2014-10-31 16:40:57.807 3777 INFO urllib3.connectionpool [-] Starting new HTTP connection (1): 62.210.200.76
2014-10-31 16:40:57.869 3777 DEBUG urllib3.connectionpool [-] "POST /v1/003048198aa94a0bb07b00802931d332/snapshots HTTP/1.1" 200 282 _make_request /usr/lib/python2.7/dist-packages/urllib3/connectionpool.py:353
2014-10-31 16:40:57.876 3777 DEBUG glanceclient.common.http [-] curl -i -X POST -H 'x-image-meta-property-root_device_name: /dev/vda' -H 'X-Auth-Token: 050d20ca27f2cbd495f9fda4f398b744' -H 'x-image-meta-property-container_format: bare' -H 'x-image-meta-property-min_ram: 0' -H 'x-image-meta-name: Unbound-snapshot' -H 'User-Agent: python-glanceclient' -H 'X-User-Id: 1e7cb96667d049ccbcbd4aac84ca71b2' -H 'x-image-meta-property-min_disk: 0' -H 'x-image-meta-property-disk_format: qcow2' -H 'x-image-meta-property-size: 291781120' -H 'x-image-meta-property-image_id: 1223acf4-705e-4921-b8f7-8b7b091024df' -H 'x-image-meta-property-block_device_mapping: [{"guest_format": null, "boot_index": 0, "no_device": null, "snapshot_id": "961e49e7-261c-4185-9fec-cd34cf5ac2b6", "delete_on_termination": null, "disk_bus": "virtio", "image_id": null, "source_type": "snapshot", "device_type": "disk", "volume_id": null, "destination_type": "volume", "volume_size": null}]' -H 'X-Service-Catalog: [{"endpoints_links": [], "endpoints": [{"adminURL": "http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332";, "region": "regionOne", "internalURL": "http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332";, "serviceName": "cinder", "id": "2a99fa52cd6c4b02bedc4d04fccf148a", "publicURL": "http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332"}], "type": "volume", "name": "cinder"}]' -H 'x-image-meta-property-image_name: Debian' -H 'x-image-meta-property-checksum: 00a2d4794fb60ddb5a9c7b66e226445e' -H 'x-image-meta-property-bdm_v2: True' -H 'X-Roles: _member_' -H 'x-image-meta-size: 0' -H 'X-Tenant-Id: 003048198aa94a0bb07b00802931d332' -H 'x-image-meta-is_public: False' -H 'X-Identity-Status: Confirmed' -H 'Content-Type: application/octet-stream' http://62.210.200.76:9292/v1/images log_curl_request /usr/lib/python2.7/dist-packages/glanceclient/common/http.py:142
2014-10-31 16:40:57.911 3777 DEBUG glanceclient.common.http [-] 
HTTP/1.1 201 Created
date: Fri, 31 Oct 2014 15:40:57 GMT
content-length: 1093
content-type: application/json
location: http://62.210.200.76:9292/v1/images/c473714b-0ed5-4843-b398-a38c50fea5e6
x-openstack-request-id: req-73da5622-b98d-4df5-ad51-c3e20b2c6761

{"image": {"status": "active", "deleted": false, "container_format": null, "min_ram": 0, "updated_at": "2014-10-31T15:40:57", "owner": "003048198aa94a0bb07b00802931d332", "min_disk": 0, "is_public": false, "deleted_at": null, "id": "c473714b-0ed5-4843-b398-a38c50fea5e6", "size": 0, "virtual_size": null, "name": "Unbound-snapshot", "checksum": null, "created_at": "2014-10-31T15:40:57", "disk_format": null, "properties": {"block_device_mapping": "[{\"guest_format\": null, \"boot_index\": 0, \"no_device\": null, \"snapshot_id\": \"961e49e7-261c-4185-9fec-cd34cf5ac2b6\", \"delete_on_termination\": null, \"disk_bus\": \"virtio\", \"image_id\": null, \"source_type\": \"snapshot\", \"device_type\": \"disk\", \"volume_id\": null, \"destination_type\": \"volume\", \"volume_size\": null}]", "checksum": "00a2d4794fb60ddb5a9c7b66e226445e", "min_ram": "0", "disk_format": "qcow2", "image_name": "Debian", "bdm_v2": "True", "image_id": "1223acf4-705e-4921-b8f7-8b7b091024df", "root_device_name": "/dev/vda", "container_format": "bare", "min_disk": "0", "size": "291781120"}, "protected": false}}
 log_http_response /usr/lib/python2.7/dist-packages/glanceclient/common/http.py:152
2014-10-31 16:40:57.912 3777 INFO nova.osapi_compute.wsgi.server [req-041f497f-687d-4309-a90f-49c76d889ee4 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332] 62.210.200.76 "POST /v2/003048198aa94a0bb07b00802931d332/servers/5749c7ac-7567-4b4d-a3ec-9bf248e4c450/action HTTP/1.1" status: 202 len: 302 time: 0.3487010
2014-10-31 16:40:57.914 3777 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:666
2014-10-31 16:40:57.914 3777 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:725
2014-10-31 16:40:57.915 3777 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1124
2014-10-31 16:40:57.915 3777 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1234
2014-10-31 16:40:57.915 3777 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 1e7cb96667d049ccbcbd4aac84ca71b2 with project_id : 003048198aa94a0bb07b00802931d332 and roles: _member_  _build_user_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1021
2014-10-31 16:40:57.916 3777 DEBUG routes.middleware [-] Matched GET /003048198aa94a0bb07b00802931d332/servers/5749c7ac-7567-4b4d-a3ec-9bf248e4c450 __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
2014-10-31 16:40:57.916 3777 DEBUG routes.middleware [-] Route path: '/{project_id}/servers/:(id)', defaults: {'action': u'show', 'controller': <nova.api.openstack.wsgi.Resource object at 0x7fb12a909d10>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
2014-10-31 16:40:57.916 3777 DEBUG routes.middleware [-] Match dict: {'action': u'show', 'controller': <nova.api.openstack.wsgi.Resource object at 0x7fb12a909d10>, 'project_id': u'003048198aa94a0bb07b00802931d332', 'id': u'5749c7ac-7567-4b4d-a3ec-9bf248e4c450'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
2014-10-31 16:40:57.917 3777 DEBUG nova.api.openstack.wsgi [req-460b2560-5f3b-43e0-a657-0795ebb831d9 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332] Calling method '<bound method Controller.show of <nova.api.openstack.compute.servers.Controller object at 0x7fb12b429c10>>' (Content-type='None', Accept='application/json') _process_stack /usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py:945
2014-10-31 16:40:57.951 3777 INFO nova.osapi_compute.wsgi.server [req-460b2560-5f3b-43e0-a657-0795ebb831d9 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332] 62.210.200.76 "GET /v2/003048198aa94a0bb07b00802931d332/servers/5749c7ac-7567-4b4d-a3ec-9bf248e4c450 HTTP/1.1" status: 200 len: 1920 time: 0.0372040

Logs for Cinder:
2014-10-31 16:43:23.045 6525 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1234
2014-10-31 16:43:23.046 6525 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 1e7cb96667d049ccbcbd4aac84ca71b2 with project_id : 003048198aa94a0bb07b00802931d332 and roles: _member_  _build_user_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1021
2014-10-31 16:43:23.046 6525 DEBUG routes.middleware [req-7b0bae66-935f-44e8-b34d-ba8c0e20e809 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Matched GET /003048198aa94a0bb07b00802931d332/snapshots/detail __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
2014-10-31 16:43:23.046 6525 DEBUG routes.middleware [req-7b0bae66-935f-44e8-b34d-ba8c0e20e809 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Route path: '/{project_id}/snapshots/detail', defaults: {'action': u'detail', 'controller': <cinder.api.openstack.wsgi.Resource object at 0x7f7d0567f090>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
2014-10-31 16:43:23.047 6525 DEBUG routes.middleware [req-7b0bae66-935f-44e8-b34d-ba8c0e20e809 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Match dict: {'action': u'detail', 'controller': <cinder.api.openstack.wsgi.Resource object at 0x7f7d0567f090>, 'project_id': u'003048198aa94a0bb07b00802931d332'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
2014-10-31 16:43:23.047 6525 INFO cinder.api.openstack.wsgi [req-7b0bae66-935f-44e8-b34d-ba8c0e20e809 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] GET http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332/snapshots/detail
2014-10-31 16:43:23.047 6525 DEBUG cinder.api.openstack.wsgi [req-7b0bae66-935f-44e8-b34d-ba8c0e20e809 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Empty body provided in request get_body /usr/lib/python2.7/dist-packages/cinder/api/openstack/wsgi.py:787
2014-10-31 16:43:23.047 6525 DEBUG cinder.api.v1.volumes [req-7b0bae66-935f-44e8-b34d-ba8c0e20e809 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Removing options '' from query remove_invalid_options /usr/lib/python2.7/dist-packages/cinder/api/v1/volumes.py:506
2014-10-31 16:43:23.055 6525 INFO cinder.api.openstack.wsgi [req-7b0bae66-935f-44e8-b34d-ba8c0e20e809 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332/snapshots/detail returned with HTTP 200
2014-10-31 16:43:23.055 6525 INFO eventlet.wsgi.server [req-7b0bae66-935f-44e8-b34d-ba8c0e20e809 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] 62.210.200.76 - - [31/Oct/2014 16:43:23] "GET /v1/003048198aa94a0bb07b00802931d332/snapshots/detail HTTP/1.1" 200 255 0.010933
2014-10-31 16:43:48.270 6525 INFO eventlet.wsgi.server [-] (6525) accepted ('62.210.200.76', 53364)
2014-10-31 16:43:48.271 6525 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:666
2014-10-31 16:43:48.271 6525 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:725
2014-10-31 16:43:48.272 6525 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1124
2014-10-31 16:43:48.272 6525 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1234
2014-10-31 16:43:48.272 6525 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 1e7cb96667d049ccbcbd4aac84ca71b2 with project_id : 003048198aa94a0bb07b00802931d332 and roles: _member_  _build_user_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1021
2014-10-31 16:43:48.273 6525 DEBUG routes.middleware [req-2c36dcb0-972a-41a8-97f0-c07739555765 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Matched GET /003048198aa94a0bb07b00802931d332/volumes/05afbc5f-7bef-4427-a898-3b480d3bd72b __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
2014-10-31 16:43:48.274 6525 DEBUG routes.middleware [req-2c36dcb0-972a-41a8-97f0-c07739555765 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Route path: '/{project_id}/volumes/:(id)', defaults: {'action': u'show', 'controller': <cinder.api.openstack.wsgi.Resource object at 0x7f7d05660090>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
2014-10-31 16:43:48.274 6525 DEBUG routes.middleware [req-2c36dcb0-972a-41a8-97f0-c07739555765 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Match dict: {'action': u'show', 'controller': <cinder.api.openstack.wsgi.Resource object at 0x7f7d05660090>, 'project_id': u'003048198aa94a0bb07b00802931d332', 'id': u'05afbc5f-7bef-4427-a898-3b480d3bd72b'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
2014-10-31 16:43:48.274 6525 INFO cinder.api.openstack.wsgi [req-2c36dcb0-972a-41a8-97f0-c07739555765 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] GET http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332/volumes/05afbc5f-7bef-4427-a898-3b480d3bd72b
2014-10-31 16:43:48.275 6525 DEBUG cinder.api.openstack.wsgi [req-2c36dcb0-972a-41a8-97f0-c07739555765 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Empty body provided in request get_body /usr/lib/python2.7/dist-packages/cinder/api/openstack/wsgi.py:787
2014-10-31 16:43:48.317 6525 AUDIT cinder.api.v1.volumes [req-2c36dcb0-972a-41a8-97f0-c07739555765 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] vol={'migration_status': None, 'availability_zone': u'nova', 'terminated_at': None, 'updated_at': datetime.datetime(2014, 10, 30, 17, 14, 16), 'provider_geometry': None, 'snapshot_id': None, 'ec2_id': None, 'mountpoint': u'vda', 'deleted_at': None, 'id': u'05afbc5f-7bef-4427-a898-3b480d3bd72b', 'size': 5L, 'user_id': u'1e7cb96667d049ccbcbd4aac84ca71b2', 'attach_time': u'2014-10-08T08:50:15.486768', 'attached_host': None, 'display_description': u'', 'encryption_key_id': None, 'project_id': u'003048198aa94a0bb07b00802931d332', 'launched_at': datetime.datetime(2014, 10, 8, 8, 50, 14), 'scheduled_at': datetime.datetime(2014, 10, 8, 8, 49, 57), 'status': u'in-use', 'volume_type_id': None, 'deleted': False, 'provider_location': u'62.210.200.76:3260,7 iqn.2010-10.org.openstack:volume-05afbc5f-7bef-4427-a898-3b480d3bd72b 1', 'host': u'pa01.ygk-cloud.net', 'source_volid': None, 'provider_auth': u'CHAP tTR2TpMtBYkEDZ4feVoq 76u7asMLMBmPHjJmQf2G', 'display_name': u'', 'instance_uuid': u'5749c7ac-7567-4b4d-a3ec-9bf248e4c450', 'bootable': True, 'created_at': datetime.datetime(2014, 10, 8, 8, 49, 57), 'attach_status': u'attached', 'volume_type': None, '_name_id': None, 'volume_metadata': [], 'metadata': {u'readonly': u'False', u'attached_mode': u'rw'}}
2014-10-31 16:43:48.351 6525 INFO cinder.api.openstack.wsgi [req-2c36dcb0-972a-41a8-97f0-c07739555765 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332/volumes/05afbc5f-7bef-4427-a898-3b480d3bd72b returned with HTTP 200
2014-10-31 16:43:48.352 6525 INFO eventlet.wsgi.server [req-2c36dcb0-972a-41a8-97f0-c07739555765 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] 62.210.200.76 - - [31/Oct/2014 16:43:48] "GET /v1/003048198aa94a0bb07b00802931d332/volumes/05afbc5f-7bef-4427-a898-3b480d3bd72b HTTP/1.1" 200 1144 0.081481
2014-10-31 16:43:48.357 6525 INFO eventlet.wsgi.server [-] (6525) accepted ('62.210.200.76', 53365)
2014-10-31 16:43:48.358 6525 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:666
2014-10-31 16:43:48.359 6525 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:725
2014-10-31 16:43:48.359 6525 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1124
2014-10-31 16:43:48.360 6525 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1234
2014-10-31 16:43:48.360 6525 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 1e7cb96667d049ccbcbd4aac84ca71b2 with project_id : 003048198aa94a0bb07b00802931d332 and roles: _member_  _build_user_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1021
2014-10-31 16:43:48.361 6525 DEBUG routes.middleware [req-84bfb5b3-81f8-4532-a412-5114cd7db9dc 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Matched GET /003048198aa94a0bb07b00802931d332/volumes/05afbc5f-7bef-4427-a898-3b480d3bd72b __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
2014-10-31 16:43:48.361 6525 DEBUG routes.middleware [req-84bfb5b3-81f8-4532-a412-5114cd7db9dc 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Route path: '/{project_id}/volumes/:(id)', defaults: {'action': u'show', 'controller': <cinder.api.openstack.wsgi.Resource object at 0x7f7d05660090>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
2014-10-31 16:43:48.361 6525 DEBUG routes.middleware [req-84bfb5b3-81f8-4532-a412-5114cd7db9dc 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Match dict: {'action': u'show', 'controller': <cinder.api.openstack.wsgi.Resource object at 0x7f7d05660090>, 'project_id': u'003048198aa94a0bb07b00802931d332', 'id': u'05afbc5f-7bef-4427-a898-3b480d3bd72b'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
2014-10-31 16:43:48.362 6525 INFO cinder.api.openstack.wsgi [req-84bfb5b3-81f8-4532-a412-5114cd7db9dc 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] GET http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332/volumes/05afbc5f-7bef-4427-a898-3b480d3bd72b
2014-10-31 16:43:48.362 6525 DEBUG cinder.api.openstack.wsgi [req-84bfb5b3-81f8-4532-a412-5114cd7db9dc 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Empty body provided in request get_body /usr/lib/python2.7/dist-packages/cinder/api/openstack/wsgi.py:787
2014-10-31 16:43:48.394 6525 AUDIT cinder.api.v1.volumes [req-84bfb5b3-81f8-4532-a412-5114cd7db9dc 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] vol={'migration_status': None, 'availability_zone': u'nova', 'terminated_at': None, 'updated_at': datetime.datetime(2014, 10, 30, 17, 14, 16), 'provider_geometry': None, 'snapshot_id': None, 'ec2_id': None, 'mountpoint': u'vda', 'deleted_at': None, 'id': u'05afbc5f-7bef-4427-a898-3b480d3bd72b', 'size': 5L, 'user_id': u'1e7cb96667d049ccbcbd4aac84ca71b2', 'attach_time': u'2014-10-08T08:50:15.486768', 'attached_host': None, 'display_description': u'', 'encryption_key_id': None, 'project_id': u'003048198aa94a0bb07b00802931d332', 'launched_at': datetime.datetime(2014, 10, 8, 8, 50, 14), 'scheduled_at': datetime.datetime(2014, 10, 8, 8, 49, 57), 'status': u'in-use', 'volume_type_id': None, 'deleted': False, 'provider_location': u'62.210.200.76:3260,7 iqn.2010-10.org.openstack:volume-05afbc5f-7bef-4427-a898-3b480d3bd72b 1', 'host': u'pa01.ygk-cloud.net', 'source_volid': None, 'provider_auth': u'CHAP tTR2TpMtBYkEDZ4feVoq 76u7asMLMBmPHjJmQf2G', 'display_name': u'', 'instance_uuid': u'5749c7ac-7567-4b4d-a3ec-9bf248e4c450', 'bootable': True, 'created_at': datetime.datetime(2014, 10, 8, 8, 49, 57), 'attach_status': u'attached', 'volume_type': None, '_name_id': None, 'volume_metadata': [], 'metadata': {u'readonly': u'False', u'attached_mode': u'rw'}}
2014-10-31 16:43:48.426 6525 INFO cinder.api.openstack.wsgi [req-84bfb5b3-81f8-4532-a412-5114cd7db9dc 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332/volumes/05afbc5f-7bef-4427-a898-3b480d3bd72b returned with HTTP 200
2014-10-31 16:43:48.426 6525 INFO eventlet.wsgi.server [req-84bfb5b3-81f8-4532-a412-5114cd7db9dc 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] 62.210.200.76 - - [31/Oct/2014 16:43:48] "GET /v1/003048198aa94a0bb07b00802931d332/volumes/05afbc5f-7bef-4427-a898-3b480d3bd72b HTTP/1.1" 200 1144 0.068342
2014-10-31 16:43:48.429 6525 INFO eventlet.wsgi.server [-] (6525) accepted ('62.210.200.76', 53366)
2014-10-31 16:43:48.429 6525 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:666
2014-10-31 16:43:48.429 6525 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:725
2014-10-31 16:43:48.430 6525 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1124
2014-10-31 16:43:48.430 6525 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1234
2014-10-31 16:43:48.430 6525 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 1e7cb96667d049ccbcbd4aac84ca71b2 with project_id : 003048198aa94a0bb07b00802931d332 and roles: _member_  _build_user_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1021
2014-10-31 16:43:48.431 6525 DEBUG routes.middleware [req-23c0fb78-d57b-497a-bae7-280fef7f1fbb 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Matched POST /003048198aa94a0bb07b00802931d332/snapshots __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
2014-10-31 16:43:48.431 6525 DEBUG routes.middleware [req-23c0fb78-d57b-497a-bae7-280fef7f1fbb 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Route path: '/{project_id}/snapshots', defaults: {'action': u'create', 'controller': <cinder.api.openstack.wsgi.Resource object at 0x7f7d0567f090>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
2014-10-31 16:43:48.432 6525 DEBUG routes.middleware [req-23c0fb78-d57b-497a-bae7-280fef7f1fbb 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Match dict: {'action': u'create', 'controller': <cinder.api.openstack.wsgi.Resource object at 0x7f7d0567f090>, 'project_id': u'003048198aa94a0bb07b00802931d332'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
2014-10-31 16:43:48.432 6525 INFO cinder.api.openstack.wsgi [req-23c0fb78-d57b-497a-bae7-280fef7f1fbb 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] POST http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332/snapshots
2014-10-31 16:43:48.445 6525 AUDIT cinder.api.v1.snapshots [req-23c0fb78-d57b-497a-bae7-280fef7f1fbb 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Create snapshot from volume 05afbc5f-7bef-4427-a898-3b480d3bd72b
2014-10-31 16:43:48.457 6525 DEBUG cinder.quota [req-23c0fb78-d57b-497a-bae7-280fef7f1fbb 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Created reservations ['ac77b3cd-1ebb-4e28-8261-a9ea1edc7397', 'c7764d90-2428-42d0-8027-5a93da71a268'] reserve /usr/lib/python2.7/dist-packages/cinder/quota.py:748
2014-10-31 16:43:48.477 6525 INFO cinder.api.openstack.wsgi [req-23c0fb78-d57b-497a-bae7-280fef7f1fbb 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332/snapshots returned with HTTP 200
2014-10-31 16:43:48.478 6525 INFO eventlet.wsgi.server [req-23c0fb78-d57b-497a-bae7-280fef7f1fbb 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] 62.210.200.76 - - [31/Oct/2014 16:43:48] "POST /v1/003048198aa94a0bb07b00802931d332/snapshots HTTP/1.1" 200 521 0.048882

Logs for Glance:
2014-10-31 16:27:13.849 36334 INFO urllib3.connectionpool [-] Starting new HTTP connection (1): 127.0.0.1
2014-10-31 16:27:13.860 36334 DEBUG urllib3.connectionpool [-] "GET /v2.0/tokens/050d20ca27f2cbd495f9fda4f398b744 HTTP/1.1" 200 6986 _make_request /usr/lib/python2.7/dist-packages/urllib3/connectionpool.py:353
2014-10-31 16:27:13.861 36334 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1234
2014-10-31 16:27:13.861 36334 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 1e7cb96667d049ccbcbd4aac84ca71b2 with project_id : 003048198aa94a0bb07b00802931d332 and roles: _member_  _build_user_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1021
2014-10-31 16:27:13.862 36334 DEBUG routes.middleware [7929d396-89e6-46c8-9ee8-6c7af004e283 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Matched GET /images/detail __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
2014-10-31 16:27:13.863 36334 DEBUG routes.middleware [7929d396-89e6-46c8-9ee8-6c7af004e283 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Route path: '/images/detail', defaults: {'action': u'detail', 'controller': <glance.common.wsgi.Resource object at 0x7ff97dce5850>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
2014-10-31 16:27:13.863 36334 DEBUG routes.middleware [7929d396-89e6-46c8-9ee8-6c7af004e283 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Match dict: {'action': u'detail', 'controller': <glance.common.wsgi.Resource object at 0x7ff97dce5850>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
2014-10-31 16:27:13.864 36334 DEBUG glance.common.client [7929d396-89e6-46c8-9ee8-6c7af004e283 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Constructed URL: http://127.0.0.1:9191/images/detail?limit=1000 _construct_url /usr/lib/python2.7/dist-packages/glance/common/client.py:411
2014-10-31 16:27:13.955 36334 DEBUG glance.registry.client.v1.client [7929d396-89e6-46c8-9ee8-6c7af004e283 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Registry request GET /images/detail HTTP 200 request id req-453bf079-53a3-4d9b-a27a-5cacccf48e02 do_request /usr/lib/python2.7/dist-packages/glance/registry/client/v1/client.py:114
2014-10-31 16:27:13.956 36334 INFO glance.wsgi.server [7929d396-89e6-46c8-9ee8-6c7af004e283 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] 62.210.200.76 - - [31/Oct/2014 16:27:13] "GET /v1/images/detail?limit=1000 HTTP/1.1" 200 6471 0.110902
2014-10-31 16:28:06.636 36334 DEBUG glance.api.middleware.version_negotiation [-] Determining version of request: POST /v1/images Accept:  process_request /usr/lib/python2.7/dist-packages/glance/api/middleware/version_negotiation.py:44
2014-10-31 16:28:06.636 36334 DEBUG glance.api.middleware.version_negotiation [-] Using url versioning process_request /usr/lib/python2.7/dist-packages/glance/api/middleware/version_negotiation.py:57
2014-10-31 16:28:06.637 36334 DEBUG glance.api.middleware.version_negotiation [-] Matched version: v1 process_request /usr/lib/python2.7/dist-packages/glance/api/middleware/version_negotiation.py:69
2014-10-31 16:28:06.637 36334 DEBUG glance.api.middleware.version_negotiation [-] new path /v1/images process_request /usr/lib/python2.7/dist-packages/glance/api/middleware/version_negotiation.py:70
2014-10-31 16:28:06.637 36334 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:666
2014-10-31 16:28:06.637 36334 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:725
2014-10-31 16:28:06.638 36334 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1124
2014-10-31 16:28:06.638 36334 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1234
2014-10-31 16:28:06.638 36334 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 1e7cb96667d049ccbcbd4aac84ca71b2 with project_id : 003048198aa94a0bb07b00802931d332 and roles: _member_  _build_user_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1021
2014-10-31 16:28:06.639 36334 DEBUG routes.middleware [e866bc71-b998-4040-8337-3bf3e4b5e86c 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Matched POST /images __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
2014-10-31 16:28:06.639 36334 DEBUG routes.middleware [e866bc71-b998-4040-8337-3bf3e4b5e86c 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Route path: '/images', defaults: {'action': u'create', 'controller': <glance.common.wsgi.Resource object at 0x7ff97dce5850>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
2014-10-31 16:28:06.639 36334 DEBUG routes.middleware [e866bc71-b998-4040-8337-3bf3e4b5e86c 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Match dict: {'action': u'create', 'controller': <glance.common.wsgi.Resource object at 0x7ff97dce5850>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
2014-10-31 16:28:06.640 36334 DEBUG glance.registry.client.v1.api [e866bc71-b998-4040-8337-3bf3e4b5e86c 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Adding image metadata... add_image_metadata /usr/lib/python2.7/dist-packages/glance/registry/client/v1/api.py:159
2014-10-31 16:28:06.640 36334 DEBUG glance.common.client [e866bc71-b998-4040-8337-3bf3e4b5e86c 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Constructed URL: http://127.0.0.1:9191/images _construct_url /usr/lib/python2.7/dist-packages/glance/common/client.py:411
2014-10-31 16:28:06.662 36334 DEBUG glance.registry.client.v1.client [e866bc71-b998-4040-8337-3bf3e4b5e86c 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Registry request POST /images HTTP 200 request id req-17c8d593-ec12-4646-8411-ba31ee4203af do_request /usr/lib/python2.7/dist-packages/glance/registry/client/v1/client.py:114
2014-10-31 16:28:06.663 36334 DEBUG oslo.messaging._drivers.amqp [e866bc71-b998-4040-8337-3bf3e4b5e86c 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] UNIQUE_ID is e1d554d149694eccbe2ff252a1fd9d42. _add_unique_id /usr/lib/python2.7/dist-packages/oslo/messaging/_drivers/amqp.py:338
2014-10-31 16:28:06.666 36334 INFO glance.wsgi.server [e866bc71-b998-4040-8337-3bf3e4b5e86c 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] 62.210.200.76 - - [31/Oct/2014 16:28:06] "POST /v1/images HTTP/1.1" 201 1358 0.030131
2014-10-31 16:28:06.760 36334 DEBUG glance.api.middleware.version_negotiation [-] Determining version of request: GET /v1/images/detail Accept:  process_request /usr/lib/python2.7/dist-packages/glance/api/middleware/version_negotiation.py:44
2014-10-31 16:28:06.761 36334 DEBUG glance.api.middleware.version_negotiation [-] Using url versioning process_request /usr/lib/python2.7/dist-packages/glance/api/middleware/version_negotiation.py:57
2014-10-31 16:28:06.761 36334 DEBUG glance.api.middleware.version_negotiation [-] Matched version: v1 process_request /usr/lib/python2.7/dist-packages/glance/api/middleware/version_negotiation.py:69
2014-10-31 16:28:06.762 36334 DEBUG glance.api.middleware.version_negotiation [-] new path /v1/images/detail process_request /usr/lib/python2.7/dist-packages/glance/api/middleware/version_negotiation.py:70
2014-10-31 16:28:06.762 36334 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:666
2014-10-31 16:28:06.762 36334 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:725
2014-10-31 16:28:06.763 36334 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1124
2014-10-31 16:28:06.763 36334 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1234
2014-10-31 16:28:06.763 36334 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 1e7cb96667d049ccbcbd4aac84ca71b2 with project_id : 003048198aa94a0bb07b00802931d332 and roles: _member_  _build_user_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1021
2014-10-31 16:28:06.764 36334 DEBUG routes.middleware [a32f7a5f-eec3-42f2-8b0f-614090bfab7a 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Matched GET /images/detail __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
2014-10-31 16:28:06.764 36334 DEBUG routes.middleware [a32f7a5f-eec3-42f2-8b0f-614090bfab7a 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Route path: '/images/detail', defaults: {'action': u'detail', 'controller': <glance.common.wsgi.Resource object at 0x7ff97dce5850>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
2014-10-31 16:28:06.765 36334 DEBUG routes.middleware [a32f7a5f-eec3-42f2-8b0f-614090bfab7a 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Match dict: {'action': u'detail', 'controller': <glance.common.wsgi.Resource object at 0x7ff97dce5850>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
2014-10-31 16:28:06.765 36334 DEBUG glance.common.client [a32f7a5f-eec3-42f2-8b0f-614090bfab7a 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Constructed URL: http://127.0.0.1:9191/images/detail?limit=1000 _construct_url /usr/lib/python2.7/dist-packages/glance/common/client.py:411
2014-10-31 16:28:06.816 36334 DEBUG glance.registry.client.v1.client [a32f7a5f-eec3-42f2-8b0f-614090bfab7a 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Registry request GET /images/detail HTTP 200 request id req-a4f1234c-b930-4854-8bb1-dae09d8f1a40 do_request /usr/lib/python2.7/dist-packages/glance/registry/client/v1/client.py:114
2014-10-31 16:28:06.818 36334 INFO glance.wsgi.server [a32f7a5f-eec3-42f2-8b0f-614090bfab7a 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] 62.210.200.76 - - [31/Oct/2014 16:28:06] "GET /v1/images/detail?limit=1000 HTTP/1.1" 200 7555 0.057574

** Affects: glance
     Importance: Undecided
         Status: New

** Attachment added: "cinder-api.log"
   https://bugs.launchpad.net/bugs/1388912/+attachment/4252126/+files/cinder-api.log

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to Glance.
https://bugs.launchpad.net/bugs/1388912

Title:
  Snapshot with image size 0 bits

Status in OpenStack Image Registry and Delivery Service (Glance):
  New

Bug description:
  Hello,

  We have a problem when we generate a snapshot.

  Informations:
  - nova --version 2.17.0
  - cinder --version 1.0.8
  - glance --version 0.12.0

  Our problem:

  To create a snapshot, we use the CLI by nova image-create.

  To verify the snapshot, we go in Images tab et click on the image of
  the snapshot, but in the specification we have a size of 0 bits :

  Spécifications

  Taille 
  0 octet 
  Format du Conteneur 
  AUCUN 
  Format du Disque 
  AUCUN 

  With the cli, we see the lvm snapshot but we can't found any image of the snapshot (qcow i presume).
  With glance image-list or cinder list, we can't see the snapshot to.

  To backup our VM, whe use cinder in CLI with cinder upload-image,
  that's okay, it's worked.

  I activate debug/verbose for nova/cinder/glance but we haven't any
  explicit error in the log files.

  When we create a snapshot, i took some logs of nova, cinder and
  glance.

  Do you have an idea of the problem?

  Logs for Nova:
  2014-10-31 16:40:52.533 3777 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:666
  2014-10-31 16:40:52.534 3777 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:725
  2014-10-31 16:40:52.534 3777 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1124
  2014-10-31 16:40:52.535 3777 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1234
  2014-10-31 16:40:52.535 3777 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 1e7cb96667d049ccbcbd4aac84ca71b2 with project_id : 003048198aa94a0bb07b00802931d332 and roles: _member_  _build_user_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1021
  2014-10-31 16:40:52.537 3777 DEBUG routes.middleware [-] Matched GET /003048198aa94a0bb07b00802931d332/servers/5749c7ac-7567-4b4d-a3ec-9bf248e4c450 __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
  2014-10-31 16:40:52.537 3777 DEBUG routes.middleware [-] Route path: '/{project_id}/servers/:(id)', defaults: {'action': u'show', 'controller': <nova.api.openstack.wsgi.Resource object at 0x7fb12a909d10>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
  2014-10-31 16:40:52.537 3777 DEBUG routes.middleware [-] Match dict: {'action': u'show', 'controller': <nova.api.openstack.wsgi.Resource object at 0x7fb12a909d10>, 'project_id': u'003048198aa94a0bb07b00802931d332', 'id': u'5749c7ac-7567-4b4d-a3ec-9bf248e4c450'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
  2014-10-31 16:40:52.538 3777 DEBUG nova.api.openstack.wsgi [req-06cc551d-72f8-4fa7-b65d-022fa03b656e 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332] Calling method '<bound method Controller.show of <nova.api.openstack.compute.servers.Controller object at 0x7fb12b429c10>>' (Content-type='None', Accept='application/json') _process_stack /usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py:945
  2014-10-31 16:40:52.595 3777 INFO nova.osapi_compute.wsgi.server [req-06cc551d-72f8-4fa7-b65d-022fa03b656e 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332] 62.210.200.76 "GET /v2/003048198aa94a0bb07b00802931d332/servers/5749c7ac-7567-4b4d-a3ec-9bf248e4c450 HTTP/1.1" status: 200 len: 1920 time: 0.0621860
  2014-10-31 16:40:57.563 3777 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:666
  2014-10-31 16:40:57.564 3777 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:725
  2014-10-31 16:40:57.564 3777 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1124
  2014-10-31 16:40:57.565 3777 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1234
  2014-10-31 16:40:57.565 3777 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 1e7cb96667d049ccbcbd4aac84ca71b2 with project_id : 003048198aa94a0bb07b00802931d332 and roles: _member_  _build_user_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1021
  2014-10-31 16:40:57.567 3777 DEBUG routes.middleware [-] Matched POST /003048198aa94a0bb07b00802931d332/servers/5749c7ac-7567-4b4d-a3ec-9bf248e4c450/action __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
  2014-10-31 16:40:57.567 3777 DEBUG routes.middleware [-] Route path: '/{project_id}/servers/:(id)/action', defaults: {'action': u'action', 'controller': <nova.api.openstack.wsgi.Resource object at 0x7fb12a909d10>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
  2014-10-31 16:40:57.567 3777 DEBUG routes.middleware [-] Match dict: {'action': u'action', 'controller': <nova.api.openstack.wsgi.Resource object at 0x7fb12a909d10>, 'project_id': u'003048198aa94a0bb07b00802931d332', 'id': u'5749c7ac-7567-4b4d-a3ec-9bf248e4c450'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
  2014-10-31 16:40:57.568 3777 DEBUG nova.api.openstack.wsgi [req-041f497f-687d-4309-a90f-49c76d889ee4 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332] Action: 'action', body: {"createImage": {"name": "Unbound-snapshot", "metadata": {}}} _process_stack /usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py:940
  2014-10-31 16:40:57.568 3777 DEBUG nova.api.openstack.wsgi [req-041f497f-687d-4309-a90f-49c76d889ee4 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332] Calling method '<bound method Controller._action_create_image of <nova.api.openstack.compute.contrib.keypairs.Controller object at 0x7fb12a527bd0>>' (Content-type='application/json', Accept='application/json') _process_stack /usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py:945
  2014-10-31 16:40:57.622 3777 DEBUG nova.volume.cinder [req-041f497f-687d-4309-a90f-49c76d889ee4 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332] Cinderclient connection created using URL: http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332 cinderclient /usr/lib/python2.7/dist-packages/nova/volume/cinder.py:93
  2014-10-31 16:40:57.623 3777 INFO urllib3.connectionpool [-] Starting new HTTP connection (1): 62.210.200.76
  2014-10-31 16:40:57.711 3777 DEBUG urllib3.connectionpool [-] "GET /v1/003048198aa94a0bb07b00802931d332/volumes/05afbc5f-7bef-4427-a898-3b480d3bd72b HTTP/1.1" 200 905 _make_request /usr/lib/python2.7/dist-packages/urllib3/connectionpool.py:353
  2014-10-31 16:40:57.715 3777 DEBUG nova.volume.cinder [req-041f497f-687d-4309-a90f-49c76d889ee4 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332] Cinderclient connection created using URL: http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332 cinderclient /usr/lib/python2.7/dist-packages/nova/volume/cinder.py:93
  2014-10-31 16:40:57.716 3777 INFO urllib3.connectionpool [-] Starting new HTTP connection (1): 62.210.200.76
  2014-10-31 16:40:57.804 3777 DEBUG urllib3.connectionpool [-] "GET /v1/003048198aa94a0bb07b00802931d332/volumes/05afbc5f-7bef-4427-a898-3b480d3bd72b HTTP/1.1" 200 905 _make_request /usr/lib/python2.7/dist-packages/urllib3/connectionpool.py:353
  2014-10-31 16:40:57.806 3777 DEBUG nova.volume.cinder [req-041f497f-687d-4309-a90f-49c76d889ee4 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332] Cinderclient connection created using URL: http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332 cinderclient /usr/lib/python2.7/dist-packages/nova/volume/cinder.py:93
  2014-10-31 16:40:57.807 3777 INFO urllib3.connectionpool [-] Starting new HTTP connection (1): 62.210.200.76
  2014-10-31 16:40:57.869 3777 DEBUG urllib3.connectionpool [-] "POST /v1/003048198aa94a0bb07b00802931d332/snapshots HTTP/1.1" 200 282 _make_request /usr/lib/python2.7/dist-packages/urllib3/connectionpool.py:353
  2014-10-31 16:40:57.876 3777 DEBUG glanceclient.common.http [-] curl -i -X POST -H 'x-image-meta-property-root_device_name: /dev/vda' -H 'X-Auth-Token: 050d20ca27f2cbd495f9fda4f398b744' -H 'x-image-meta-property-container_format: bare' -H 'x-image-meta-property-min_ram: 0' -H 'x-image-meta-name: Unbound-snapshot' -H 'User-Agent: python-glanceclient' -H 'X-User-Id: 1e7cb96667d049ccbcbd4aac84ca71b2' -H 'x-image-meta-property-min_disk: 0' -H 'x-image-meta-property-disk_format: qcow2' -H 'x-image-meta-property-size: 291781120' -H 'x-image-meta-property-image_id: 1223acf4-705e-4921-b8f7-8b7b091024df' -H 'x-image-meta-property-block_device_mapping: [{"guest_format": null, "boot_index": 0, "no_device": null, "snapshot_id": "961e49e7-261c-4185-9fec-cd34cf5ac2b6", "delete_on_termination": null, "disk_bus": "virtio", "image_id": null, "source_type": "snapshot", "device_type": "disk", "volume_id": null, "destination_type": "volume", "volume_size": null}]' -H 'X-Service-Catalog: [{"endpoints_links": [], "endpoints": [{"adminURL": "http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332";, "region": "regionOne", "internalURL": "http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332";, "serviceName": "cinder", "id": "2a99fa52cd6c4b02bedc4d04fccf148a", "publicURL": "http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332"}], "type": "volume", "name": "cinder"}]' -H 'x-image-meta-property-image_name: Debian' -H 'x-image-meta-property-checksum: 00a2d4794fb60ddb5a9c7b66e226445e' -H 'x-image-meta-property-bdm_v2: True' -H 'X-Roles: _member_' -H 'x-image-meta-size: 0' -H 'X-Tenant-Id: 003048198aa94a0bb07b00802931d332' -H 'x-image-meta-is_public: False' -H 'X-Identity-Status: Confirmed' -H 'Content-Type: application/octet-stream' http://62.210.200.76:9292/v1/images log_curl_request /usr/lib/python2.7/dist-packages/glanceclient/common/http.py:142
  2014-10-31 16:40:57.911 3777 DEBUG glanceclient.common.http [-] 
  HTTP/1.1 201 Created
  date: Fri, 31 Oct 2014 15:40:57 GMT
  content-length: 1093
  content-type: application/json
  location: http://62.210.200.76:9292/v1/images/c473714b-0ed5-4843-b398-a38c50fea5e6
  x-openstack-request-id: req-73da5622-b98d-4df5-ad51-c3e20b2c6761

  {"image": {"status": "active", "deleted": false, "container_format": null, "min_ram": 0, "updated_at": "2014-10-31T15:40:57", "owner": "003048198aa94a0bb07b00802931d332", "min_disk": 0, "is_public": false, "deleted_at": null, "id": "c473714b-0ed5-4843-b398-a38c50fea5e6", "size": 0, "virtual_size": null, "name": "Unbound-snapshot", "checksum": null, "created_at": "2014-10-31T15:40:57", "disk_format": null, "properties": {"block_device_mapping": "[{\"guest_format\": null, \"boot_index\": 0, \"no_device\": null, \"snapshot_id\": \"961e49e7-261c-4185-9fec-cd34cf5ac2b6\", \"delete_on_termination\": null, \"disk_bus\": \"virtio\", \"image_id\": null, \"source_type\": \"snapshot\", \"device_type\": \"disk\", \"volume_id\": null, \"destination_type\": \"volume\", \"volume_size\": null}]", "checksum": "00a2d4794fb60ddb5a9c7b66e226445e", "min_ram": "0", "disk_format": "qcow2", "image_name": "Debian", "bdm_v2": "True", "image_id": "1223acf4-705e-4921-b8f7-8b7b091024df", "root_device_name": "/dev/vda", "container_format": "bare", "min_disk": "0", "size": "291781120"}, "protected": false}}
   log_http_response /usr/lib/python2.7/dist-packages/glanceclient/common/http.py:152
  2014-10-31 16:40:57.912 3777 INFO nova.osapi_compute.wsgi.server [req-041f497f-687d-4309-a90f-49c76d889ee4 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332] 62.210.200.76 "POST /v2/003048198aa94a0bb07b00802931d332/servers/5749c7ac-7567-4b4d-a3ec-9bf248e4c450/action HTTP/1.1" status: 202 len: 302 time: 0.3487010
  2014-10-31 16:40:57.914 3777 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:666
  2014-10-31 16:40:57.914 3777 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:725
  2014-10-31 16:40:57.915 3777 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1124
  2014-10-31 16:40:57.915 3777 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1234
  2014-10-31 16:40:57.915 3777 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 1e7cb96667d049ccbcbd4aac84ca71b2 with project_id : 003048198aa94a0bb07b00802931d332 and roles: _member_  _build_user_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1021
  2014-10-31 16:40:57.916 3777 DEBUG routes.middleware [-] Matched GET /003048198aa94a0bb07b00802931d332/servers/5749c7ac-7567-4b4d-a3ec-9bf248e4c450 __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
  2014-10-31 16:40:57.916 3777 DEBUG routes.middleware [-] Route path: '/{project_id}/servers/:(id)', defaults: {'action': u'show', 'controller': <nova.api.openstack.wsgi.Resource object at 0x7fb12a909d10>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
  2014-10-31 16:40:57.916 3777 DEBUG routes.middleware [-] Match dict: {'action': u'show', 'controller': <nova.api.openstack.wsgi.Resource object at 0x7fb12a909d10>, 'project_id': u'003048198aa94a0bb07b00802931d332', 'id': u'5749c7ac-7567-4b4d-a3ec-9bf248e4c450'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
  2014-10-31 16:40:57.917 3777 DEBUG nova.api.openstack.wsgi [req-460b2560-5f3b-43e0-a657-0795ebb831d9 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332] Calling method '<bound method Controller.show of <nova.api.openstack.compute.servers.Controller object at 0x7fb12b429c10>>' (Content-type='None', Accept='application/json') _process_stack /usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py:945
  2014-10-31 16:40:57.951 3777 INFO nova.osapi_compute.wsgi.server [req-460b2560-5f3b-43e0-a657-0795ebb831d9 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332] 62.210.200.76 "GET /v2/003048198aa94a0bb07b00802931d332/servers/5749c7ac-7567-4b4d-a3ec-9bf248e4c450 HTTP/1.1" status: 200 len: 1920 time: 0.0372040

  Logs for Cinder:
  2014-10-31 16:43:23.045 6525 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1234
  2014-10-31 16:43:23.046 6525 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 1e7cb96667d049ccbcbd4aac84ca71b2 with project_id : 003048198aa94a0bb07b00802931d332 and roles: _member_  _build_user_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1021
  2014-10-31 16:43:23.046 6525 DEBUG routes.middleware [req-7b0bae66-935f-44e8-b34d-ba8c0e20e809 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Matched GET /003048198aa94a0bb07b00802931d332/snapshots/detail __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
  2014-10-31 16:43:23.046 6525 DEBUG routes.middleware [req-7b0bae66-935f-44e8-b34d-ba8c0e20e809 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Route path: '/{project_id}/snapshots/detail', defaults: {'action': u'detail', 'controller': <cinder.api.openstack.wsgi.Resource object at 0x7f7d0567f090>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
  2014-10-31 16:43:23.047 6525 DEBUG routes.middleware [req-7b0bae66-935f-44e8-b34d-ba8c0e20e809 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Match dict: {'action': u'detail', 'controller': <cinder.api.openstack.wsgi.Resource object at 0x7f7d0567f090>, 'project_id': u'003048198aa94a0bb07b00802931d332'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
  2014-10-31 16:43:23.047 6525 INFO cinder.api.openstack.wsgi [req-7b0bae66-935f-44e8-b34d-ba8c0e20e809 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] GET http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332/snapshots/detail
  2014-10-31 16:43:23.047 6525 DEBUG cinder.api.openstack.wsgi [req-7b0bae66-935f-44e8-b34d-ba8c0e20e809 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Empty body provided in request get_body /usr/lib/python2.7/dist-packages/cinder/api/openstack/wsgi.py:787
  2014-10-31 16:43:23.047 6525 DEBUG cinder.api.v1.volumes [req-7b0bae66-935f-44e8-b34d-ba8c0e20e809 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Removing options '' from query remove_invalid_options /usr/lib/python2.7/dist-packages/cinder/api/v1/volumes.py:506
  2014-10-31 16:43:23.055 6525 INFO cinder.api.openstack.wsgi [req-7b0bae66-935f-44e8-b34d-ba8c0e20e809 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332/snapshots/detail returned with HTTP 200
  2014-10-31 16:43:23.055 6525 INFO eventlet.wsgi.server [req-7b0bae66-935f-44e8-b34d-ba8c0e20e809 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] 62.210.200.76 - - [31/Oct/2014 16:43:23] "GET /v1/003048198aa94a0bb07b00802931d332/snapshots/detail HTTP/1.1" 200 255 0.010933
  2014-10-31 16:43:48.270 6525 INFO eventlet.wsgi.server [-] (6525) accepted ('62.210.200.76', 53364)
  2014-10-31 16:43:48.271 6525 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:666
  2014-10-31 16:43:48.271 6525 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:725
  2014-10-31 16:43:48.272 6525 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1124
  2014-10-31 16:43:48.272 6525 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1234
  2014-10-31 16:43:48.272 6525 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 1e7cb96667d049ccbcbd4aac84ca71b2 with project_id : 003048198aa94a0bb07b00802931d332 and roles: _member_  _build_user_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1021
  2014-10-31 16:43:48.273 6525 DEBUG routes.middleware [req-2c36dcb0-972a-41a8-97f0-c07739555765 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Matched GET /003048198aa94a0bb07b00802931d332/volumes/05afbc5f-7bef-4427-a898-3b480d3bd72b __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
  2014-10-31 16:43:48.274 6525 DEBUG routes.middleware [req-2c36dcb0-972a-41a8-97f0-c07739555765 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Route path: '/{project_id}/volumes/:(id)', defaults: {'action': u'show', 'controller': <cinder.api.openstack.wsgi.Resource object at 0x7f7d05660090>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
  2014-10-31 16:43:48.274 6525 DEBUG routes.middleware [req-2c36dcb0-972a-41a8-97f0-c07739555765 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Match dict: {'action': u'show', 'controller': <cinder.api.openstack.wsgi.Resource object at 0x7f7d05660090>, 'project_id': u'003048198aa94a0bb07b00802931d332', 'id': u'05afbc5f-7bef-4427-a898-3b480d3bd72b'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
  2014-10-31 16:43:48.274 6525 INFO cinder.api.openstack.wsgi [req-2c36dcb0-972a-41a8-97f0-c07739555765 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] GET http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332/volumes/05afbc5f-7bef-4427-a898-3b480d3bd72b
  2014-10-31 16:43:48.275 6525 DEBUG cinder.api.openstack.wsgi [req-2c36dcb0-972a-41a8-97f0-c07739555765 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Empty body provided in request get_body /usr/lib/python2.7/dist-packages/cinder/api/openstack/wsgi.py:787
  2014-10-31 16:43:48.317 6525 AUDIT cinder.api.v1.volumes [req-2c36dcb0-972a-41a8-97f0-c07739555765 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] vol={'migration_status': None, 'availability_zone': u'nova', 'terminated_at': None, 'updated_at': datetime.datetime(2014, 10, 30, 17, 14, 16), 'provider_geometry': None, 'snapshot_id': None, 'ec2_id': None, 'mountpoint': u'vda', 'deleted_at': None, 'id': u'05afbc5f-7bef-4427-a898-3b480d3bd72b', 'size': 5L, 'user_id': u'1e7cb96667d049ccbcbd4aac84ca71b2', 'attach_time': u'2014-10-08T08:50:15.486768', 'attached_host': None, 'display_description': u'', 'encryption_key_id': None, 'project_id': u'003048198aa94a0bb07b00802931d332', 'launched_at': datetime.datetime(2014, 10, 8, 8, 50, 14), 'scheduled_at': datetime.datetime(2014, 10, 8, 8, 49, 57), 'status': u'in-use', 'volume_type_id': None, 'deleted': False, 'provider_location': u'62.210.200.76:3260,7 iqn.2010-10.org.openstack:volume-05afbc5f-7bef-4427-a898-3b480d3bd72b 1', 'host': u'pa01.ygk-cloud.net', 'source_volid': None, 'provider_auth': u'CHAP tTR2TpMtBYkEDZ4feVoq 76u7asMLMBmPHjJmQf2G', 'display_name': u'', 'instance_uuid': u'5749c7ac-7567-4b4d-a3ec-9bf248e4c450', 'bootable': True, 'created_at': datetime.datetime(2014, 10, 8, 8, 49, 57), 'attach_status': u'attached', 'volume_type': None, '_name_id': None, 'volume_metadata': [], 'metadata': {u'readonly': u'False', u'attached_mode': u'rw'}}
  2014-10-31 16:43:48.351 6525 INFO cinder.api.openstack.wsgi [req-2c36dcb0-972a-41a8-97f0-c07739555765 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332/volumes/05afbc5f-7bef-4427-a898-3b480d3bd72b returned with HTTP 200
  2014-10-31 16:43:48.352 6525 INFO eventlet.wsgi.server [req-2c36dcb0-972a-41a8-97f0-c07739555765 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] 62.210.200.76 - - [31/Oct/2014 16:43:48] "GET /v1/003048198aa94a0bb07b00802931d332/volumes/05afbc5f-7bef-4427-a898-3b480d3bd72b HTTP/1.1" 200 1144 0.081481
  2014-10-31 16:43:48.357 6525 INFO eventlet.wsgi.server [-] (6525) accepted ('62.210.200.76', 53365)
  2014-10-31 16:43:48.358 6525 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:666
  2014-10-31 16:43:48.359 6525 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:725
  2014-10-31 16:43:48.359 6525 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1124
  2014-10-31 16:43:48.360 6525 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1234
  2014-10-31 16:43:48.360 6525 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 1e7cb96667d049ccbcbd4aac84ca71b2 with project_id : 003048198aa94a0bb07b00802931d332 and roles: _member_  _build_user_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1021
  2014-10-31 16:43:48.361 6525 DEBUG routes.middleware [req-84bfb5b3-81f8-4532-a412-5114cd7db9dc 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Matched GET /003048198aa94a0bb07b00802931d332/volumes/05afbc5f-7bef-4427-a898-3b480d3bd72b __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
  2014-10-31 16:43:48.361 6525 DEBUG routes.middleware [req-84bfb5b3-81f8-4532-a412-5114cd7db9dc 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Route path: '/{project_id}/volumes/:(id)', defaults: {'action': u'show', 'controller': <cinder.api.openstack.wsgi.Resource object at 0x7f7d05660090>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
  2014-10-31 16:43:48.361 6525 DEBUG routes.middleware [req-84bfb5b3-81f8-4532-a412-5114cd7db9dc 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Match dict: {'action': u'show', 'controller': <cinder.api.openstack.wsgi.Resource object at 0x7f7d05660090>, 'project_id': u'003048198aa94a0bb07b00802931d332', 'id': u'05afbc5f-7bef-4427-a898-3b480d3bd72b'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
  2014-10-31 16:43:48.362 6525 INFO cinder.api.openstack.wsgi [req-84bfb5b3-81f8-4532-a412-5114cd7db9dc 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] GET http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332/volumes/05afbc5f-7bef-4427-a898-3b480d3bd72b
  2014-10-31 16:43:48.362 6525 DEBUG cinder.api.openstack.wsgi [req-84bfb5b3-81f8-4532-a412-5114cd7db9dc 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Empty body provided in request get_body /usr/lib/python2.7/dist-packages/cinder/api/openstack/wsgi.py:787
  2014-10-31 16:43:48.394 6525 AUDIT cinder.api.v1.volumes [req-84bfb5b3-81f8-4532-a412-5114cd7db9dc 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] vol={'migration_status': None, 'availability_zone': u'nova', 'terminated_at': None, 'updated_at': datetime.datetime(2014, 10, 30, 17, 14, 16), 'provider_geometry': None, 'snapshot_id': None, 'ec2_id': None, 'mountpoint': u'vda', 'deleted_at': None, 'id': u'05afbc5f-7bef-4427-a898-3b480d3bd72b', 'size': 5L, 'user_id': u'1e7cb96667d049ccbcbd4aac84ca71b2', 'attach_time': u'2014-10-08T08:50:15.486768', 'attached_host': None, 'display_description': u'', 'encryption_key_id': None, 'project_id': u'003048198aa94a0bb07b00802931d332', 'launched_at': datetime.datetime(2014, 10, 8, 8, 50, 14), 'scheduled_at': datetime.datetime(2014, 10, 8, 8, 49, 57), 'status': u'in-use', 'volume_type_id': None, 'deleted': False, 'provider_location': u'62.210.200.76:3260,7 iqn.2010-10.org.openstack:volume-05afbc5f-7bef-4427-a898-3b480d3bd72b 1', 'host': u'pa01.ygk-cloud.net', 'source_volid': None, 'provider_auth': u'CHAP tTR2TpMtBYkEDZ4feVoq 76u7asMLMBmPHjJmQf2G', 'display_name': u'', 'instance_uuid': u'5749c7ac-7567-4b4d-a3ec-9bf248e4c450', 'bootable': True, 'created_at': datetime.datetime(2014, 10, 8, 8, 49, 57), 'attach_status': u'attached', 'volume_type': None, '_name_id': None, 'volume_metadata': [], 'metadata': {u'readonly': u'False', u'attached_mode': u'rw'}}
  2014-10-31 16:43:48.426 6525 INFO cinder.api.openstack.wsgi [req-84bfb5b3-81f8-4532-a412-5114cd7db9dc 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332/volumes/05afbc5f-7bef-4427-a898-3b480d3bd72b returned with HTTP 200
  2014-10-31 16:43:48.426 6525 INFO eventlet.wsgi.server [req-84bfb5b3-81f8-4532-a412-5114cd7db9dc 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] 62.210.200.76 - - [31/Oct/2014 16:43:48] "GET /v1/003048198aa94a0bb07b00802931d332/volumes/05afbc5f-7bef-4427-a898-3b480d3bd72b HTTP/1.1" 200 1144 0.068342
  2014-10-31 16:43:48.429 6525 INFO eventlet.wsgi.server [-] (6525) accepted ('62.210.200.76', 53366)
  2014-10-31 16:43:48.429 6525 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:666
  2014-10-31 16:43:48.429 6525 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:725
  2014-10-31 16:43:48.430 6525 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1124
  2014-10-31 16:43:48.430 6525 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1234
  2014-10-31 16:43:48.430 6525 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 1e7cb96667d049ccbcbd4aac84ca71b2 with project_id : 003048198aa94a0bb07b00802931d332 and roles: _member_  _build_user_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1021
  2014-10-31 16:43:48.431 6525 DEBUG routes.middleware [req-23c0fb78-d57b-497a-bae7-280fef7f1fbb 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Matched POST /003048198aa94a0bb07b00802931d332/snapshots __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
  2014-10-31 16:43:48.431 6525 DEBUG routes.middleware [req-23c0fb78-d57b-497a-bae7-280fef7f1fbb 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Route path: '/{project_id}/snapshots', defaults: {'action': u'create', 'controller': <cinder.api.openstack.wsgi.Resource object at 0x7f7d0567f090>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
  2014-10-31 16:43:48.432 6525 DEBUG routes.middleware [req-23c0fb78-d57b-497a-bae7-280fef7f1fbb 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Match dict: {'action': u'create', 'controller': <cinder.api.openstack.wsgi.Resource object at 0x7f7d0567f090>, 'project_id': u'003048198aa94a0bb07b00802931d332'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
  2014-10-31 16:43:48.432 6525 INFO cinder.api.openstack.wsgi [req-23c0fb78-d57b-497a-bae7-280fef7f1fbb 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] POST http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332/snapshots
  2014-10-31 16:43:48.445 6525 AUDIT cinder.api.v1.snapshots [req-23c0fb78-d57b-497a-bae7-280fef7f1fbb 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Create snapshot from volume 05afbc5f-7bef-4427-a898-3b480d3bd72b
  2014-10-31 16:43:48.457 6525 DEBUG cinder.quota [req-23c0fb78-d57b-497a-bae7-280fef7f1fbb 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Created reservations ['ac77b3cd-1ebb-4e28-8261-a9ea1edc7397', 'c7764d90-2428-42d0-8027-5a93da71a268'] reserve /usr/lib/python2.7/dist-packages/cinder/quota.py:748
  2014-10-31 16:43:48.477 6525 INFO cinder.api.openstack.wsgi [req-23c0fb78-d57b-497a-bae7-280fef7f1fbb 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] http://62.210.200.76:8776/v1/003048198aa94a0bb07b00802931d332/snapshots returned with HTTP 200
  2014-10-31 16:43:48.478 6525 INFO eventlet.wsgi.server [req-23c0fb78-d57b-497a-bae7-280fef7f1fbb 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] 62.210.200.76 - - [31/Oct/2014 16:43:48] "POST /v1/003048198aa94a0bb07b00802931d332/snapshots HTTP/1.1" 200 521 0.048882

  Logs for Glance:
  2014-10-31 16:27:13.849 36334 INFO urllib3.connectionpool [-] Starting new HTTP connection (1): 127.0.0.1
  2014-10-31 16:27:13.860 36334 DEBUG urllib3.connectionpool [-] "GET /v2.0/tokens/050d20ca27f2cbd495f9fda4f398b744 HTTP/1.1" 200 6986 _make_request /usr/lib/python2.7/dist-packages/urllib3/connectionpool.py:353
  2014-10-31 16:27:13.861 36334 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1234
  2014-10-31 16:27:13.861 36334 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 1e7cb96667d049ccbcbd4aac84ca71b2 with project_id : 003048198aa94a0bb07b00802931d332 and roles: _member_  _build_user_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1021
  2014-10-31 16:27:13.862 36334 DEBUG routes.middleware [7929d396-89e6-46c8-9ee8-6c7af004e283 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Matched GET /images/detail __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
  2014-10-31 16:27:13.863 36334 DEBUG routes.middleware [7929d396-89e6-46c8-9ee8-6c7af004e283 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Route path: '/images/detail', defaults: {'action': u'detail', 'controller': <glance.common.wsgi.Resource object at 0x7ff97dce5850>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
  2014-10-31 16:27:13.863 36334 DEBUG routes.middleware [7929d396-89e6-46c8-9ee8-6c7af004e283 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Match dict: {'action': u'detail', 'controller': <glance.common.wsgi.Resource object at 0x7ff97dce5850>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
  2014-10-31 16:27:13.864 36334 DEBUG glance.common.client [7929d396-89e6-46c8-9ee8-6c7af004e283 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Constructed URL: http://127.0.0.1:9191/images/detail?limit=1000 _construct_url /usr/lib/python2.7/dist-packages/glance/common/client.py:411
  2014-10-31 16:27:13.955 36334 DEBUG glance.registry.client.v1.client [7929d396-89e6-46c8-9ee8-6c7af004e283 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Registry request GET /images/detail HTTP 200 request id req-453bf079-53a3-4d9b-a27a-5cacccf48e02 do_request /usr/lib/python2.7/dist-packages/glance/registry/client/v1/client.py:114
  2014-10-31 16:27:13.956 36334 INFO glance.wsgi.server [7929d396-89e6-46c8-9ee8-6c7af004e283 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] 62.210.200.76 - - [31/Oct/2014 16:27:13] "GET /v1/images/detail?limit=1000 HTTP/1.1" 200 6471 0.110902
  2014-10-31 16:28:06.636 36334 DEBUG glance.api.middleware.version_negotiation [-] Determining version of request: POST /v1/images Accept:  process_request /usr/lib/python2.7/dist-packages/glance/api/middleware/version_negotiation.py:44
  2014-10-31 16:28:06.636 36334 DEBUG glance.api.middleware.version_negotiation [-] Using url versioning process_request /usr/lib/python2.7/dist-packages/glance/api/middleware/version_negotiation.py:57
  2014-10-31 16:28:06.637 36334 DEBUG glance.api.middleware.version_negotiation [-] Matched version: v1 process_request /usr/lib/python2.7/dist-packages/glance/api/middleware/version_negotiation.py:69
  2014-10-31 16:28:06.637 36334 DEBUG glance.api.middleware.version_negotiation [-] new path /v1/images process_request /usr/lib/python2.7/dist-packages/glance/api/middleware/version_negotiation.py:70
  2014-10-31 16:28:06.637 36334 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:666
  2014-10-31 16:28:06.637 36334 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:725
  2014-10-31 16:28:06.638 36334 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1124
  2014-10-31 16:28:06.638 36334 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1234
  2014-10-31 16:28:06.638 36334 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 1e7cb96667d049ccbcbd4aac84ca71b2 with project_id : 003048198aa94a0bb07b00802931d332 and roles: _member_  _build_user_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1021
  2014-10-31 16:28:06.639 36334 DEBUG routes.middleware [e866bc71-b998-4040-8337-3bf3e4b5e86c 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Matched POST /images __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
  2014-10-31 16:28:06.639 36334 DEBUG routes.middleware [e866bc71-b998-4040-8337-3bf3e4b5e86c 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Route path: '/images', defaults: {'action': u'create', 'controller': <glance.common.wsgi.Resource object at 0x7ff97dce5850>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
  2014-10-31 16:28:06.639 36334 DEBUG routes.middleware [e866bc71-b998-4040-8337-3bf3e4b5e86c 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Match dict: {'action': u'create', 'controller': <glance.common.wsgi.Resource object at 0x7ff97dce5850>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
  2014-10-31 16:28:06.640 36334 DEBUG glance.registry.client.v1.api [e866bc71-b998-4040-8337-3bf3e4b5e86c 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Adding image metadata... add_image_metadata /usr/lib/python2.7/dist-packages/glance/registry/client/v1/api.py:159
  2014-10-31 16:28:06.640 36334 DEBUG glance.common.client [e866bc71-b998-4040-8337-3bf3e4b5e86c 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Constructed URL: http://127.0.0.1:9191/images _construct_url /usr/lib/python2.7/dist-packages/glance/common/client.py:411
  2014-10-31 16:28:06.662 36334 DEBUG glance.registry.client.v1.client [e866bc71-b998-4040-8337-3bf3e4b5e86c 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Registry request POST /images HTTP 200 request id req-17c8d593-ec12-4646-8411-ba31ee4203af do_request /usr/lib/python2.7/dist-packages/glance/registry/client/v1/client.py:114
  2014-10-31 16:28:06.663 36334 DEBUG oslo.messaging._drivers.amqp [e866bc71-b998-4040-8337-3bf3e4b5e86c 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] UNIQUE_ID is e1d554d149694eccbe2ff252a1fd9d42. _add_unique_id /usr/lib/python2.7/dist-packages/oslo/messaging/_drivers/amqp.py:338
  2014-10-31 16:28:06.666 36334 INFO glance.wsgi.server [e866bc71-b998-4040-8337-3bf3e4b5e86c 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] 62.210.200.76 - - [31/Oct/2014 16:28:06] "POST /v1/images HTTP/1.1" 201 1358 0.030131
  2014-10-31 16:28:06.760 36334 DEBUG glance.api.middleware.version_negotiation [-] Determining version of request: GET /v1/images/detail Accept:  process_request /usr/lib/python2.7/dist-packages/glance/api/middleware/version_negotiation.py:44
  2014-10-31 16:28:06.761 36334 DEBUG glance.api.middleware.version_negotiation [-] Using url versioning process_request /usr/lib/python2.7/dist-packages/glance/api/middleware/version_negotiation.py:57
  2014-10-31 16:28:06.761 36334 DEBUG glance.api.middleware.version_negotiation [-] Matched version: v1 process_request /usr/lib/python2.7/dist-packages/glance/api/middleware/version_negotiation.py:69
  2014-10-31 16:28:06.762 36334 DEBUG glance.api.middleware.version_negotiation [-] new path /v1/images/detail process_request /usr/lib/python2.7/dist-packages/glance/api/middleware/version_negotiation.py:70
  2014-10-31 16:28:06.762 36334 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:666
  2014-10-31 16:28:06.762 36334 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:725
  2014-10-31 16:28:06.763 36334 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1124
  2014-10-31 16:28:06.763 36334 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1234
  2014-10-31 16:28:06.763 36334 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: 1e7cb96667d049ccbcbd4aac84ca71b2 with project_id : 003048198aa94a0bb07b00802931d332 and roles: _member_  _build_user_headers /usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py:1021
  2014-10-31 16:28:06.764 36334 DEBUG routes.middleware [a32f7a5f-eec3-42f2-8b0f-614090bfab7a 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Matched GET /images/detail __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
  2014-10-31 16:28:06.764 36334 DEBUG routes.middleware [a32f7a5f-eec3-42f2-8b0f-614090bfab7a 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Route path: '/images/detail', defaults: {'action': u'detail', 'controller': <glance.common.wsgi.Resource object at 0x7ff97dce5850>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
  2014-10-31 16:28:06.765 36334 DEBUG routes.middleware [a32f7a5f-eec3-42f2-8b0f-614090bfab7a 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Match dict: {'action': u'detail', 'controller': <glance.common.wsgi.Resource object at 0x7ff97dce5850>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
  2014-10-31 16:28:06.765 36334 DEBUG glance.common.client [a32f7a5f-eec3-42f2-8b0f-614090bfab7a 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Constructed URL: http://127.0.0.1:9191/images/detail?limit=1000 _construct_url /usr/lib/python2.7/dist-packages/glance/common/client.py:411
  2014-10-31 16:28:06.816 36334 DEBUG glance.registry.client.v1.client [a32f7a5f-eec3-42f2-8b0f-614090bfab7a 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] Registry request GET /images/detail HTTP 200 request id req-a4f1234c-b930-4854-8bb1-dae09d8f1a40 do_request /usr/lib/python2.7/dist-packages/glance/registry/client/v1/client.py:114
  2014-10-31 16:28:06.818 36334 INFO glance.wsgi.server [a32f7a5f-eec3-42f2-8b0f-614090bfab7a 1e7cb96667d049ccbcbd4aac84ca71b2 003048198aa94a0bb07b00802931d332 - - -] 62.210.200.76 - - [31/Oct/2014 16:28:06] "GET /v1/images/detail?limit=1000 HTTP/1.1" 200 7555 0.057574

To manage notifications about this bug go to:
https://bugs.launchpad.net/glance/+bug/1388912/+subscriptions
Follow ups

[Bug 1388912] Re: Snapshot with image size 0 bits
From: Abhishek Kekane, 2018-04-20
[Bug 1388912] [NEW] Snapshot with image size 0 bits
From: Boris Tassou, 2014-11-03
References

[Bug 1388912] [NEW] Snapshot with image size 0 bits
From: Boris Tassou, 2014-11-03