OpenStack Backup/Restore and DR (Freezer)

Deletion of temporary snapshot is causing nova engine problem

Bug #1687921 reported by Elena Lindqvist
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Backup/Restore and DR (Freezer)
Fix Released
Critical
jiaopengju
OpenStack Backup/Restore and DR (Freezer) pike-2 "pike-2"

Bug Description

I tried to do backup of an instance with the following command :

freezer-agent --debug --action backup --nova-inst-id 69e956dd-4c02-4a9d-890b-5a92aa49b798 --storage local --container /home/stack/mtas-backup02 --backup-name mtas-bkp02 --mode nova --engine nova --no-incremental true --log-file mtas-bkp02.log

Backup fails with the following error

2017-05-03 13:13:53.810 12709 ERROR freezer.utils.streaming [-] expected string or buffer
2017-05-03 13:13:53.810 12709 ERROR freezer.utils.streaming Traceback (most recent call last):
2017-05-03 13:13:53.810 12709 ERROR freezer.utils.streaming File "/home/stack/freezer_agent/lib/python2.7/site-packages/freezer/utils/streaming.py", line 111, in run
2017-05-03 13:13:53.810 12709 ERROR freezer.utils.streaming super(QueuedThread, self).run()
2017-05-03 13:13:53.810 12709 ERROR freezer.utils.streaming File "/usr/lib64/python2.7/threading.py", line 764, in run
2017-05-03 13:13:53.810 12709 ERROR freezer.utils.streaming self.__target(*self.__args, **self.__kwargs)
2017-05-03 13:13:53.810 12709 ERROR freezer.utils.streaming File "/home/stack/freezer_agent/lib/python2.7/site-packages/freezer/engine/engine.py", line 100, in backup_stream
2017-05-03 13:13:53.810 12709 ERROR freezer.utils.streaming manifest_path))
2017-05-03 13:13:53.810 12709 ERROR freezer.utils.streaming File "/home/stack/freezer_agent/lib/python2.7/site-packages/freezer/utils/streaming.py", line 68, in put_messages
2017-05-03 13:13:53.810 12709 ERROR freezer.utils.streaming for message in messages:
2017-05-03 13:13:53.810 12709 ERROR freezer.utils.streaming File "/home/stack/freezer_agent/lib/python2.7/site-packages/freezer/engine/nova/nova.py", line 206, in backup_data
2017-05-03 13:13:53.810 12709 ERROR freezer.utils.streaming image_block_mapping = json.loads(image_block_mapping_info)
2017-05-03 13:13:53.810 12709 ERROR freezer.utils.streaming File "/usr/lib64/python2.7/json/__init__.py", line 338, in loads
2017-05-03 13:13:53.810 12709 ERROR freezer.utils.streaming return _default_decoder.decode(s)
2017-05-03 13:13:53.810 12709 ERROR freezer.utils.streaming File "/usr/lib64/python2.7/json/decoder.py", line 366, in decode
2017-05-03 13:13:53.810 12709 ERROR freezer.utils.streaming obj, end = self.raw_decode(s, idx=_w(s, 0).end())
2017-05-03 13:13:53.810 12709 ERROR freezer.utils.streaming TypeError: expected string or buffer
2017-05-03 13:13:53.810 12709 ERROR freezer.utils.streaming
2017-05-03 13:13:54.664 12709 ERROR freezer.utils.streaming [-] Forced stop
2017-05-03 13:13:54.664 12709 ERROR freezer.utils.streaming Traceback (most recent call last):
2017-05-03 13:13:54.664 12709 ERROR freezer.utils.streaming File "/home/stack/freezer_agent/lib/python2.7/site-packages/freezer/utils/streaming.py", line 111, in run
2017-05-03 13:13:54.664 12709 ERROR freezer.utils.streaming super(QueuedThread, self).run()
2017-05-03 13:13:54.664 12709 ERROR freezer.utils.streaming File "/usr/lib64/python2.7/threading.py", line 764, in run
2017-05-03 13:13:54.664 12709 ERROR freezer.utils.streaming self.__target(*self.__args, **self.__kwargs)
2017-05-03 13:13:54.664 12709 ERROR freezer.utils.streaming File "/home/stack/freezer_agent/lib/python2.7/site-packages/freezer/storage/fslike.py", line 52, in write_backup
2017-05-03 13:13:54.664 12709 ERROR freezer.utils.streaming for message in rich_queue.get_messages():
2017-05-03 13:13:54.664 12709 ERROR freezer.utils.streaming File "/home/stack/freezer_agent/lib/python2.7/site-packages/freezer/utils/streaming.py", line 89, in get_messages
2017-05-03 13:13:54.664 12709 ERROR freezer.utils.streaming self.check_stop()
2017-05-03 13:13:54.664 12709 ERROR freezer.utils.streaming File "/home/stack/freezer_agent/lib/python2.7/site-packages/freezer/utils/streaming.py", line 65, in check_stop
2017-05-03 13:13:54.664 12709 ERROR freezer.utils.streaming raise Exception("Forced stop")
2017-05-03 13:13:54.664 12709 ERROR freezer.utils.streaming Exception: Forced stop
2017-05-03 13:13:54.664 12709 ERROR freezer.utils.streaming
2017-05-03 13:13:54.665 12709 CRITICAL freezer.engine.engine [-] Engine error: expected string or buffer
2017-05-03 13:13:54.665 12709 CRITICAL freezer.engine.engine [-] Engine error: Forced stop
2017-05-03 13:13:54.665 12709 ERROR freezer.main [-] ('Engine error. Failed to backup.', {})
2017-05-03 13:13:54.665 12709 ERROR freezer.main Traceback (most recent call last):
2017-05-03 13:13:54.665 12709 ERROR freezer.main File "/home/stack/freezer_agent/lib/python2.7/site-packages/freezer/main.py", line 217, in main
2017-05-03 13:13:54.665 12709 ERROR freezer.main freezer_main(backup_args)
2017-05-03 13:13:54.665 12709 ERROR freezer.main File "/home/stack/freezer_agent/lib/python2.7/site-packages/freezer/main.py", line 114, in freezer_main
2017-05-03 13:13:54.665 12709 ERROR freezer.main return run_job(backup_args, storage)
2017-05-03 13:13:54.665 12709 ERROR freezer.main File "/home/stack/freezer_agent/lib/python2.7/site-packages/freezer/main.py", line 127, in run_job
2017-05-03 13:13:54.665 12709 ERROR freezer.main response = freezer_job.execute()
2017-05-03 13:13:54.665 12709 ERROR freezer.main File "/home/stack/freezer_agent/lib/python2.7/site-packages/freezer/job.py", line 153, in execute
2017-05-03 13:13:54.665 12709 ERROR freezer.main backup_level = self.backup(app_mode)
2017-05-03 13:13:54.665 12709 ERROR freezer.main File "/home/stack/freezer_agent/lib/python2.7/site-packages/freezer/job.py", line 275, in backup
2017-05-03 13:13:54.665 12709 ERROR freezer.main restart_always_level=self.conf.restart_always_level)
2017-05-03 13:13:54.665 12709 ERROR freezer.main File "/home/stack/freezer_agent/lib/python2.7/site-packages/freezer/engine/engine.py", line 183, in backup
2017-05-03 13:13:54.665 12709 ERROR freezer.main "Engine error. Failed to backup.")
2017-05-03 13:13:54.665 12709 ERROR freezer.main EngineException: ('Engine error. Failed to backup.', {})
2017-05-03 13:13:54.665 12709 ERROR freezer.main
2017-05-03 13:13:54.666 12709 CRITICAL freezer.main [-] End freezer agent process unsuccessfully
2017-05-03 13:13:54.666 12709 CRITICAL freezer.main [-] Critical Error: ('Engine error. Failed to backup.', {})

For a complete stack trace, check http://paste.openstack.org/show/608694/

I suspect this change is causing this problem
https://github.com/openstack/freezer/commit/bd1bb00afb5f947f4b2d03591abc14e24c3e82d6

git revert bd1bb00afb5f947f4b2d03591abc14e24c3e82d6 might solve the problem

Saad Zaher (szaher)
Changed in freezer:
importance: Undecided → Critical
assignee: nobody → jiaopengju (jiaopengju)
status: New → Confirmed
milestone: none → pike-2
Revision history for this message
jiaopengju (pj-jiao) wrote :

Hi, I have tested it.

The patch that I have submited is in the situation when doing backup of volume or snapshot launched nova instance.

The error above occurred when doing backup of nova instance which was launched by image, cause it has no info about 'block_device_mapping', I think I should add the "none judgment" before line 205 of nova.py.

Few days ago, with more in-depth testing, I found that freezer does not support volume or snapshot correctly and the patch I have submited will fail when doing backup of image launched nova instance. So I submit a new patch https://review.openstack.org/#/c/460427/ and fix the error(include the above error).

The above error will not occur when doing backup of volume or snapshot based nova instance.

jiaopengju (pj-jiao)
Changed in freezer:
status: Confirmed → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to freezer (master)

Fix proposed to branch: master
Review: https://review.openstack.org/462149

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to freezer (master)

Reviewed: https://review.openstack.org/462149
Committed: https://git.openstack.org/cgit/openstack/freezer/commit/?id=52d25ee78e151858091fd4fed5f3cafea7d238ff
Submitter: Jenkins
Branch: master

commit 52d25ee78e151858091fd4fed5f3cafea7d238ff
Author: Pengju Jiao <email address hidden>
Date: Wed May 3 21:19:14 2017 +0800

    Fix loading 'block_device_mapping' info error

    In commit with change-id Ic20b6da85e2cdd9414627e31b0e11276443b8579,
    it miss the 'none value judgement', this will cause nova engine
    error. This patch will fix it.

    Change-Id: I8d3952ea97f554f77856ac9ba89aca8f359afbb0
    Closes-Bug: #1687921

Changed in freezer:
status: In Progress → Fix Released
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/freezer 5.0.0.0b2

This issue was fixed in the openstack/freezer 5.0.0.0b2 development milestone.

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

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.