Bug 2026809 - VM remains locked after importing from vmware/external-ova, we see "'str' object has no attribute 'decode'" in the log
Summary: VM remains locked after importing from vmware/external-ova, we see "'str' ob...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: vdsm
Classification: oVirt
Component: General
Version: 4.40.100.1
Hardware: x86_64
OS: Linux
unspecified
high vote
Target Milestone: ovirt-4.4.10
: 4.40.100.2
Assignee: Tomáš Golembiovský
QA Contact: Tamir
URL:
Whiteboard:
Depends On:
Blocks: 2037739 2037758
TreeView+ depends on / blocked
 
Reported: 2021-11-26 00:40 UTC by Tamir
Modified: 2022-01-19 07:00 UTC (History)
6 users (show)

Fixed In Version: vdsm-4.40.100.2
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
: 2037739 2037758 (view as bug list)
Environment:
Last Closed: 2022-01-19 07:00:13 UTC
oVirt Team: Virt
pm-rhel: ovirt-4.4+
pelauter: planning_ack+


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Issue Tracker RHV-44092 0 None None None 2021-11-26 00:40:44 UTC
oVirt gerrit 118073 0 master MERGED v2v: decode bytes input immediately 2021-12-20 08:51:37 UTC
oVirt gerrit 118105 0 ovirt-4.4.z MERGED v2v: decode bytes input immediately 2021-12-21 16:30:32 UTC

Description Tamir 2021-11-26 00:40:01 UTC
Created attachment 1843639 [details]
Added engine.log and vdsm.log logs

Description of problem:

When I import a VM (It can be any VM) from VCenter 7 to RHV, the getStats method is called, and then the error: 'str' object has no attribute 'decode' occurs.

Currently, when we test the import from VCenter 7 to RHV, the VDSM logs are filled with these errors and it makes the bug investigating process harder.

Those following lines could repeat hundreds of times (I saw logs with 440 times such errors):

2021-11-25 19:42:48,705+0200 INFO  (jsonrpc/0) [api.host] START getStats() from=::ffff:10.35.235.26,56956 (api:48)
2021-11-25 19:42:48,722+0200 INFO  (jsonrpc/0) [api.host] FINISH getStats error='str' object has no attribute 'decode' from=::ffff:10.35.235.26,56956 (api:52)
2021-11-25 19:42:48,722+0200 ERROR (jsonrpc/0) [jsonrpc.JsonRpcServer] Internal server error (__init__:354)
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/yajsonrpc/__init__.py", line 349, in _handle_request
    res = method(**params)
  File "/usr/lib/python3.6/site-packages/vdsm/rpc/Bridge.py", line 198, in _dynamicMethod
    result = fn(*methodArgs)
  File "<decorator-gen-471>", line 2, in getStats
  File "/usr/lib/python3.6/site-packages/vdsm/common/api.py", line 50, in method
    ret = func(*args, **kwargs)
  File "/usr/lib/python3.6/site-packages/vdsm/API.py", line 1456, in getStats
    multipath=True)
  File "/usr/lib/python3.6/site-packages/vdsm/host/api.py", line 49, in get_stats
    decStats = stats.produce(first_sample, last_sample)
  File "/usr/lib/python3.6/site-packages/vdsm/host/stats.py", line 108, in produce
    stats['v2vJobs'] = v2v.get_jobs_status()
  File "/usr/lib/python3.6/site-packages/vdsm/v2v.py", line 290, in get_jobs_status
    'description': job.description.decode('utf-8'),
AttributeError: 'str' object has no attribute 'decode'
2021-11-25 19:42:48,727+0200 INFO  (jsonrpc/0) [jsonrpc.JsonRpcServer] RPC call Host.getStats failed (error -32603) in 0.02 seconds (__init__:312)



Version-Release number of selected component (if applicable):
 - Engine instance with RHV 4.4.10-1 (ovirt-engine-4.4.10-0.17.el8ev) and RHEL 8.5 installed.
 - 3 hosts with RHV 4.4.10-1 and RHEL 8.5, 3 hosts with vdsm-4.40.100.1-1.el8ev

How reproducible:
100%

Steps to Reproduce:
1. Create a 4.6 data center and a 4.6 cluster.
2. Install the hosts and create a new NFS storage domain.
3. Open the VM import modal, select VMware as the source, fill in the VCenter 7 details, and select a VM to import and import it.
4. Check that in the engine.log and vdsm.log of the host used in the import there aren't any mentions of the "'str' object has no attribute 'decode'" error while the import process runs.
5. Check that the VM was imported successfully.

Actual results:
1. The 4.6 data center and the 4.6 cluster were created.
2. The host was installed and the NFS storage domain was created.
3. The VM import process has started.
4. There are too many (more than 400) mentions of the error, where there should be none.
5. The VM was imported successfully.

Expected results:
Steps 1-3 and 5 are as expected.
In Step 4, we shouldn't see any "'str' object has no attribute 'decode'" errors, If we can't get any status from the host, we should log it once in a while and we shouldn't fill the logs with the same error.

In engine.log:
2021-11-25 19:39:28,827+02 WARN  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetStatsAsyncVDSCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-34) [] Unexpected return value: Status [code=-32603, message=Internal JSON-RPC error: {'reason': "'str' object has no attribute 'decode'"}]
2021-11-25 19:39:28,829+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.GetStatsAsyncVDSCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-34) [] Failed in 'Get Host Statistics' method

In vdsm.log:
2021-11-25 19:42:48,705+0200 INFO  (jsonrpc/0) [api.host] START getStats() from=::ffff:10.35.235.26,56956 (api:48)
2021-11-25 19:42:48,722+0200 INFO  (jsonrpc/0) [api.host] FINISH getStats error='str' object has no attribute 'decode' from=::ffff:10.35.235.26,56956 (api:52)
2021-11-25 19:42:48,722+0200 ERROR (jsonrpc/0) [jsonrpc.JsonRpcServer] Internal server error (__init__:354)
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/yajsonrpc/__init__.py", line 349, in _handle_request
    res = method(**params)
  File "/usr/lib/python3.6/site-packages/vdsm/rpc/Bridge.py", line 198, in _dynamicMethod
    result = fn(*methodArgs)
  File "<decorator-gen-471>", line 2, in getStats
  File "/usr/lib/python3.6/site-packages/vdsm/common/api.py", line 50, in method
    ret = func(*args, **kwargs)
  File "/usr/lib/python3.6/site-packages/vdsm/API.py", line 1456, in getStats
    multipath=True)
  File "/usr/lib/python3.6/site-packages/vdsm/host/api.py", line 49, in get_stats
    decStats = stats.produce(first_sample, last_sample)
  File "/usr/lib/python3.6/site-packages/vdsm/host/stats.py", line 108, in produce
    stats['v2vJobs'] = v2v.get_jobs_status()
  File "/usr/lib/python3.6/site-packages/vdsm/v2v.py", line 290, in get_jobs_status
    'description': job.description.decode('utf-8'),
AttributeError: 'str' object has no attribute 'decode'
2021-11-25 19:42:48,727+0200 INFO  (jsonrpc/0) [jsonrpc.JsonRpcServer] RPC call Host.getStats failed (error -32603) in 0.02 seconds (__init__:312)


Additional info:

Comment 1 Yury.Panchenko 2021-12-17 18:33:12 UTC
Hello there,
I increased the priority because this problem also can lock the vm after import.
So in my case I couldn't import vm from ova teamplate it left in locked state after sucessfull import.
2021-12-16 19:29:10,692+0100 INFO  (v2v/9ad2c75e) [root] Job '9ad2c75e-708d-4259-bcd7-ad5764f1eed8' finished import successfully (v2v:894)

2021-12-16 19:29:14,389+0100 INFO  (jsonrpc/7) [api.host] FINISH getStats error='str' object has no attribute 'decode' from=::ffff:172.25.16.27,49972 (api:52)
2021-12-16 19:29:14,389+0100 ERROR (jsonrpc/7) [jsonrpc.JsonRpcServer] Internal server error (__init__:354)
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/yajsonrpc/__init__.py", line 349, in _handle_request
    res = method(**params)
  File "/usr/lib/python3.6/site-packages/vdsm/rpc/Bridge.py", line 194, in _dynamicMethod
    result = fn(*methodArgs)
  File "<decorator-gen-471>", line 2, in getStats
  File "/usr/lib/python3.6/site-packages/vdsm/common/api.py", line 50, in method
    ret = func(*args, **kwargs)
  File "/usr/lib/python3.6/site-packages/vdsm/API.py", line 1456, in getStats
    multipath=True)
  File "/usr/lib/python3.6/site-packages/vdsm/host/api.py", line 49, in get_stats
    decStats = stats.produce(first_sample, last_sample)
  File "/usr/lib/python3.6/site-packages/vdsm/host/stats.py", line 108, in produce
    stats['v2vJobs'] = v2v.get_jobs_status()
  File "/usr/lib/python3.6/site-packages/vdsm/v2v.py", line 290, in get_jobs_status
    'description': job.description.decode('utf-8'),
AttributeError: 'str' object has no attribute 'decode'

Comment 2 Tamir 2022-01-06 13:42:28 UTC
Verified on RHV 4.4.10-3.

Env:
    - Engine instance with RHV 4.4.10-3 (ovirt-engine-4.4.10.2-0.1.el8ev.noarch) and RHEL 8.5 installed.
    - 2 hosts with RHV 4.4.10-3 and RHEL 8.5 and with vdsm-4.40.100.2-1.el8ev

Tests:

Check the partner's case:

Firstly, I would like to mention that I didn't encounter the customer's bug in the newest version and also in older versions of VDSM.

I performed the steps from Veeam's user guide (from page 20):

1. I have downloaded the zip from their website, which can be alternatively retrieved from the following Red Hat server. 
2. I have extracted it in /tmp/new_folder in one of the hosts in the env.
3. I ran chmod 755  veeam_rhv_proxy_beta_vm_1.0.1488.* and
 chown 36:36 veeam_rhv_proxy_beta_vm_1.0.1488.*

In Admin Portal:
4. Create a 4.6 data center and a 4.6 cluster.
5. Install the hosts and create a new NFS storage domain.
6. Open the VM import modal, select OVA as the source, fill in the OVA path and host, load, and import the VM.
7. The VM was imported successfully and was unlocked.

Results (As Expected):
4. The 4.6 data center and the 4.6 cluster were created.
5. The host was installed and the NFS storage domain was created.
6. The VM import process has started.
7. The VM was imported successfully and was unlocked.


Check that the log doesn't contain any mentions of the "'str' object has no attribute 'decode'" error:

In Admin Portal:

1. Create a 4.6 data center and a 4.6 cluster.
2. Install the hosts and create a new NFS storage domain.
3. Open the VM import modal, select VMware as the source, fill in the VCenter 7 details, and select a VM to import and import it.
4. Check that in the engine.log and vdsm.log of the host used in the import there aren't any mentions of the "'str' object has no attribute 'decode'" error while the import process runs.
5. Check that the VM was imported successfully.

Results (As Expected):
1. The 4.6 data center and the 4.6 cluster were created.
2. The host was installed and the NFS storage domain was created.
3. The VM import process has started.
4. In the engine.log and vdsm.log in the host used in the import there aren't any mentions of the "'str' object has no attribute 'decode'" error while and after the import process.
5. The VM was imported successfully.

Comment 3 Sandro Bonazzola 2022-01-19 07:00:13 UTC
This bugzilla is included in oVirt 4.4.10 release, published on January 18th 2022.

Since the problem described in this bug report should be resolved in oVirt 4.4.10 release, it has been closed with a resolution of CURRENT RELEASE.

If the solution does not work for you, please open a new bug report.


Note You need to log in before you can comment on or make changes to this bug.