Open Stack

Have you tried pulling the patch directly and retesting?

$ git fetch https://review.openstack.org/openstack/nova refs/changes/98/40298/18 && git checkout FETCH_HEAD

I just pulled the change by itself (for the sake of paranoia) and tested it manually. It works fine in isolation. For my test I used "nova image-create" then booted an instance from the new image. This all worked fine.

# Shawn Hartsock

----- Original Message -----
> From: "openstack learner" <openstackleaner at gmail.com>
> To: openstack-dev at lists.openstack.org
> Sent: Monday, September 23, 2013 5:00:58 PM
> Subject: [openstack-dev] [Openstack] Snapshot failure with VMwareVCDriver
> 
> Hi all,
> 
> There was a bug fixed on the snapshot failure in* **Snapshot failure with
> VMwareVCDriver* https://review.openstack.org/#/c/40298
> 
> 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. However, the
> snapshot stilled failed in my case.
> 
> 
> 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
> >
> 
> _______________________________________________
> OpenStack-dev mailing list
> OpenStack-dev at lists.openstack.org
> http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev
>