[Bug 1631561] Re: [SRU] volume usage audit print excessive debug log for deleted resources

[Edward Hope-Morley]

** Tags removed: sts-sru-needed
** Tags added: sts-sru-done

-- 
You received this bug notification because you are a member of Ubuntu
OpenStack, which is subscribed to Ubuntu Cloud Archive.
https://bugs.launchpad.net/bugs/1631561

Title:
  [SRU] volume usage audit print excessive debug log for deleted
  resources

Status in Cinder:
  Fix Released
Status in Ubuntu Cloud Archive:
  Fix Released
Status in Ubuntu Cloud Archive mitaka series:
  Fix Released
Status in Ubuntu Cloud Archive newton series:
  Fix Released
Status in cinder package in Ubuntu:
  Fix Released
Status in cinder source package in Xenial:
  Fix Released
Status in cinder source package in Yakkety:
  Fix Released

Bug description:
  [Impact]

  * Current volume usage audit tool queries all
  volumes/snapshots/backups including those resources have been deleted,
  as a result, every single deleted resource would trigger a few
  debug/exception level messages, which is too much for a running
  production cluster at hour/day period.

  * notify_snapshot_usage() doesn't handles the case when
   when the source volume for the snapshot has been deleted.

  The following exception is raised:

  2017-02-17 20:20:10.067 1921 ERROR cinder [req-7e273ce0-1ae8-410e-a814-0f444364c028 - - - - -] Exists snapshot notification failed: Volume 2c84e585-9947-4ad9-bd93-2fc3a5cf9a08 could not be found.
  2017-02-17 20:20:10.067 1921 ERROR cinder Traceback (most recent call last):
  2017-02-17 20:20:10.067 1921 ERROR cinder File "/usr/lib/python2.7/dist-packages/cinder/cmd/volume_usage_audit.py", line 188, in main
  2017-02-17 20:20:10.067 1921 ERROR cinder extra_info)
  2017-02-17 20:20:10.067 1921 ERROR cinder File "/usr/lib/python2.7/dist-packages/cinder/volume/utils.py", line 174, in notify_about_snapshot_usage
  2017-02-17 20:20:10.067 1921 ERROR cinder usage_info = _usage_from_snapshot(snapshot, **extra_usage_info)
  2017-02-17 20:20:10.067 1921 ERROR cinder File "/usr/lib/python2.7/dist-packages/cinder/volume/utils.py", line 151, in _usage_from_snapshot
  2017-02-17 20:20:10.067 1921 ERROR cinder 'availability_zone': snapshot.volume['availability_zone'],
  2017-02-17 20:20:10.067 1921 ERROR cinder File "/usr/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 67, in getter
  2017-02-17 20:20:10.067 1921 ERROR cinder self.obj_load_attr(name)
  2017-02-17 20:20:10.067 1921 ERROR cinder File "/usr/lib/python2.7/dist-packages/cinder/objects/snapshot.py", line 196, in obj_load_attr
  2017-02-17 20:20:10.067 1921 ERROR cinder self.volume_id)
  2017-02-17 20:20:10.067 1921 ERROR cinder File "/usr/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 181, in wrapper
  2017-02-17 20:20:10.067 1921 ERROR cinder result = fn(cls, context, *args, **kwargs)
  2017-02-17 20:20:10.067 1921 ERROR cinder File "/usr/lib/python2.7/dist-packages/cinder/objects/base.py", line 166, in get_by_id
  2017-02-17 20:20:10.067 1921 ERROR cinder orm_obj = db.get_by_id(context, model, id, *args, **kwargs)
  2017-02-17 20:20:10.067 1921 ERROR cinder File "/usr/lib/python2.7/dist-packages/cinder/db/api.py", line 1127, in get_by_id
  2017-02-17 20:20:10.067 1921 ERROR cinder return IMPL.get_by_id(context, model, id, *args, **kwargs)
  2017-02-17 20:20:10.067 1921 ERROR cinder File "/usr/lib/python2.7/dist-packages/cinder/db/sqlalchemy/api.py", line 193, in wrapper
  2017-02-17 20:20:10.067 1921 ERROR cinder return f(*args, **kwargs)
  2017-02-17 20:20:10.067 1921 ERROR cinder File "/usr/lib/python2.7/dist-packages/cinder/db/sqlalchemy/api.py", line 4451, in get_by_id
  2017-02-17 20:20:10.067 1921 ERROR cinder return _GET_METHODS[model](context, id, *args, **kwargs)
  2017-02-17 20:20:10.067 1921 ERROR cinder File "/usr/lib/python2.7/dist-packages/cinder/db/sqlalchemy/api.py", line 193, in wrapper
  2017-02-17 20:20:10.067 1921 ERROR cinder return f(*args, **kwargs)
  2017-02-17 20:20:10.067 1921 ERROR cinder File "/usr/lib/python2.7/dist-packages/cinder/db/sqlalchemy/api.py", line 1480, in volume_get
  2017-02-17 20:20:10.067 1921 ERROR cinder return _volume_get(context, volume_id)
  2017-02-17 20:20:10.067 1921 ERROR cinder File "/usr/lib/python2.7/dist-packages/cinder/db/sqlalchemy/api.py", line 193, in wrapper
  2017-02-17 20:20:10.067 1921 ERROR cinder return f(*args, **kwargs)
  2017-02-17 20:20:10.067 1921 ERROR cinder File "/usr/lib/python2.7/dist-packages/cinder/db/sqlalchemy/api.py", line 1425, in _volume_get
  2017-02-17 20:20:10.067 1921 ERROR cinder raise exception.VolumeNotFound(volume_id=volume_id)
  2017-02-17 20:20:10.067 1921 ERROR cinder VolumeNotFound: Volume 2c84e585-9947-4ad9-bd93-2fc3a5cf9a08 could not be found.

  [Test Case]

   *The steps to reproduce this bug:

  1) Deploy Mitaka/Newton cloud
  2) Set the volumes as deleted on the database

  mysql> update volumes set deleted = 1;
  Query OK, 2 rows affected (0.00 sec)
  Rows matched: 2 Changed: 2 Warnings: 0

  3) Run the cinder-volume-usage-audit command:

  # /usr/bin/cinder-volume-usage-audit --start_time "2017-02-17
  15:10:00" --end_time "2017-02-17 15:20:00" --debug

  [Regression Potential]

   * None identified as the commit fixes a already existing misbehavior.

To manage notifications about this bug go to:
https://bugs.launchpad.net/cinder/+bug/1631561/+subscriptions