cinder-volume-usage-audit breaks when upgrading from Kilo to Liberty

Bug #1517763 reported by Tobias Urdin on 2015-11-19
14
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Cinder
Undecided
Michal Dulko
Ubuntu Cloud Archive
Undecided
Unassigned
Icehouse
Medium
Unassigned
Kilo
Medium
Unassigned
cinder (Ubuntu)
Undecided
Unassigned
trusty (Ubuntu)
Undecided
Unassigned

Bug Description

The cinder-volume-usage-audit utility breaks when upgrading from Kilo to Liberty.
I think it should be something that is changed in the database which causing this issue.

This is the output from our test environment having two volumes which as you can see it fails on the
iteration of both.

No handlers could be found for logger "oslo_config.cfg"
/usr/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py:241: NotSupportedWarning: Configuration option(s) ['use_tpool'] not supported
  exception.NotSupportedWarning
2015-11-19 08:50:31.946 23397 ERROR cinder [req-cd131e13-3266-485e-8158-4adcb329a1a3 - - - - -] Exists volume notification failed: Parent instance <Volume at 0x7f48daac13d0> is not bound to a Session; lazy load operation of attribute 'volume_metadata' cannot proceed
2015-11-19 08:50:31.946 23397 ERROR cinder Traceback (most recent call last):
2015-11-19 08:50:31.946 23397 ERROR cinder File "/usr/lib/python2.7/dist-packages/cinder/cmd/volume_usage_audit.py", line 120, in main
2015-11-19 08:50:31.946 23397 ERROR cinder 'exists', extra_usage_info=extra_info)
2015-11-19 08:50:31.946 23397 ERROR cinder File "/usr/lib/python2.7/dist-packages/cinder/volume/utils.py", line 125, in notify_about_volume_usage
2015-11-19 08:50:31.946 23397 ERROR cinder usage_info = _usage_from_volume(context, volume, **extra_usage_info)
2015-11-19 08:50:31.946 23397 ERROR cinder File "/usr/lib/python2.7/dist-packages/cinder/volume/utils.py", line 75, in _usage_from_volume
2015-11-19 08:50:31.946 23397 ERROR cinder metadata=volume_ref.get('volume_metadata'),)
2015-11-19 08:50:31.946 23397 ERROR cinder File "/usr/lib/python2.7/dist-packages/oslo_db/sqlalchemy/models.py", line 68, in get
2015-11-19 08:50:31.946 23397 ERROR cinder return getattr(self, key, default)
2015-11-19 08:50:31.946 23397 ERROR cinder File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/attributes.py", line 237, in __get__
2015-11-19 08:50:31.946 23397 ERROR cinder return self.impl.get(instance_state(instance), dict_)
2015-11-19 08:50:31.946 23397 ERROR cinder File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/attributes.py", line 578, in get
2015-11-19 08:50:31.946 23397 ERROR cinder value = self.callable_(state, passive)
2015-11-19 08:50:31.946 23397 ERROR cinder File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/strategies.py", line 502, in _load_for_state
2015-11-19 08:50:31.946 23397 ERROR cinder (orm_util.state_str(state), self.key)
2015-11-19 08:50:31.946 23397 ERROR cinder DetachedInstanceError: Parent instance <Volume at 0x7f48daac13d0> is not bound to a Session; lazy load operation of attribute 'volume_metadata' cannot proceed
2015-11-19 08:50:31.946 23397 ERROR cinder
2015-11-19 08:50:31.950 23397 ERROR cinder [req-cd131e13-3266-485e-8158-4adcb329a1a3 - - - - -] Exists volume notification failed: Parent instance <Volume at 0x7f48daac1450> is not bound to a Session; lazy load operation of attribute 'volume_metadata' cannot proceed
2015-11-19 08:50:31.950 23397 ERROR cinder Traceback (most recent call last):
2015-11-19 08:50:31.950 23397 ERROR cinder File "/usr/lib/python2.7/dist-packages/cinder/cmd/volume_usage_audit.py", line 120, in main
2015-11-19 08:50:31.950 23397 ERROR cinder 'exists', extra_usage_info=extra_info)
2015-11-19 08:50:31.950 23397 ERROR cinder File "/usr/lib/python2.7/dist-packages/cinder/volume/utils.py", line 125, in notify_about_volume_usage
2015-11-19 08:50:31.950 23397 ERROR cinder usage_info = _usage_from_volume(context, volume, **extra_usage_info)
2015-11-19 08:50:31.950 23397 ERROR cinder File "/usr/lib/python2.7/dist-packages/cinder/volume/utils.py", line 75, in _usage_from_volume
2015-11-19 08:50:31.950 23397 ERROR cinder metadata=volume_ref.get('volume_metadata'),)
2015-11-19 08:50:31.950 23397 ERROR cinder File "/usr/lib/python2.7/dist-packages/oslo_db/sqlalchemy/models.py", line 68, in get
2015-11-19 08:50:31.950 23397 ERROR cinder return getattr(self, key, default)
2015-11-19 08:50:31.950 23397 ERROR cinder File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/attributes.py", line 237, in __get__
2015-11-19 08:50:31.950 23397 ERROR cinder return self.impl.get(instance_state(instance), dict_)
2015-11-19 08:50:31.950 23397 ERROR cinder File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/attributes.py", line 578, in get
2015-11-19 08:50:31.950 23397 ERROR cinder value = self.callable_(state, passive)
2015-11-19 08:50:31.950 23397 ERROR cinder File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/strategies.py", line 502, in _load_for_state
2015-11-19 08:50:31.950 23397 ERROR cinder (orm_util.state_str(state), self.key)
2015-11-19 08:50:31.950 23397 ERROR cinder DetachedInstanceError: Parent instance <Volume at 0x7f48daac1450> is not bound to a Session; lazy load operation of attribute 'volume_metadata' cannot proceed
2015-11-19 08:50:31.950 23397 ERROR cinder

Tobias Urdin (tobias-urdin) wrote :

Error is suppressed when commeting out the metadata line in the dict at /usr/lib/python2.7/dist-packages/cinder/volume/utils.py line 75.
So this should be an issue with the sqlalchemy query which is incorrect or some value checking is wrong since my volumes dont have any volume_metadata entries in the database.

I don't know what impact removing this line has.

Tobias Urdin (tobias-urdin) wrote :

I fail to see what purpose loading any metadata would be relevant for the cinder-volume-usage-audit auditing process.

Tobias Urdin (tobias-urdin) wrote :

I won't submit any change for this because I don't know what it affects but I will just include it here if anybody has the same error message and want to have is suppressed.

Tobias Urdin (tobias-urdin) wrote :

Here is a quick fix by Michal Dulko (dulek) after talking on IRC, he will work out a review fix for this when he has time I don't have the knowledge to dig deeper into this.

Ignore my ugly fix above and instead use this one if you are really in need of a quick fix.
Please note we cannot guarantee this causes any other issues since it hasn't been tested properly.

In /usr/lib/python2.7/dist-packages/cinder/db/sqlalchemy/api.py add the change on line 10 in the following paste.
http://paste.openstack.org/show/479381/

Changed in cinder:
assignee: nobody → Tobias Urdin (tobias-urdin)
assignee: Tobias Urdin (tobias-urdin) → nobody
status: New → Confirmed
Changed in cinder:
assignee: nobody → Michal Dulko (michal-dulko-f)
status: Confirmed → In Progress
tags: added: liberty-backport-potential

Reviewed: https://review.openstack.org/248035
Committed: https://git.openstack.org/cgit/openstack/cinder/commit/?id=586727cef755abeb3360f176782c1b1dd680d318
Submitter: Jenkins
Branch: master

commit 586727cef755abeb3360f176782c1b1dd680d318
Author: Michał Dulko <email address hidden>
Date: Fri Nov 20 12:36:22 2015 +0100

    Eager load columns in volume_get_active_by_window

    All other volume-related methods in db.sqlalchemy.api are eager loading
    volume_metadata, volume_admin_metadata (if admin), volume_type,
    volume_attachment and consistencygroup. volume_get_active_by_window
    wasn't, causing fails because of SQLAlchemy Session being closed when
    trying to lazy load volume_metadata. This commit adds missing
    options(joinedload()) to this query.

    Change-Id: I33ec89d7f1f43aae6010aaa6e12951b7c522b8f0
    Closes-Bug: 1517763
    Related-Bug: 1501838

Changed in cinder:
status: In Progress → Fix Committed

This issue was fixed in the openstack/cinder 8.0.0.0b1 development milestone.

Thierry Carrez (ttx) on 2015-12-03
Changed in cinder:
status: Fix Committed → Fix Released

Reviewed: https://review.openstack.org/304446
Committed: https://git.openstack.org/cgit/openstack/cinder/commit/?id=7e970a1da65431655179b3bba084f4a63fdae959
Submitter: Jenkins
Branch: stable/liberty

commit 7e970a1da65431655179b3bba084f4a63fdae959
Author: Michał Dulko <email address hidden>
Date: Fri Nov 20 12:36:22 2015 +0100

    Eager load columns in volume_get_active_by_window

    All other volume-related methods in db.sqlalchemy.api are eager loading
    volume_metadata, volume_admin_metadata (if admin), volume_type,
    volume_attachment and consistencygroup. volume_get_active_by_window
    wasn't, causing fails because of SQLAlchemy Session being closed when
    trying to lazy load volume_metadata. This commit adds missing
    options(joinedload()) to this query.

    Change-Id: I33ec89d7f1f43aae6010aaa6e12951b7c522b8f0
    Closes-Bug: 1517763
    Related-Bug: 1501838
    (cherry picked from commit 586727cef755abeb3360f176782c1b1dd680d318)

tags: added: in-stable-liberty

This issue was fixed in the openstack/cinder 7.0.2 release.

Tobias Urdin (tobias-urdin) wrote :

When can we expect a 7.0.2 release for stable liberty in Ubuntu cloud archieve? Added Ubuntu as distro

Tobias Urdin (tobias-urdin) wrote :

Bump

The attachment "cinder-volume-usage-audit-error-fix.patch" seems to be a patch. If it isn't, please remove the "patch" flag from the attachment, remove the "patch" tag, and if you are a member of the ~ubuntu-reviewers, unsubscribe the team.

[This is an automated message performed by a Launchpad user owned by ~brian-murray, for any issues please contact him.]

tags: added: patch
Tobias Urdin (tobias-urdin) wrote :

Removed patch flag from attachment because it's not the resolution.

no longer affects: ubuntu

This issue was fixed in the openstack/cinder 7.0.2 release.

Changed in trusty (Ubuntu):
status: New → Triaged
importance: Undecided → Medium
status: Triaged → Invalid
importance: Medium → Undecided
Changed in cloud-archive:
status: New → Invalid
Changed in cinder (Ubuntu):
status: New → Invalid
Corey Bryant (corey.bryant) wrote :

This looks to be valid for kilo and icehouse as well so triaging it accordingly for ubuntu.

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers