openvstorage
celery: UnicodeEncodeError: 'ascii' codec can't encode character u'\u9a6c' in position 0: ordinal not in range(128)
Hello,
I converted a qcow2 image to a raw image into/under vpool mount point, but the device name contains a few Chinese characters. Then vdisks list page became empty and its api returns 500 error.
May 23 15:30:00 Node-43 celery: 2019-05-23 15:30:00 16300 +0800 - Node-43 - 17135/140243007780672 - celery/log.py - log - 20 - ERROR - Task ovs.vdisk.sync_with_reality[535558d9-b4ad-41b5-b6ef-4ef916a75c84] raised unexpected: UnicodeEncodeError('ascii', u'\u9a6c', 0, 1, 'ordinal not in range(128)')
May 23 15:30:00 Node-43 celery: UnicodeEncodeError: 'ascii' codec can't encode character u'\u9a6c' in position 0: ordinal not in range(128)
I guess the Chinese chars could be the cause to this issue, so I removed that raw file such as rm /mnt/vpool/xxx.raw . However, the log above still coming out when vdisks list page is accessed. Of coz the page is still empty.
Is that device name saved somewhere? Best regards Yongsheng
Hi Yongshengma
Converting the image made the volumedriver trigger the create event on which the Framework responds. The Framework enforces ascii encoding when saving objects to the OVSDB Arakoon (through the ujson serialization) Since it can't encode the name (that is what I'm hoping given the error, no real other context), I suspect it isn't yet stored inside the OVSDB.
The following suggestion will not work if the Framework already stored the key inside Arakoon as decoding it would be impossible with the current implementation. If this is the case, reply back to this ticket and I'll see how I can assist you further.
from ovs.dal.lists.vdisklist import VDiskList
from ovs.dal.lists.vpoollist import VPoolList
devicename = "<INSERT NAME HERE>"
vpool_name = "<INSERT VPOOL NAME HERE>"
vpool = VPoolList.get_vpool_by_name(vpool_name)
vdisk = VDiskList.get_by_devicename_and_vpool(devicename, vpool)
if not vdisk:
# Try an alternative route
for vd in VDiskList.get_vdisks():
# Edit: devicename iso device_name
if devicename in vd.devicename:
print 'Found it!'
vdisk = vd
break
if not vdisk:
print 'Found nothing'
else:
# VDisk is now usable. The framework managed to store it internally
print vdisk.guid
If the snippet above raises any exception regarding decoding, we will have to resolve it differently.
If no vdisk is found but len(VDiskList.get_vdisks()) works as excepted, the issue lies in syncing up with the volumedriver which would mean renaming/removing the volume there.
Side note: The error message you provide is not from the vdisk list. It's coming from the Framework trying to sync up the volumes of the volumedriver into its own database. This error will have occurred when processing the volumedriver event.
For future exceptions: it's better to log the stacktrace as seen in the ovs-workers logs as it would provide more context.
Best regards
Hi @JeffreyDevloo
I replicated this issue in a test env, so look at these lines please:
In [1]: from ovs.dal.lists.vdisklist import VDiskList
In [2]: from ovs.dal.lists.vpoollist import VPoolList
In [3]: devicename = "马.raw"
In [4]: vpool_name = "pool-3"
In [5]: vpool = VPoolList.get_vpool_by_name(vpool_name)
In [6]: vdisk = VDiskList.get_by_devicename_and_vpool(devicename, vpool)
/opt/UniStor/ovs/dal/datalist.py:298: UnicodeWarning: Unicode equal comparison failed to convert both arguments to Unicode - interpreting them as being unequal
return value == item[2], instance
In [7]: print vdisk
None
In [8]: if not vdisk:
...: # Try an alternative route
...: for vd in VDiskList.get_vdisks():
...: if devicename in vdisk.device_name:
...: print 'Found it!'
...: vdisk = vd
...: break
...:
---------------------------------------------------------------------------
AttributeError Traceback (most recent call last)
<ipython-input-8-2c521981e957> in <module>()
2 # Try an alternative route
3 for vd in VDiskList.get_vdisks():
----> 4 if devicename in vdisk.device_name:
5 print 'Found it!'
6 vdisk = vd
AttributeError: 'NoneType' object has no attribute 'device_name'
In [9]:
In [9]: len(VDiskList.get_vdisks())
Out[9]: 9
The returned number of len(VDiskList.get_vdisks()) is one more than ls /mnt/vpool/.
Happenly a task snapshot_all_vdisks info in which there are 7 vdisks and 1 vtemplate:
May 24 11:59:59 Node-41 celery[21671]: 2019-05-24 11:59:59 71200 +0800 - Node-41 - 21741/140566430168896 - lib/generic.py - snapshot_all_vdisks - 24 - INFO - [SSA] Snapshot has been taken for 7 vDisks, 1 failed.
May that failed one be the removed one with special chars?
More context:
May 24 11:59:59 Node-41 celery[21671]: 2019-05-24 11:59:59 31700 +0800 - Node-41 - 21671/140566430168896 - celery/strategy.py - task_message_handler - 286 - INFO - Received task: ovs.generic.snapshot_all_vdisks[ca7ff8c2-7cca-4dc4-bc6c-ea3a68660ff4]
May 24 11:59:59 Node-41 celery[21671]: 2019-05-24 11:59:59 32200 +0800 - Node-41 - 21741/140566430168896 - lib/decorators.py - log_message - 14 - INFO - Ensure single DEFAULT mode - ID 1558670399_yEpzAWNQhv - Setting key ovs_ensure_single_ovs.generic.snapshot_all_vdisks
May 24 11:59:59 Node-41 celery[21671]: 2019-05-24 11:59:59 32500 +0800 - Node-41 - 21741/140566430168896 - lib/generic.py - snapshot_all_vdisks - 15 - INFO - [SSA] started
May 24 11:59:59 Node-41 celery[21671]: 2019-05-24 11:59:59 35300 +0800 - Node-41 - 21741/140566430168896 - lib/vdisk.py - create_snapshots - 16 - INFO - Create inconsistent snapshot for vDisk junk-5
May 24 11:59:59 Node-41 celery[21671]: 2019-05-24 11:59:59 38900 +0800 - Node-41 - 21741/140566430168896 - lib/vdisk.py - create_snapshots - 17 - INFO - Create inconsistent snapshot for vDisk junk-1
May 24 11:59:59 Node-41 celery[21671]: 2019-05-24 11:59:59 42200 +0800 - Node-41 - 21741/140566430168896 - lib/vdisk.py - create_snapshots - 18 - INFO - Create inconsistent snapshot for vDisk disk-10
May 24 11:59:59 Node-41 celery[21671]: 2019-05-24 11:59:59 47300 +0800 - Node-41 - 21741/140566430168896 - lib/vdisk.py - create_snapshots - 19 - INFO - Create inconsistent snapshot for vDisk junk-3
May 24 11:59:59 Node-41 celery[21671]: 2019-05-24 11:59:59 50200 +0800 - Node-41 - 21741/140566430168896 - lib/generic.py - snapshot_all_vdisks - 20 - ERROR - Error taking snapshot for vDisk b530ab26-e128-42e6-bf25-c0461b668faa
May 24 11:59:59 Node-41 celery[21671]: Traceback (most recent call last):
May 24 11:59:59 Node-41 celery[21671]: File "/opt/OpenvStorage/ovs/lib/generic.py", line 80, in snapshot_all_vdisks
May 24 11:59:59 Node-41 celery[21671]: metadata=metadata)
May 24 11:59:59 Node-41 celery[21671]: File "/usr/lib/python2.7/site-packages/celery/local.py", line 188, in __call__
May 24 11:59:59 Node-41 celery[21671]: return self._get_current_object()(*a, **kw)
May 24 11:59:59 Node-41 celery[21671]: File "/usr/lib/python2.7/site-packages/celery/app/trace.py", line 439, in __protected_call__
May 24 11:59:59 Node-41 celery[21671]: return orig(self, *args, **kwargs)
May 24 11:59:59 Node-41 celery[21671]: File "/usr/lib/python2.7/site-packages/celery/app/task.py", line 420, in __call__
May 24 11:59:59 Node-41 celery[21671]: return self.run(*args, **kwargs)
May 24 11:59:59 Node-41 celery[21671]: File "/opt/OpenvStorage/ovs/lib/vdisk.py", line 502, in create_snapshot
May 24 11:59:59 Node-41 celery[21671]: raise RuntimeError(vdisk_result[1])
May 24 11:59:59 Node-41 celery[21671]: RuntimeError: Throw location unknown (consider using BOOST_THROW_EXCEPTION)
May 24 11:59:59 Node-41 celery[21671]: Dynamic exception type: volumedriverfs::ObjectNotRegisteredException
May 24 11:59:59 Node-41 celery[21671]: std::exception::what: std::exception
May 24 11:59:59 Node-41 celery[21671]: [volumedriverfs::tag_volume_id*] = bc23f688-b583-40cd-be4f-312647c3a211
May 24 11:59:59 Node-41 celery[21671]: 2019-05-24 11:59:59 62400 +0800 - Node-41 - 21741/140566430168896 - lib/vdisk.py - create_snapshots - 21 - INFO - Create inconsistent snapshot for vDisk junk-7
May 24 11:59:59 Node-41 celery[21671]: 2019-05-24 11:59:59 65100 +0800 - Node-41 - 21741/140566430168896 - lib/vdisk.py - create_snapshots - 22 - INFO - Create inconsistent snapshot for vDisk disk-22
May 24 11:59:59 Node-41 celery[21671]: 2019-05-24 11:59:59 69500 +0800 - Node-41 - 21741/140566430168896 - lib/vdisk.py - create_snapshots - 23 - INFO - Create inconsistent snapshot for vDisk junk-2
May 24 11:59:59 Node-41 celery[21671]: 2019-05-24 11:59:59 71200 +0800 - Node-41 - 21741/140566430168896 - lib/generic.py - snapshot_all_vdisks - 24 - INFO - [SSA] Snapshot has been taken for 7 vDisks, 1 failed.
May 24 11:59:59 Node-41 celery[21671]: 2019-05-24 11:59:59 71200 +0800 - Node-41 - 21741/140566430168896 - lib/decorators.py - log_message - 25 - INFO - Ensure single DEFAULT mode - ID 1558670399_yEpzAWNQhv - Task ovs.generic.snapshot_all_vdisks finished successfully
May 24 11:59:59 Node-41 celery[21671]: 2019-05-24 11:59:59 71300 +0800 - Node-41 - 21741/140566430168896 - lib/decorators.py - log_message - 26 - INFO - Ensure single DEFAULT mode - ID 1558670399_yEpzAWNQhv - Deleting key ovs_ensure_single_ovs.generic.snapshot_all_vdisks
I;m afraid you made a typo mistake on device_name, so I did a little differently:
In [12]: for vd in VDiskList.get_vdisks():
....: print vd.devicename
....:
/vdisk-temp.raw
/junk-5.raw
/junk-1.raw
/disk-10.raw
/junk-3.raw
/马.raw
/junk-7.raw
/disk-22.raw
/junk-2.raw
In [13]:
You can see that heterogeneous vdisk name shows up in the list, but it has actually been removed by me.
Continue
In [13]: if not vdisk:
....: # Try an alternative route
....: for vd in VDiskList.get_vdisks():
....: if devicename in vdisk.devicename:
....: print 'Found it!'
....: vdisk = vd
....: break
....:
---------------------------------------------------------------------------
AttributeError Traceback (most recent call last)
<ipython-input-13-88bcc8483f6b> in <module>()
2 # Try an alternative route
3 for vd in VDiskList.get_vdisks():
----> 4 if devicename in vdisk.devicename:
5 print 'Found it!'
6 vdisk = vd
AttributeError: 'NoneType' object has no attribute 'devicename'
In [5]: for vd in VDiskList.get_vdisks():
...: print vd.guid, vd.devicename
...:
1e809b46-69bf-48ff-8280-e05e73692df1 /vdisk-temp.raw
560ef179-2a56-4a4d-ac2b-0b5fb52d7a16 /junk-5.raw
7d22df05-a317-4d67-93d5-d2118524b515 /junk-1.raw
87f43cd6-286f-47d9-a000-4f8a5afcb001 /disk-10.raw
a7bd1a3e-cf6e-4639-8806-7e31fed63974 /junk-3.raw
b530ab26-e128-42e6-bf25-c0461b668faa /马.raw
ba4f6b3c-8230-4e02-aabb-af9baa91b067 /junk-7.raw
c9d82503-6d4f-4c3b-8c0d-e87e2b958a07 /disk-22.raw
cfdf5a45-bb08-448c-98c4-f68bb58937b4 /junk-2.raw
In [6]:
In [6]: from ovs.lib.vdisk import VDiskController
In [7]: vdisk_guid = 'b530ab26-e128-42e6-bf25-c0461b668faa'
In [8]: VDiskController.delete(vdisk_guid)
2019-05-24 15:12:12 56700 +0800 - Node-42 - 5091/140202688362304 - hybrids/storagerouter.py - _features - 0 - ERROR - Could not load feature information
Traceback (most recent call last):
File "/opt/OpenvStorage/ovs/dal/hybrids/storagerouter.py", line 162, in _features
client = SSHClient(self, username='root')
File "/opt/OpenvStorage/ovs/extensions/generic/sshclient.py", line 52, in __init__
storagerouter = StorageRouter(endpoint.guid)
File "/opt/OpenvStorage/ovs/dal/dataobject.py", line 238, in __init__
self.__class__.__name__, self._guid
ObjectNotFoundException: StorageRouter with guid 'a8c998b5-efc0-40e5-b835-d5ea77c5deea' could not be found
---------------------------------------------------------------------------
TypeError Traceback (most recent call last)
<ipython-input-8-4a8f279942cb> in <module>()
----> 1 VDiskController.delete(vdisk_guid)
/usr/lib/python2.7/site-packages/celery/local.pyc in __call__(self, *a, **kw)
186
187 def __call__(self, *a, **kw):
--> 188 return self._get_current_object()(*a, **kw)
189
190 def __len__(self):
/usr/lib/python2.7/site-packages/celery/app/task.pyc in __call__(self, *args, **kwargs)
418 if self.__self__ is not None:
419 return self.run(self.__self__, *args, **kwargs)
--> 420 return self.run(*args, **kwargs)
421 finally:
422 self.pop_request()
/opt/OpenvStorage/ovs/lib/vdisk.pyc in delete(vdisk_guid)
199 vdisk.invalidate_dynamics('storagerouter_guid')
200 storagerouter = StorageRouter(vdisk.storagerouter_guid)
--> 201 if 'directory_unlink' in storagerouter.features['volumedriver']['features']:
202 first = True
203 devicename_parts = vdisk.devicename.strip('/').split('/')
TypeError: 'NoneType' object has no attribute '__getitem__'
In [9]:
In [9]: from ovs.dal.hybrids.vdisk import VDisk
In [10]: vdisk = VDisk(vdisk_guid)
In [11]: vdisk
Out[11]: <VDisk (guid: b530ab26-e128-42e6-bf25-c0461b668faa, at: 0x7f8355ee2c50)>
In [12]: print vdisk
2019-05-24 15:14:39 29100 +0800 - Node-42 - 5091/140202688362304 - hybrids/vdisk.py - fetch_statistics - 1 - ERROR - Error loading statistics_volume from bc23f688-b583-40cd-be4f-312647c3a211: Throw location unknown (consider using BOOST_THROW_EXCEPTION)
Dynamic exception type: volumedriverfs::ObjectNotRegisteredException
std::exception::what: std::exception
[volumedriverfs::tag_volume_id*] = bc23f688-b583-40cd-be4f-312647c3a211
{
"edge_clients": [],
"cache_quota": null,
"has_manual_dtl": false,
"guid": "b530ab26-e128-42e6-bf25-c0461b668faa",
"size": 2147483648,
"devicename": "/\u9a6c.raw",
"statistics": {
"operations": 0,
"backend_write_latency": 0,
"4k_unaligned_read_operations": 0,
"write_latency_distribution": {
........
"cinder_id": null,
"description": "\u9a6c",
"vpool_guid": "34f7e980-0d6a-450d-b7cd-c93e4d0a1a39",
"storagedriver_id": null,
"snapshots": [],
"volume_id": "bc23f688-b583-40cd-be4f-312647c3a211",
"info": {
"owner_tag": "<class 'volumedriver.storagerouter.storagerouterclient.OwnerTag'>: OwnerTag(0)",
"vrouter_id": "",
"object_type": "FILE",
"live_status": "RUNNING",
"failover_mode": "",
"stored": 0,
"failover_port": 0,
"namespace": "",
"volume_size": 0,
"cluster_cache_handle": "<class 'volumedriver.storagerouter.storagerouterclient.ClusterCacheHandle'>: ClusterCacheHandle(0)",
"parent_volume_id": "",
"failover_ip": "",
"metadata_backend_config": {},
"parent_namespace": "",
"halted": false,
"cluster_multiplier": 0,
"volume_id": "",
"footprint": 0,
"lba_count": 0,
"lba_size": 0,
"parent_snapshot_id": "",
"cluster_cache_limit": null,
"sco_multiplier": 0
},
"name": "\u9a6c",
"storagerouter_guid": null,
"dtl_status": "unknown"
}
Hi Yongshenga
I indeed made some mistakes while writing the small test out. The version you should use is:
from ovs.dal.lists.vdisklist import VDiskList
from ovs.dal.lists.vpoollist import VPoolList
devicename = "<INSERT NAME HERE>"
vpool_name = "<INSERT VPOOL NAME HERE>"
vpool = VPoolList.get_vpool_by_name(vpool_name)
vdisk = VDiskList.get_by_devicename_and_vpool(devicename, vpool)
if not vdisk:
# Try an alternative route
for vd in VDiskList.get_vdisks():
# Edit: devicename iso device_name
# Edit2: vd.device_name iso vdisk as vd is the variable of our loop
if devicename in vd.devicename:
print 'Found it!'
vdisk = vd
break
if not vdisk:
print 'Found nothing'
else:
# VDisk is now usable. The framework managed to store it internally
print vdisk.guid
But it looks like i have the information I need. The VDisk object can be retrieved through a list lookup (for vdisk in VDiskList.get_vdisks()'), but not while performing queries (get_by_devicename_and_vpool`, the unicodewarning is given).
I think the volumedriver is also having issues with the volume too (the object not registered thing). Either you have removed the volume on the volumedriver's end or it's having issues doing a lookup.
The StorageRouter lookup exception puzzles me. I have no clue on what went wrong during that look up. The only thing coming to mind is that an old entry is still cached for that volume and the cluster shrank, but this is an unlikely scenario. If anything it points to https://github.com/openvstorage/framework/issues/2289 which is also lacking in context.
Hi @JeffreyDevloo
I can still access vdisk list from each router's vdisk tab, so it's not a big deal at this moment. I will keep on following this issue. Thanks for your reference.
Best regards Yongsheng