Cinder Backup Failed

senthil_p

Cadet
Joined
Oct 22, 2019
Messages
6
Hi
We have configured with cinder backup service and tested working. when am checking with cinder incremental backup I found the first time I can take the backup of the instance which is in use. When I am trying second-time backup getting failed due to FreeNAS API failed unknown reason.
Can anyone advise me what am doing here and how the cinder incremental backup works?

Thanks



default_volume_type = ixsystems-iscsi
enabled_backends = ixsystems-iscsi

[ixsystems-iscsi]
iscsi_helper = tgtadm
volume_dd_blocksize = 512
volume_driver = cinder.volume.drivers.ixsystems.iscsi.FreeNASISCSIDriver
ixsystems_login = root
ixsystems_password = r!@#@ksjdkj
ixsystems_server_hostname = 20.30.4.7
ixsystems_volume_backend_name = iXsystems_FREENAS_Storage
ixsystems_iqn_prefix = iqn.2005-10.org.freenas.ctl
ixsystems_datastore_pool = Virtual-Disk-1
ixsystems_vendor_name = iXsystems
ixsystems_storage_protocol = iscsi




Cinder volume log :

2019-10-22 15:30:30.508 21508 INFO cinder.volume.manager [req-e7f4a09b-4d63-4296-8407-b4bd4ef4a2ac 6f2284200926497c87d1b50f3e9f0194 6d806e7e0b0642ba8d46f867ab6622c0 - default default] Deleted volume successfully.
2019-10-22 15:30:52.826 21508 INFO cinder.volume.drivers.ixsystems.iscsi [req-40f63700-562b-4cca-85d1-4b983a09b7bb 6f2284200926497c87d1b50f3e9f0194 6d806e7e0b0642ba8d46f867ab6622c0 - default default] iXsystems Create Colened Volume
2019-10-22 15:30:52.826 21508 INFO cinder.volume.drivers.ixsystems.iscsi [req-40f63700-562b-4cca-85d1-4b983a09b7bb 6f2284200926497c87d1b50f3e9f0194 6d806e7e0b0642ba8d46f867ab6622c0 - default default] create_cloned_volume: 0af94e57-0d5b-499b-8aac-89688895bac8
2019-10-22 15:30:52.827 21508 INFO cinder.volume.drivers.ixsystems.iscsi [req-40f63700-562b-4cca-85d1-4b983a09b7bb 6f2284200926497c87d1b50f3e9f0194 6d806e7e0b0642ba8d46f867ab6622c0 - default default] iXsystems Create Snapshot
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server [req-40f63700-562b-4cca-85d1-4b983a09b7bb 6f2284200926497c87d1b50f3e9f0194 6d806e7e0b0642ba8d46f867ab6622c0 - default default] Exception during message handling: FreeNASApiError: FREENAS api failed. Reason - Unexpected error:FREENAS api failed. Reason - Unexpected error:Error while creating snapshot: 400:Bad Request
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 163, in _process_incoming
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 220, in dispatch
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server return self._do_dispatch(endpoint, method, ctxt, args)
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 190, in _do_dispatch
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server result = func(ctxt, **new_args)
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 4332, in get_backup_device
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server self.driver.get_backup_device(ctxt, backup))
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/cinder/volume/driver.py", line 1144, in get_backup_device
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server context, backup)
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/cinder/volume/driver.py", line 1185, in _get_backup_volume_temp_volume
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server context, volume)
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/cinder/volume/driver.py", line 1291, in _create_temp_cloned_volume
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server temp_vol_ref.destroy()
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server self.force_reraise()
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/cinder/volume/driver.py", line 1286, in _create_temp_cloned_volume
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server model_update = self.create_cloned_volume(temp_vol_ref, volume)
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/ixsystems/iscsi.py", line 212, in create_cloned_volume
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server self.create_snapshot(temp_snapshot)
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/ixsystems/iscsi.py", line 167, in create_snapshot
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server self.common._create_snapshot(freenas_snapshot['name'], freenas_volume['name'])
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/ixsystems/common.py", line 299, in _create_snapshot
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server raise FreeNASApiError('Unexpected error', e)
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server FreeNASApiError: FREENAS api failed. Reason - Unexpected error:FREENAS api failed. Reason - Unexpected error:Error while creating snapshot: 400:Bad Request
2019-10-22 15:30:53.087 21508 ERROR oslo_messaging.rpc.server

Cinder Backup LOG:


2019-10-22 15:30:52.635 390 INFO cinder.backup.manager [req-40f63700-562b-4cca-85d1-4b983a09b7bb 6f2284200926497c87d1b50f3e9f0194 6d806e7e0b0642ba8d46f867ab6622c0 - default default] Create backup started, backup: d93fd9c2-d67f-4f9e-a428-3eef67b230dd volume: 0af94e57-0d5b-499b-8aac-89688895bac8.
2019-10-22 15:30:52.670 390 INFO os_brick.remotefs.remotefs [req-40f63700-562b-4cca-85d1-4b983a09b7bb 6f2284200926497c87d1b50f3e9f0194 6d806e7e0b0642ba8d46f867ab6622c0 - default default] Already mounted: /var/lib/cinder/backup_nfs/80c4fc8dae0f4784c10ebc068f570056
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server [req-40f63700-562b-4cca-85d1-4b983a09b7bb 6f2284200926497c87d1b50f3e9f0194 6d806e7e0b0642ba8d46f867ab6622c0 - default default] Exception during message handling: RemoteError: Remote error: FreeNASApiError FREENAS api failed. Reason - Unexpected error:FREENAS api failed. Reason - Unexpected error:Error while creating snapshot: 400:Bad Request
[u'Traceback (most recent call last):\n', u' File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 163, in _process_incoming\n res = self.dispatcher.dispatch(message)\n', u' File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 220, in dispatch\n return self._do_dispatch(endpoint, method, ctxt, args)\n', u' File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 190, in _do_dispatch\n result = func(ctxt, **new_args)\n', u' File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 4332, in get_backup_device\n self.driver.get_backup_device(ctxt, backup))\n', u' File "/usr/lib/python2.7/site-packages/cinder/volume/driver.py", line 1144, in get_backup_device\n context, backup)\n', u' File "/usr/lib/python2.7/site-packages/cinder/volume/driver.py", line 1185, in _get_backup_volume_temp_volume\n context, volume)\n', u' File "/usr/lib/python2.7/site-packages/cinder/volume/driver.py", line 1291, in _create_temp_cloned_volume\n temp_vol_ref.destroy()\n', u' File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__\n self.force_reraise()\n', u' File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise\n six.reraise(self.type_, self.value, self.tb)\n', u' File "/usr/lib/python2.7/site-packages/cinder/volume/driver.py", line 1286, in _create_temp_cloned_volume\n model_update = self.create_cloned_volume(temp_vol_ref, volume)\n', u' File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/ixsystems/iscsi.py", line 212, in create_cloned_volume\n self.create_snapshot(temp_snapshot)\n', u' File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/ixsystems/iscsi.py", line 167, in create_snapshot\n self.common._create_snapshot(freenas_snapshot[\'name\'], freenas_volume[\'name\'])\n', u' File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/ixsystems/common.py", line 299, in _create_snapshot\n raise FreeNASApiError(\'Unexpected error\', e)\n', u'FreeNASApiError: FREENAS api failed. Reason - Unexpected error:FREENAS api failed. Reason - Unexpected error:Error while creating snapshot: 400:Bad Request\n'].
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 163, in _process_incoming
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 220, in dispatch
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server return self._do_dispatch(endpoint, method, ctxt, args)
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 190, in _do_dispatch
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server result = func(ctxt, **new_args)
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/cinder/backup/manager.py", line 413, in create_backup
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server self._update_backup_error(backup, six.text_type(err))
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server self.force_reraise()
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/cinder/backup/manager.py", line 402, in create_backup
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server updates = self._run_backup(context, backup, volume)
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/cinder/backup/manager.py", line 468, in _run_backup
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server volume)
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/cinder/volume/rpcapi.py", line 339, in get_backup_device
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server want_objects=True)
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 174, in call
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server retry=self.retry)
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_messaging/transport.py", line 131, in _send
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server timeout=timeout, retry=retry)
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 559, in send
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server retry=retry)
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 550, in _send
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server raise result
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server RemoteError: Remote error: FreeNASApiError FREENAS api failed. Reason - Unexpected error:FREENAS api failed. Reason - Unexpected error:Error while creating snapshot: 400:Bad Request
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server [u'Traceback (most recent call last):\n', u' File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 163, in _process_incoming\n res = self.dispatcher.dispatch(message)\n', u' File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 220, in dispatch\n return self._do_dispatch(endpoint, method, ctxt, args)\n', u' File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 190, in _do_dispatch\n result = func(ctxt, **new_args)\n', u' File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 4332, in get_backup_device\n self.driver.get_backup_device(ctxt, backup))\n', u' File "/usr/lib/python2.7/site-packages/cinder/volume/driver.py", line 1144, in get_backup_device\n context, backup)\n', u' File "/usr/lib/python2.7/site-packages/cinder/volume/driver.py", line 1185, in _get_backup_volume_temp_volume\n context, volume)\n', u' File "/usr/lib/python2.7/site-packages/cinder/volume/driver.py", line 1291, in _create_temp_cloned_volume\n temp_vol_ref.destroy()\n', u' File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__\n self.force_reraise()\n', u' File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise\n six.reraise(self.type_, self.value, self.tb)\n', u' File "/usr/lib/python2.7/site-packages/cinder/volume/driver.py", line 1286, in _create_temp_cloned_volume\n model_update = self.create_cloned_volume(temp_vol_ref, volume)\n', u' File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/ixsystems/iscsi.py", line 212, in create_cloned_volume\n self.create_snapshot(temp_snapshot)\n', u' File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/ixsystems/iscsi.py", line 167, in create_snapshot\n self.common._create_snapshot(freenas_snapshot[\'name\'], freenas_volume[\'name\'])\n', u' File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/ixsystems/common.py", line 299, in _create_snapshot\n raise FreeNASApiError(\'Unexpected error\', e)\n', u'FreeNASApiError: FREENAS api failed. Reason - Unexpected error:FREENAS api failed. Reason - Unexpected error:Error while creating snapshot: 400:Bad Request\n'].
2019-10-22 15:30:53.140 390 ERROR oslo_messaging.rpc.server
 

senthil_p

Cadet
Joined
Oct 22, 2019
Messages
6
cinder Back end used NFS share from FreeNAS
Backend driver

Cinder.conf

backup_driver = cinder.backup.drivers.nfs
#backup_mount_options="vers=3"
backup_mount_point_base = $state_path/backup_nfs
backup_share = 20.40.4.7:/mnt/Virtual-Disk-1/cinder
nas_secure_file_operations=false
 

senthil_p

Cadet
Joined
Oct 22, 2019
Messages
6
@dlavigne I can't able to solve these issues! Does the FreeNAS work with cinder incremental backup?

OpenStack Version Queen
openstack-cinder-12.0.8-1
 
D

dlavigne

Guest
This might be fixed in 11.3 with the replication/snapshots rewrite. If you get a chance to test 11.3-BETA1 (due out this week), let us know if the issue persists.
 
Top