Merge ~niedbalski/ubuntu/+source/cinder:stable/newton into ~ubuntu-server-dev/ubuntu/+source/cinder:stable/newton

Proposed by Jorge Niedbalski on 2017-03-10
Status: Merged
Merged at revision: 42e7a27b2c1068d6b8f0c103f7c0fb29a8bdff7f
Proposed branch: ~niedbalski/ubuntu/+source/cinder:stable/newton
Merge into: ~ubuntu-server-dev/ubuntu/+source/cinder:stable/newton
Diff against target: 335 lines (+314/-0)
3 files modified
debian/changelog (+7/-0)
debian/patches/log-message-cleanup-for-volume-usage-audit.patch (+306/-0)
debian/patches/series (+1/-0)
Reviewer Review Type Date Requested Status
Ubuntu Server Developers 2017-03-10 Pending
Review via email: mp+319623@code.launchpad.net

Description of the change

* d/p/log-message-cleanup-for-volume-usage-audit.patch:
    Fixes LP: #1631561.

To post a comment you must log in.

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
1diff --git a/debian/changelog b/debian/changelog
2index 570a073..cdcd84a 100644
3--- a/debian/changelog
4+++ b/debian/changelog
5@@ -1,3 +1,10 @@
6+cinder (2:9.1.2-0ubuntu2) yakkety; urgency=medium
7+
8+ * d/p/log-message-cleanup-for-volume-usage-audit.patch:
9+ Fixes LP: #1631561.
10+
11+ -- Jorge Niedbalski <jorge.niedbalski@canonical.com> Fri, 10 Mar 2017 18:20:41 -0300
12+
13 cinder (2:9.1.2-0ubuntu1) yakkety; urgency=medium
14
15 [ Corey Bryant ]
16diff --git a/debian/patches/log-message-cleanup-for-volume-usage-audit.patch b/debian/patches/log-message-cleanup-for-volume-usage-audit.patch
17new file mode 100644
18index 0000000..9421d04
19--- /dev/null
20+++ b/debian/patches/log-message-cleanup-for-volume-usage-audit.patch
21@@ -0,0 +1,306 @@
22+From 82792be330e3b88aa1f625537ae1d2649e14ba4f Mon Sep 17 00:00:00 2001
23+From: Zhiteng Huang <zhithuang@ebaysf.com>
24+Date: Sat, 8 Oct 2016 13:03:37 -0700
25+Subject: [PATCH] Log message cleanup for volume-usage-audit
26+
27+volume-usage-audit utlis logs unecessary message at for deleted
28+volumes or exception:
29+
30+ try:
31+ LOG.debug('Send notification for vol X')
32+ _notify_func
33+ except Exception:
34+ LOG.exception(...)
35+
36+In the case when _notify_func raises exception, it logs
37+'Send notification' and the exception.
38+
39+This change reduce logs by only logging 'Sent notification' when
40+there is no exception by:
41+
42+ try:
43+ _notify_func
44+ LOG.debug('Sent notification for vol X')
45+ except Exception:
46+ LOG.exception(...)
47+
48+Also, this change fixes notify_snapshot_usage() for not handling
49+the case when source volume for the snapshot is deleted.
50+
51+Closes-bug: #1631561
52+
53+Change-Id: Iff5448e888ee39bce1ff99c7bf48581d655fb687
54+---
55+ cinder/cmd/volume_usage_audit.py | 80 +++++++++++++++++-----------------
56+ cinder/tests/unit/test_volume_utils.py | 46 +++++++++++++++++++
57+ cinder/volume/utils.py | 14 +++++-
58+ 3 files changed, 99 insertions(+), 41 deletions(-)
59+
60+diff --git a/cinder/cmd/volume_usage_audit.py b/cinder/cmd/volume_usage_audit.py
61+index ba8d38f..678d4e0 100644
62+--- a/cinder/cmd/volume_usage_audit.py
63++++ b/cinder/cmd/volume_usage_audit.py
64+@@ -48,7 +48,7 @@ from cinder import i18n
65+ i18n.enable_lazy()
66+ from cinder import context
67+ from cinder import db
68+-from cinder.i18n import _, _LE
69++from cinder.i18n import _, _LE, _LI
70+ from cinder import objects
71+ from cinder import rpc
72+ from cinder import utils
73+@@ -95,9 +95,9 @@ def main():
74+ 'end': end}
75+ LOG.error(msg)
76+ sys.exit(-1)
77+- LOG.debug("Starting volume usage audit")
78+- msg = _("Creating usages for %(begin_period)s until %(end_period)s")
79+- LOG.debug(msg, {"begin_period": str(begin), "end_period": str(end)})
80++ LOG.info(_LI("Starting volume usage audit"))
81++ msg = _LI("Creating usages for %(begin_period)s until %(end_period)s")
82++ LOG.info(msg, {"begin_period": str(begin), "end_period": str(end)})
83+
84+ extra_info = {
85+ 'audit_period_beginning': str(begin),
86+@@ -107,19 +107,19 @@ def main():
87+ volumes = db.volume_get_active_by_window(admin_context,
88+ begin,
89+ end)
90+- LOG.debug("Found %d volumes", len(volumes))
91++ LOG.info(_LI("Found %d volumes"), len(volumes))
92+ for volume_ref in volumes:
93+ try:
94+- LOG.debug("Send exists notification for <volume_id: "
95++ cinder.volume.utils.notify_about_volume_usage(
96++ admin_context,
97++ volume_ref,
98++ 'exists', extra_usage_info=extra_info)
99++ LOG.debug("Sent exists notification for <volume_id: "
100+ "%(volume_id)s> <project_id %(project_id)s> "
101+ "<%(extra_info)s>",
102+ {'volume_id': volume_ref.id,
103+ 'project_id': volume_ref.project_id,
104+ 'extra_info': extra_info})
105+- cinder.volume.utils.notify_about_volume_usage(
106+- admin_context,
107+- volume_ref,
108+- 'exists', extra_usage_info=extra_info)
109+ except Exception as exc_msg:
110+ LOG.exception(_LE("Exists volume notification failed: %s"),
111+ exc_msg, resource=volume_ref)
112+@@ -132,12 +132,6 @@ def main():
113+ 'audit_period_beginning': str(volume_ref.created_at),
114+ 'audit_period_ending': str(volume_ref.created_at),
115+ }
116+- LOG.debug("Send create notification for "
117+- "<volume_id: %(volume_id)s> "
118+- "<project_id %(project_id)s> <%(extra_info)s>",
119+- {'volume_id': volume_ref.id,
120+- 'project_id': volume_ref.project_id,
121+- 'extra_info': local_extra_info})
122+ cinder.volume.utils.notify_about_volume_usage(
123+ admin_context,
124+ volume_ref,
125+@@ -146,6 +140,12 @@ def main():
126+ admin_context,
127+ volume_ref,
128+ 'create.end', extra_usage_info=local_extra_info)
129++ LOG.debug("Sent create notification for "
130++ "<volume_id: %(volume_id)s> "
131++ "<project_id %(project_id)s> <%(extra_info)s>",
132++ {'volume_id': volume_ref.id,
133++ 'project_id': volume_ref.project_id,
134++ 'extra_info': local_extra_info})
135+ except Exception as exc_msg:
136+ LOG.exception(_LE("Create volume notification failed: %s"),
137+ exc_msg, resource=volume_ref)
138+@@ -158,12 +158,6 @@ def main():
139+ 'audit_period_beginning': str(volume_ref.deleted_at),
140+ 'audit_period_ending': str(volume_ref.deleted_at),
141+ }
142+- LOG.debug("Send delete notification for "
143+- "<volume_id: %(volume_id)s> "
144+- "<project_id %(project_id)s> <%(extra_info)s>",
145+- {'volume_id': volume_ref.id,
146+- 'project_id': volume_ref.project_id,
147+- 'extra_info': local_extra_info})
148+ cinder.volume.utils.notify_about_volume_usage(
149+ admin_context,
150+ volume_ref,
151+@@ -172,24 +166,30 @@ def main():
152+ admin_context,
153+ volume_ref,
154+ 'delete.end', extra_usage_info=local_extra_info)
155++ LOG.debug("Sent delete notification for "
156++ "<volume_id: %(volume_id)s> "
157++ "<project_id %(project_id)s> <%(extra_info)s>",
158++ {'volume_id': volume_ref.id,
159++ 'project_id': volume_ref.project_id,
160++ 'extra_info': local_extra_info})
161+ except Exception as exc_msg:
162+ LOG.exception(_LE("Delete volume notification failed: %s"),
163+ exc_msg, resource=volume_ref)
164+
165+ snapshots = objects.SnapshotList.get_active_by_window(admin_context,
166+ begin, end)
167+- LOG.debug("Found %d snapshots", len(snapshots))
168++ LOG.info(_LI("Found %d snapshots"), len(snapshots))
169+ for snapshot_ref in snapshots:
170+ try:
171+- LOG.debug("Send notification for <snapshot_id: %(snapshot_id)s> "
172+- "<project_id %(project_id)s> <%(extra_info)s>",
173+- {'snapshot_id': snapshot_ref.id,
174+- 'project_id': snapshot_ref.project_id,
175+- 'extra_info': extra_info})
176+ cinder.volume.utils.notify_about_snapshot_usage(admin_context,
177+ snapshot_ref,
178+ 'exists',
179+ extra_info)
180++ LOG.debug("Sent notification for <snapshot_id: %(snapshot_id)s> "
181++ "<project_id %(project_id)s> <%(extra_info)s>",
182++ {'snapshot_id': snapshot_ref.id,
183++ 'project_id': snapshot_ref.project_id,
184++ 'extra_info': extra_info})
185+ except Exception as exc_msg:
186+ LOG.exception(_LE("Exists snapshot notification failed: %s"),
187+ exc_msg, resource=snapshot_ref)
188+@@ -202,12 +202,6 @@ def main():
189+ 'audit_period_beginning': str(snapshot_ref.created_at),
190+ 'audit_period_ending': str(snapshot_ref.created_at),
191+ }
192+- LOG.debug("Send create notification for "
193+- "<snapshot_id: %(snapshot_id)s> "
194+- "<project_id %(project_id)s> <%(extra_info)s>",
195+- {'snapshot_id': snapshot_ref.id,
196+- 'project_id': snapshot_ref.project_id,
197+- 'extra_info': local_extra_info})
198+ cinder.volume.utils.notify_about_snapshot_usage(
199+ admin_context,
200+ snapshot_ref,
201+@@ -216,6 +210,12 @@ def main():
202+ admin_context,
203+ snapshot_ref,
204+ 'create.end', extra_usage_info=local_extra_info)
205++ LOG.debug("Sent create notification for "
206++ "<snapshot_id: %(snapshot_id)s> "
207++ "<project_id %(project_id)s> <%(extra_info)s>",
208++ {'snapshot_id': snapshot_ref.id,
209++ 'project_id': snapshot_ref.project_id,
210++ 'extra_info': local_extra_info})
211+ except Exception as exc_msg:
212+ LOG.exception(_LE("Create snapshot notification failed: %s"),
213+ exc_msg, resource=snapshot_ref)
214+@@ -228,12 +228,6 @@ def main():
215+ 'audit_period_beginning': str(snapshot_ref.deleted_at),
216+ 'audit_period_ending': str(snapshot_ref.deleted_at),
217+ }
218+- LOG.debug("Send delete notification for "
219+- "<snapshot_id: %(snapshot_id)s> "
220+- "<project_id %(project_id)s> <%(extra_info)s>",
221+- {'snapshot_id': snapshot_ref.id,
222+- 'project_id': snapshot_ref.project_id,
223+- 'extra_info': local_extra_info})
224+ cinder.volume.utils.notify_about_snapshot_usage(
225+ admin_context,
226+ snapshot_ref,
227+@@ -242,6 +236,12 @@ def main():
228+ admin_context,
229+ snapshot_ref,
230+ 'delete.end', extra_usage_info=local_extra_info)
231++ LOG.debug("Sent delete notification for "
232++ "<snapshot_id: %(snapshot_id)s> "
233++ "<project_id %(project_id)s> <%(extra_info)s>",
234++ {'snapshot_id': snapshot_ref.id,
235++ 'project_id': snapshot_ref.project_id,
236++ 'extra_info': local_extra_info})
237+ except Exception as exc_msg:
238+ LOG.exception(_LE("Delete snapshot notification failed: %s"),
239+ exc_msg, resource=snapshot_ref)
240+diff --git a/cinder/tests/unit/test_volume_utils.py b/cinder/tests/unit/test_volume_utils.py
241+index c49b113..bca8c71 100644
242+--- a/cinder/tests/unit/test_volume_utils.py
243++++ b/cinder/tests/unit/test_volume_utils.py
244+@@ -166,6 +166,52 @@ class NotifyUsageTestCase(test.TestCase):
245+ }
246+ self.assertDictMatch(expected_snapshot, usage_info)
247+
248++ @mock.patch('cinder.objects.Volume.get_by_id')
249++ def test_usage_from_deleted_snapshot(self, volume_get_by_id):
250++ raw_volume = {
251++ 'id': fake.VOLUME_ID,
252++ 'availability_zone': 'nova',
253++ 'deleted': 1
254++ }
255++ ctxt = context.get_admin_context()
256++ volume_obj = fake_volume.fake_volume_obj(ctxt, **raw_volume)
257++ volume_get_by_id.side_effect = exception.VolumeNotFound(
258++ volume_id=fake.VOLUME_ID)
259++
260++ raw_snapshot = {
261++ 'project_id': fake.PROJECT_ID,
262++ 'user_id': fake.USER_ID,
263++ 'volume': volume_obj,
264++ 'volume_id': fake.VOLUME_ID,
265++ 'volume_size': 1,
266++ 'id': fake.SNAPSHOT_ID,
267++ 'display_name': '11',
268++ 'created_at': '2014-12-11T10:10:00',
269++ 'status': fields.SnapshotStatus.ERROR,
270++ 'deleted': '',
271++ 'snapshot_metadata': [{'key': 'fake_snap_meta_key',
272++ 'value': 'fake_snap_meta_value'}],
273++ 'expected_attrs': ['metadata'],
274++ }
275++
276++ snapshot_obj = fake_snapshot.fake_snapshot_obj(ctxt, **raw_snapshot)
277++ usage_info = volume_utils._usage_from_snapshot(snapshot_obj)
278++ expected_snapshot = {
279++ 'tenant_id': fake.PROJECT_ID,
280++ 'user_id': fake.USER_ID,
281++ 'availability_zone': '',
282++ 'volume_id': fake.VOLUME_ID,
283++ 'volume_size': 1,
284++ 'snapshot_id': fake.SNAPSHOT_ID,
285++ 'display_name': '11',
286++ 'created_at': 'DONTCARE',
287++ 'status': fields.SnapshotStatus.ERROR,
288++ 'deleted': '',
289++ 'metadata': six.text_type({'fake_snap_meta_key':
290++ u'fake_snap_meta_value'}),
291++ }
292++ self.assertDictMatch(expected_snapshot, usage_info)
293++
294+ @mock.patch('cinder.db.volume_glance_metadata_get')
295+ @mock.patch('cinder.db.volume_attachment_get_all_by_volume_id')
296+ def test_usage_from_volume(self, mock_attachment, mock_image_metadata):
297+diff --git a/cinder/volume/utils.py b/cinder/volume/utils.py
298+index 0aec08a..c811e2d 100644
299+--- a/cinder/volume/utils.py
300++++ b/cinder/volume/utils.py
301+@@ -149,10 +149,22 @@ def notify_about_backup_usage(context, backup, event_suffix,
302+
303+
304+ def _usage_from_snapshot(snapshot, **extra_usage_info):
305++ try:
306++ az = snapshot.volume['availability_zone']
307++ except exception.VolumeNotFound:
308++ # (zhiteng) Snapshot's source volume could have been deleted
309++ # (which means snapshot has been deleted as well),
310++ # lazy-loading volume would raise VolumeNotFound exception.
311++ # In that case, not going any further by abusing low level
312++ # DB API to fetch deleted volume but simply return empty
313++ # string for snapshot's AZ info.
314++ az = ''
315++ LOG.debug("Source volume %s deleted", snapshot.volume_id)
316++
317+ usage_info = {
318+ 'tenant_id': snapshot.project_id,
319+ 'user_id': snapshot.user_id,
320+- 'availability_zone': snapshot.volume['availability_zone'],
321++ 'availability_zone': az,
322+ 'volume_id': snapshot.volume_id,
323+ 'volume_size': snapshot.volume_size,
324+ 'snapshot_id': snapshot.id,
325+--
326+2.7.4
327+
328diff --git a/debian/patches/series b/debian/patches/series
329index 7abc008..238c9c6 100644
330--- a/debian/patches/series
331+++ b/debian/patches/series
332@@ -1,2 +1,3 @@
333 google-back-requirements.patch
334 fix-long-casting.patch
335+log-message-cleanup-for-volume-usage-audit.patch

Subscribers

People subscribed via source and target branches