Open Stack

Hi all,

After git clone the newest devstack repository on sep23 2013  and reinstall
devstack, when i did a snapshot it still failed.

This time, from the vCenter task history i could see both the  "Create
virtual machine snapshot" and the "Copy virtual disk" operation are
completed successfully. There was a "Copy virtual disk" operation failure
before and now this issue is fixed in the new code i think.

>From the horizon, the new created snapshot image status was firstly
"queued" and then "deleted". And the snapshot image is not in the list when
i do a nova image-list, glance image-list or look at the horizon
image&snapshot list.

>From the screen "*g-reg*" log, I found it seems like the snapshot image was
created and then deleted before glance upload the image.

The output log is shown as followed:

2013-09-23 12:49:46.634 13386 INFO glance.registry.api.v1.images
[61f1aefc-e56b-481e-ac5d-23e5c8a1ab6c 1e1e314becc94d2ebe8246f0a36ca99a
09ee20f776914ad7983bb2ace867623a] Successfully retrieved image
66e47135-8576-49af-a474-47a11de0c46d
2013-09-23 12:50:09.126 13386 DEBUG keystoneclient.middleware.auth_token
[-] Authenticating user token __call__
/opt/stack/python-keystoneclient/keystoneclient/middleware/auth_token.py:532
2013-09-23 12:50:09.126 13386 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
/opt/stack/python-keystoneclient/keystoneclient/middleware/auth_token.py:591
2013-09-23 12:50:09.126 13386 DEBUG keystoneclient.middleware.auth_token
[-] Returning cached token a06afb4e1371592a52ee6cb53b0e2bae _cache_get
/opt/stack/python-keystoneclient/keystoneclient/middleware/auth_token.py:982
2013-09-23 12:50:09.127 13386 DEBUG glance.api.policy [-] Loaded policy
rules: {u'context_is_admin': 'role:admin', u'default': '@',
u'manage_image_cache': 'role:admin'} load_rules
/opt/stack/glance/glance/api/policy.py:75
2013-09-23 12:50:09.127 13386 DEBUG routes.middleware [-] Matched GET
/images/66e47135-8576-49af-a474-47a11de0c46d __call__
/usr/lib/python2.7/dist-packages/routes/middleware.py:100
2013-09-23 12:50:09.127 13386 DEBUG routes.middleware [-] Route path:
'/images/{id}', defaults: {'action': u'show', 'controller':
<glance.common.wsgi.Resource object at 0x279ba50>} __call__
/usr/lib/python2.7/dist-packages/routes/middleware.py:102
2013-09-23 12:50:09.127 13386 DEBUG routes.middleware [-] Match dict:
{'action': u'show', 'controller': <glance.common.wsgi.Resource object at
0x279ba50>, 'id': u'66e47135-8576-49af-a474-47a11de0c46d'} __call__
/usr/lib/python2.7/dist-packages/routes/middleware.py:103
2013-09-23 12:50:09.138 13386 INFO glance.registry.api.v1.images
[fa8c8425-0637-45cc-a80f-c188a787ad41 1e1e314becc94d2ebe8246f0a36ca99a
09ee20f776914ad7983bb2ace867623a] Successfully retrieved image
66e47135-8576-49af-a474-47a11de0c46d
2013-09-23 12:50:34.130 13386 DEBUG keystoneclient.middleware.auth_token
[-] Authenticating user token __call__
/opt/stack/python-keystoneclient/keystoneclient/middleware/auth_token.py:532
2013-09-23 12:50:34.131 13386 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
/opt/stack/python-keystoneclient/keystoneclient/middleware/auth_token.py:591
2013-09-23 12:50:34.131 13386 DEBUG keystoneclient.middleware.auth_token
[-] Returning cached token a06afb4e1371592a52ee6cb53b0e2bae _cache_get
/opt/stack/python-keystoneclient/keystoneclient/middleware/auth_token.py:982
2013-09-23 12:50:34.131 13386 DEBUG glance.api.policy [-] Loaded policy
rules: {u'context_is_admin': 'role:admin', u'default': '@',
u'manage_image_cache': 'role:admin'} load_rules
/opt/stack/glance/glance/api/policy.py:75
2013-09-23 12:50:34.132 13386 DEBUG routes.middleware [-] Matched GET
/images/66e47135-8576-49af-a474-47a11de0c46d __call__
/usr/lib/python2.7/dist-packages/routes/middleware.py:100
2013-09-23 12:50:34.132 13386 DEBUG routes.middleware [-] Route path:
'/images/{id}', defaults: {'action': u'show', 'controller':
<glance.common.wsgi.Resource object at 0x279ba50>} __call__
/usr/lib/python2.7/dist-packages/routes/middleware.py:102
2013-09-23 12:50:34.132 13386 DEBUG routes.middleware [-] Match dict:
{'action': u'show', 'controller': <glance.common.wsgi.Resource object at
0x279ba50>, 'id': u'66e47135-8576-49af-a474-47a11de0c46d'} __call__
/usr/lib/python2.7/dist-packages/routes/middleware.py:103
2013-09-23 12:50:34.139 13386 INFO glance.registry.api.v1.images
[5d0b9eec-b064-40b2-8db7-aeeb1f88c97e 1e1e314becc94d2ebe8246f0a36ca99a
09ee20f776914ad7983bb2ace867623a] Successfully retrieved image
66e47135-8576-49af-a474-47a11de0c46d
2013-09-23 12:50:54.527 13386 DEBUG keystoneclient.middleware.auth_token
[-] Authenticating user token __call__
/opt/stack/python-keystoneclient/keystoneclient/middleware/auth_token.py:532
2013-09-23 12:50:54.527 13386 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
/opt/stack/python-keystoneclient/keystoneclient/middleware/auth_token.py:591
2013-09-23 12:50:54.528 13386 DEBUG keystoneclient.middleware.auth_token
[-] Returning cached token a06afb4e1371592a52ee6cb53b0e2bae _cache_get
/opt/stack/python-keystoneclient/keystoneclient/middleware/auth_token.py:982
2013-09-23 12:50:54.528 13386 DEBUG glance.api.policy [-] Loaded policy
rules: {u'context_is_admin': 'role:admin', u'default': '@',
u'manage_image_cache': 'role:admin'} load_rules
/opt/stack/glance/glance/api/policy.py:75
2013-09-23 12:50:54.528 13386 DEBUG routes.middleware [-] Matched GET
/images/66e47135-8576-49af-a474-47a11de0c46d __call__
/usr/lib/python2.7/dist-packages/routes/middleware.py:100
2013-09-23 12:50:54.529 13386 DEBUG routes.middleware [-] Route path:
'/images/{id}', defaults: {'action': u'show', 'controller':
<glance.common.wsgi.Resource object at 0x279ba50>} __call__
/usr/lib/python2.7/dist-packages/routes/middleware.py:102
2013-09-23 12:50:54.529 13386 DEBUG routes.middleware [-] Match dict:
{'action': u'show', 'controller': <glance.common.wsgi.Resource object at
0x279ba50>, 'id': u'66e47135-8576-49af-a474-47a11de0c46d'} __call__
/usr/lib/python2.7/dist-packages/routes/middleware.py:103
2013-09-23 12:50:54.535 13386 INFO glance.registry.api.v1.images
[3681cb8b-f9b2-480e-b0b1-a05a08649701 1e1e314becc94d2ebe8246f0a36ca99a
09ee20f776914ad7983bb2ace867623a] Successfully retrieved image
66e47135-8576-49af-a474-47a11de0c46d
2013-09-23 12:50:54.538 13386 DEBUG keystoneclient.middleware.auth_token
[-] Authenticating user token __call__
/opt/stack/python-keystoneclient/keystoneclient/middleware/auth_token.py:532
2013-09-23 12:50:54.538 13386 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
/opt/stack/python-keystoneclient/keystoneclient/middleware/auth_token.py:591
2013-09-23 12:50:54.538 13386 DEBUG keystoneclient.middleware.auth_token
[-] Returning cached token a06afb4e1371592a52ee6cb53b0e2bae _cache_get
/opt/stack/python-keystoneclient/keystoneclient/middleware/auth_token.py:982
2013-09-23 12:50:54.539 13386 DEBUG glance.api.policy [-] Loaded policy
rules: {u'context_is_admin': 'role:admin', u'default': '@',
u'manage_image_cache': 'role:admin'} load_rules
/opt/stack/glance/glance/api/policy.py:75
2013-09-23 12:50:54.539 13386 DEBUG routes.middleware [-] Matched PUT
/images/66e47135-8576-49af-a474-47a11de0c46d __call__
/usr/lib/python2.7/dist-packages/routes/middleware.py:100
2013-09-23 12:50:54.539 13386 DEBUG routes.middleware [-] Route path:
'/images/{id}', defaults: {'action': u'update', 'controller':
<glance.common.wsgi.Resource object at 0x279ba50>} __call__
/usr/lib/python2.7/dist-packages/routes/middleware.py:102
2013-09-23 12:50:54.540 13386 DEBUG routes.middleware [-] Match dict:
{'action': u'update', 'controller': <glance.common.wsgi.Resource object at
0x279ba50>, 'id': u'66e47135-8576-49af-a474-47a11de0c46d'} __call__
/usr/lib/python2.7/dist-packages/routes/middleware.py:103
2013-09-23 12:50:54.540 13386 DEBUG glance.registry.api.v1.images
[a5473e1c-63d4-447e-9ebf-363f4176bebc 1e1e314becc94d2ebe8246f0a36ca99a
09ee20f776914ad7983bb2ace867623a] Updating image
66e47135-8576-49af-a474-47a11de0c46d with metadata: {u'status': u'deleted'}
update /opt/stack/glance/glance/registry/api/v1/images.py:436
2013-09-23 12:50:54.555 13386 INFO glance.registry.api.v1.images
[a5473e1c-63d4-447e-9ebf-363f4176bebc 1e1e314becc94d2ebe8246f0a36ca99a
09ee20f776914ad7983bb2ace867623a] Updating metadata for image
66e47135-8576-49af-a474-47a11de0c46d
2013-09-23 12:50:54.558 13386 DEBUG keystoneclient.middleware.auth_token
[-] Authenticating user token __call__
/opt/stack/python-keystoneclient/keystoneclient/middleware/auth_token.py:532
2013-09-23 12:50:54.558 13386 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
/opt/stack/python-keystoneclient/keystoneclient/middleware/auth_token.py:591
2013-09-23 12:50:54.558 13386 DEBUG keystoneclient.middleware.auth_token
[-] Returning cached token a06afb4e1371592a52ee6cb53b0e2bae _cache_get
/opt/stack/python-keystoneclient/keystoneclient/middleware/auth_token.py:982
2013-09-23 12:50:54.559 13386 DEBUG glance.api.policy [-] Loaded policy
rules: {u'context_is_admin': 'role:admin', u'default': '@',
u'manage_image_cache': 'role:admin'} load_rules
/opt/stack/glance/glance/api/policy.py:75
2013-09-23 12:50:54.559 13386 DEBUG routes.middleware [-] Matched DELETE
/images/66e47135-8576-49af-a474-47a11de0c46d __call__
/usr/lib/python2.7/dist-packages/routes/middleware.py:100
2013-09-23 12:50:54.559 13386 DEBUG routes.middleware [-] Route path:
'/images/{id}', defaults: {'action': u'delete', 'controller':
<glance.common.wsgi.Resource object at 0x279ba50>} __call__
/usr/lib/python2.7/dist-packages/routes/middleware.py:102
2013-09-23 12:50:54.559 13386 DEBUG routes.middleware [-] Match dict:
{'action': u'delete', 'controller': <glance.common.wsgi.Resource object at
0x279ba50>, 'id': u'66e47135-8576-49af-a474-47a11de0c46d'} __call__
/usr/lib/python2.7/dist-packages/routes/middleware.py:103
2013-09-23 12:50:54.591 13386 INFO glance.registry.api.v1.images
[681e3d40-ecaa-42be-beb8-fc972a2997a5 1e1e314becc94d2ebe8246f0a36ca99a
09ee20f776914ad7983bb2ace867623a] Successfully deleted image
66e47135-8576-49af-a474-47a11de0c46d
2013-09-23 12:51:01.650 13386 DEBUG keystoneclient.middleware.auth_token
[-] Authenticating user token __call__
/opt/stack/python-keystoneclient/keystoneclient/middleware/auth_token.py:532
2013-09-23 12:51:01.650 13386 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
/opt/stack/python-keystoneclient/keystoneclient/middleware/auth_token.py:591
2013-09-23 12:51:01.651 13386 INFO requests.packages.urllib3.connectionpool
[-] Starting new HTTP connection (1): 172.20.239.92
2013-09-23 12:51:01.664 13386 DEBUG
requests.packages.urllib3.connectionpool [-] "GET
/v2.0/tokens/a06afb4e1371592a52ee6cb53b0e2bae HTTP/1.1" 200 5371
_make_request
/usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:296
2013-09-23 12:51:01.664 13386 DEBUG keystoneclient.middleware.auth_token
[-] Storing a06afb4e1371592a52ee6cb53b0e2bae token in memcache _cache_put
/opt/stack/python-keystoneclient/keystoneclient/middleware/auth_token.py:1042
2013-09-23 12:51:01.665 13386 DEBUG glance.api.policy [-] Loaded policy
rules: {u'context_is_admin': 'role:admin', u'default': '@',
u'manage_image_cache': 'role:admin'} load_rules
/opt/stack/glance/glance/api/policy.py:75
2013-09-23 12:51:01.665 13386 DEBUG routes.middleware [-] Matched GET
/images/66e47135-8576-49af-a474-47a11de0c46d __call__
/usr/lib/python2.7/dist-packages/routes/middleware.py:100
2013-09-23 12:51:01.665 13386 DEBUG routes.middleware [-] Route path:
'/images/{id}', defaults: {'action': u'show', 'controller':
<glance.common.wsgi.Resource object at 0x279ba50>} __call__
/usr/lib/python2.7/dist-packages/routes/middleware.py:102
2013-09-23 12:51:01.665 13386 DEBUG routes.middleware [-] Match dict:
{'action': u'show', 'controller': <glance.common.wsgi.Resource object at
0x279ba50>, 'id': u'66e47135-8576-49af-a474-47a11de0c46d'} __call__
/usr/lib/python2.7/dist-packages/routes/middleware.py:103
2013-09-23 12:51:01.671 13386 DEBUG glance.db.sqlalchemy.api
[94099a83-19e1-40c1-b592-dd61013caf7a 1e1e314becc94d2ebe8246f0a36ca99a
09ee20f776914ad7983bb2ace867623a] No image found with ID
66e47135-8576-49af-a474-47a11de0c46d _image_get
/opt/stack/glance/glance/db/sqlalchemy/api.py:334
2013-09-23 12:51:01.671 13386 INFO glance.registry.api.v1.images
[94099a83-19e1-40c1-b592-dd61013caf7a 1e1e314becc94d2ebe8246f0a36ca99a
09ee20f776914ad7983bb2ace867623a] Image
66e47135-8576-49af-a474-47a11de0c46d not found
2013-09-23 12:57:51.769 13386 DEBUG keystoneclient.middleware.auth_token
[-] Authenticating user token __call__
/opt/stack/python-keystoneclient/keystoneclient/middleware/auth_token.py:532
2013-09-23 12:57:51.769 13386 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
/opt/stack/python-keystoneclient/keystoneclient/middleware/auth_token.py:591
2013-09-23 12:57:51.770 13386 INFO requests.packages.urllib3.connectionpool
[-] Starting new HTTP connection (1): 172.20.239.92
2013-09-23 12:57:51.797 13386 DEBUG
requests.packages.urllib3.connectionpool [-] "GET /v2.0/tokens/revoked
HTTP/1.1" 200 794 _make_request
/usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:296
2013-09-23 12:57:51.809 13386 DEBUG keystoneclient.middleware.auth_token
[-] Storing e8ba2019300908551e0c6ccb766af4e6 token in memcache _cache_put
/opt/stack/python-keystoneclient/keystoneclient/middleware/auth_token.py:1042
2013-09-23 12:57:51.811 13386 DEBUG glance.api.policy [-] Loaded policy
rules: {u'context_is_admin': 'role:admin', u'default': '@',
u'manage_image_cache': 'role:admin'} load_rules
/opt/stack/glance/glance/api/policy.py:75
2013-09-23 12:57:51.811 13386 DEBUG routes.middleware [-] Matched GET
/images/detail __call__
/usr/lib/python2.7/dist-packages/routes/middleware.py:100
2013-09-23 12:57:51.811 13386 DEBUG routes.middleware [-] Route path:
'/images/detail', defaults: {'action': u'detail', 'controller':
<glance.common.wsgi.Resource object at 0x279ba50>} __call__
/usr/lib/python2.7/dist-packages/routes/middleware.py:102
2013-09-23 12:57:51.811 13386 DEBUG routes.middleware [-] Match dict:
{'action': u'detail', 'controller': <glance.common.wsgi.Resource object at
0x279ba50>} __call__
/usr/lib/python2.7/dist-packages/routes/middleware.py:103
2013-09-23 12:57:51.833 13386 INFO glance.registry.api.v1.images
[8fe70cc1-bee3-4629-91fa-0f6aa0acbcc4 1e1e314becc94d2ebe8246f0a36ca99a
09ee20f776914ad7983bb2ace867623a] Returning detailed image list



Any idea about what caused the problem?   Does it mean that the bug has not
been totally fixed, anything wrong with my devstack setting or openstack
service?

Thanks
xin



On Sun, Sep 22, 2013 at 11:05 PM, Chinmaya Bharadwaj A <
acbharadwaj at hotmail.com> wrote:

> there is a bug filed, but supposed to be fixed by now.
> https://bugs.launchpad.net/nova/+bug/1184807
> just check you have these changes
> https://review.openstack.org/#/c/40298/18
>
> regards
> Chinmay
>
> ------------------------------
> Date: Sun, 22 Sep 2013 19:02:02 -0700
> From: openstackleaner at gmail.com
> To: openstack at lists.openstack.org
> Subject: [Openstack] Snapshot failure with VMwareVCDriver
>
>
>
> I am unable to get snapshots working in my devstack setup with the
> VCDriver.
>
> When I tried to snapshot a vm instance, in the glance image-list, i could
> firstly see a new image was create and the status was "saving", few seconds
> later the new created image entry disappeared from the image list and when
> i check the vCenter, in the task history i found the "Create virtual
> machine snapshot" operation is completed but there is an error of the "Copy
> virtual disk" operation:  "The requested operation is not implemented by
> the server."
>
> Anyone has the same problem and know how to solve it?  Any idea about what
> caused the problem?   Is this a bug of vmware api with the devstack?
>
> Thanks
>
> xin
>
> _______________________________________________ Mailing list:
> http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack Post to :
> openstack at lists.openstack.org Unsubscribe :
> http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openstack.org/pipermail/openstack/attachments/20130923/9c5fe09f/attachment.html>