Bug 1533500 - Node Zero flow incorrectly handling of unicode chars in error messages.
Summary: Node Zero flow incorrectly handling of unicode chars in error messages.
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: ovirt-hosted-engine-setup
Classification: oVirt
Component: General
Version: 2.2.4
Hardware: x86_64
OS: Linux
high
medium
Target Milestone: ovirt-4.2.2
: ---
Assignee: Simone Tiraboschi
QA Contact: Nikolai Sednev
URL:
Whiteboard:
Depends On: 1551289
Blocks: 1458709
TreeView+ depends on / blocked
 
Reported: 2018-01-11 14:10 UTC by Nikolai Sednev
Modified: 2018-03-29 11:00 UTC (History)
3 users (show)

Fixed In Version: ovirt-hosted-engine-setup-2.2.12
Clone Of:
Environment:
Last Closed: 2018-03-29 11:00:20 UTC
oVirt Team: Integration
Embargoed:
ylavi: ovirt-4.2+
ylavi: exception+
sbonazzo: devel_ack+


Attachments (Terms of Use)
sosreport from host (9.41 MB, application/x-xz)
2018-02-05 18:04 UTC, Nikolai Sednev
no flags Details
sosreport from puma19 (10.51 MB, application/x-xz)
2018-02-06 15:20 UTC, Nikolai Sednev
no flags Details
all 13 logs from /var/log/ovirt-hosted-engine-setup/ (2.08 MB, application/x-gzip)
2018-02-06 16:11 UTC, Nikolai Sednev
no flags Details
test.yml (196 bytes, text/x-vhdl)
2018-02-22 13:34 UTC, Simone Tiraboschi
no flags Details


Links
System ID Private Priority Status Summary Last Updated
oVirt gerrit 86956 0 None MERGED 2_ovirt_logger.py: Log more data 2020-05-27 17:30:17 UTC
oVirt gerrit 88070 0 master MERGED ansible: better handle unicode in callbacks 2020-05-27 17:30:17 UTC
oVirt gerrit 88165 0 ovirt-hosted-engine-setup-2.2 MERGED ansible: better handle unicode in callbacks 2020-05-27 17:30:17 UTC

Description Nikolai Sednev 2018-01-11 14:10:46 UTC
Description of problem:
[ ERROR ] 'ascii' codec can't encode character u'\u2018' in position 520:
> ordinal not in

[ INFO  ] changed: [localhost]
          Please specify the storage you would like to use (glusterfs, iscsi, fc, nfs)[nfs]:
          Please specify the nfs version you would like to use (auto, v3, v4, v4_1)[auto]: v3
          Please specify the full shared storage connection path to use (example: host:/path): yellow-vdsb.qa.lab.tlv.redhat.com:/Compute_NFS/nsednev_he_2
          If needed, specify additional mount options for the connection to the hosted-engine storagedomain []: rsize=32768,wsize=32768


Version-Release number of selected component (if applicable):
ovirt-hosted-engine-ha-2.2.3-0.0.master.20171218181916.20171218181911.git4c22b93.el7.centos.noarch
ovirt-hosted-engine-setup-2.2.4-0.0.master.20180109170856.gitb593776.el7.centos.noarch
ovirt-engine-appliance-4.2-20180110.1.el7.centos.noarch

How reproducible:
100%

Steps to Reproduce:
1.Deploy Node Zero over NFS using rsize=32768,wsize=32768 for mounting options, e.g. "If needed, specify additional mount options for the connection to the hosted-engine storagedomain []: rsize=32768,wsize=32768"

Expected results:
Should work normally.

Additional info:

Comment 1 Nikolai Sednev 2018-01-11 14:14:10 UTC
Adding more data from Simone from https://bugzilla.redhat.com/show_bug.cgi?id=1359265#c17:
"
> [ ERROR ] 'ascii' codec can't encode character u'\u2018' in position 520:
> ordinal not in

The real issue is here:
2018-01-10 17:58:30,479+0200 DEBUG otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils._process_output:73 {u'_ansible_parsed': True, u'stderr_lines': [u'dd: failed to open \u2018/rhev/data-center/mnt/yellow-vdsb.qa.lab.tlv.redhat.com:_Compute__NFS_nsednev__he__2/000ccade-f52e-4bf6-9a11-d09f4c74a3a9/images/6ab7311c-3107-4afb-8d77-c290efdaabf6/71c22342-0ec9-43df-b756-1bc6ab8ef741\u2019: Permission denied'], u'cmd': [u'dd', u'bs=20480', u'count=1', u'oflag=direct', u'if=/var/tmp/localvmYRB8qf/71c22342-0ec9-43df-b756-1bc6ab8ef741', u'of=/rhev/data-center/mnt/yellow-vdsb.qa.lab.tlv.redhat.com:_Compute__NFS_nsednev__he__2/000ccade-f52e-4bf6-9a11-d09f4c74a3a9/images/6ab7311c-3107-4afb-8d77-c290efdaabf6/71c22342-0ec9-43df-b756-1bc6ab8ef741'], u'end': u'2018-01-10 17:58:30.337743', u'_ansible_no_log': False, u'stdout': u'', u'changed': True, u'start': u'2018-01-10 17:58:30.332305', u'delta': u'0:00:00.005438', u'stderr': u'dd: failed to open \u2018/rhev/data-center/mnt/yellow-vdsb.qa.lab.tlv.redhat.com:_Compute__NFS_nsednev__he__2/000ccade-f52e-4bf6-9a11-d09f4c74a3a9/images/6ab7311c-3107-4afb-8d77-c290efdaabf6/71c22342-0ec9-43df-b756-1bc6ab8ef741\u2019: Permission denied', u'rc': 1, u'invocation': {u'module_args': {u'warn': True, u'executable': None, u'_uses_shell': False, u'_raw_params': u'dd bs=20480 count=1 oflag=direct if="/var/tmp/localvmYRB8qf/71c22342-0ec9-43df-b756-1bc6ab8ef741" of="/rhev/data-center/mnt/yellow-vdsb.qa.lab.tlv.redhat.com:_Compute__NFS_nsednev__he__2/000ccade-f52e-4bf6-9a11-d09f4c74a3a9/images/6ab7311c-3107-4afb-8d77-c290efdaabf6/71c22342-0ec9-43df-b756-1bc6ab8ef741"', u'removes': None, u'creates': None, u'chdir': None, u'stdin': None}}, u'stdout_lines': [], u'msg': u'non-zero return code'}


but we had an issue parsing the error message on:
[u'dd: failed to open \u2018/rhev/data-center/mnt/yellow-vdsb.qa.lab.tlv.redhat.com:_Compute__NFS_nsednev__he__2/000ccade-f52e-4bf6-9a11-d09f4c74a3a9/images/6ab7311c-3107-4afb-8d77-c290efdaabf6/71c22342-0ec9-43df-b756-1bc6ab8ef741\u2019: Permission denied']

And so:
2018-01-10 17:58:30,783+0200 ERROR otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils.run:150 (<ansible.plugins.callback.1_otopi_json.CallbackModule object at 0x1f2d950>):
2018-01-10 17:58:30,783+0200 DEBUG otopi.plugins.otopi.dialog.human 
2018-01-10 17:58:30,783+0200 ERROR otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils.run:150 'ascii' codec can't encode character u'\u2018' in position 520: ordinal not in

(\u2018 is LEFT SINGLE QUOTATION MARK and \u2019 is RIGHT SINGLE QUOTATION MARK)."

Comment 2 Simone Tiraboschi 2018-01-11 14:25:16 UTC
The issue was here:
2018-01-10 17:58:30,479+0200 DEBUG otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils._process_output:73 {u'_ansible_parsed': True, u'stderr_lines': [u'dd: failed to open \u2018/rhev/data-center/mnt/yellow-vdsb.qa.lab.tlv.redhat.com:_Compute__NFS_nsednev__he__2/000ccade-f52e-4bf6-9a11-d09f4c74a3a9/images/6ab7311c-3107-4afb-8d77-c290efdaabf6/71c22342-0ec9-43df-b756-1bc6ab8ef741\u2019: Permission denied'], u'cmd': [u'dd', u'bs=20480', u'count=1', u'oflag=direct', u'if=/var/tmp/localvmYRB8qf/71c22342-0ec9-43df-b756-1bc6ab8ef741', u'of=/rhev/data-center/mnt/yellow-vdsb.qa.lab.tlv.redhat.com:_Compute__NFS_nsednev__he__2/000ccade-f52e-4bf6-9a11-d09f4c74a3a9/images/6ab7311c-3107-4afb-8d77-c290efdaabf6/71c22342-0ec9-43df-b756-1bc6ab8ef741'], u'end': u'2018-01-10 17:58:30.337743', u'_ansible_no_log': False, u'stdout': u'', u'changed': True, u'start': u'2018-01-10 17:58:30.332305', u'delta': u'0:00:00.005438', u'stderr': u'dd: failed to open \u2018/rhev/data-center/mnt/yellow-vdsb.qa.lab.tlv.redhat.com:_Compute__NFS_nsednev__he__2/000ccade-f52e-4bf6-9a11-d09f4c74a3a9/images/6ab7311c-3107-4afb-8d77-c290efdaabf6/71c22342-0ec9-43df-b756-1bc6ab8ef741\u2019: Permission denied', u'rc': 1, u'invocation': {u'module_args': {u'warn': True, u'executable': None, u'_uses_shell': False, u'_raw_params': u'dd bs=20480 count=1 oflag=direct if="/var/tmp/localvmYRB8qf/71c22342-0ec9-43df-b756-1bc6ab8ef741" of="/rhev/data-center/mnt/yellow-vdsb.qa.lab.tlv.redhat.com:_Compute__NFS_nsednev__he__2/000ccade-f52e-4bf6-9a11-d09f4c74a3a9/images/6ab7311c-3107-4afb-8d77-c290efdaabf6/71c22342-0ec9-43df-b756-1bc6ab8ef741"', u'removes': None, u'creates': None, u'chdir': None, u'stdin': None}}, u'stdout_lines': [], u'msg': u'non-zero return code'}


but we had an issue parsing the error message on:
[u'dd: failed to open \u2018/rhev/data-center/mnt/yellow-vdsb.qa.lab.tlv.redhat.com:_Compute__NFS_nsednev__he__2/000ccade-f52e-4bf6-9a11-d09f4c74a3a9/images/6ab7311c-3107-4afb-8d77-c290efdaabf6/71c22342-0ec9-43df-b756-1bc6ab8ef741\u2019: Permission denied']

And so:
2018-01-10 17:58:30,783+0200 ERROR otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils.run:150 (<ansible.plugins.callback.1_otopi_json.CallbackModule object at 0x1f2d950>):
2018-01-10 17:58:30,783+0200 DEBUG otopi.plugins.otopi.dialog.human 
2018-01-10 17:58:30,783+0200 ERROR otopi.ovirt_hosted_engine_setup.ansible_utils ansible_utils.run:150 'ascii' codec can't encode character u'\u2018' in position 520: ordinal not in

(\u2018 is LEFT SINGLE QUOTATION MARK and \u2019 is RIGHT SINGLE QUOTATION MARK).

Could you please open a new bug on the node zero flow about correctly handling unicode chars in error messages?

Comment 3 Simone Tiraboschi 2018-01-11 14:42:32 UTC
This is enough to trigger it:

[root@c74he20180108h1 ~]# dd if=/dev/zero of=/test/t1
dd: failed to open ‘/test/t1’: No such file or directory
[root@c74he20180108h1 ~]# locale
LANG=en_US.UTF-8
LC_CTYPE="en_US.UTF-8"
LC_NUMERIC=it_IT.UTF-8
LC_TIME=it_IT.UTF-8
LC_COLLATE="en_US.UTF-8"
LC_MONETARY=it_IT.UTF-8
LC_MESSAGES="en_US.UTF-8"
LC_PAPER=it_IT.UTF-8
LC_NAME="en_US.UTF-8"
LC_ADDRESS="en_US.UTF-8"
LC_TELEPHONE="en_US.UTF-8"
LC_MEASUREMENT=it_IT.UTF-8
LC_IDENTIFICATION="en_US.UTF-8"
LC_ALL=

Comment 4 Martin Sivák 2018-01-12 15:26:37 UTC
Where does the error originate? otopi or hosted engine?

In any way, the component is wrong as this is definitely a Python encoding related issue and ovirt-engine is written in Java..

Comment 5 Yedidyah Bar David 2018-01-15 12:28:11 UTC
Fixed by https://gerrit.ovirt.org/86238

Comment 6 Nikolai Sednev 2018-01-15 13:40:06 UTC
otopi

Comment 7 Nikolai Sednev 2018-02-05 18:03:47 UTC
Failed on these components:
rhvm-appliance-4.2-20180202.0.el7.noarch
ovirt-hosted-engine-setup-2.2.9-1.el7ev.noarch
ovirt-hosted-engine-ha-2.2.4-1.el7ev.noarch
Red Hat Enterprise Linux Server release 7.4 (Maipo)

[ ERROR ]  [WARNING]: Failure using method (v2_runner_on_failed) in callback plugin
         
[ ERROR ] (<ansible.plugins.callback.1_otopi_json.CallbackModule object at 0x32fa590>):
         
[ ERROR ] 'ascii' codec can't encode character u'\u2018' in position 520: ordinal not in
         
[ ERROR ] range(128)
         
[ ERROR ] Failed to execute stage 'Closing up': Failed executing ansible-playbook



http://pastebin.test.redhat.com/552880

Sosreport from host is attached.
Logs from engine were not accessible, as engine was not accessible via ssh.

Comment 8 Nikolai Sednev 2018-02-05 18:04:43 UTC
Created attachment 1391667 [details]
sosreport from host

Comment 9 Yedidyah Bar David 2018-02-06 09:04:08 UTC
Please attach the deploy log. The one in the attached sosrepot is cut in the middle and is different from the one in the pastebin of comment 7.

All my patches so far were for 2_ovirt_logger , not for 1_otopi_json, so bug is indeed not fixed. But need to understand where and how it fails exactly.

Comment 10 Nikolai Sednev 2018-02-06 15:20:34 UTC
Created attachment 1392141 [details]
sosreport from puma19

Comment 11 Nikolai Sednev 2018-02-06 15:33:28 UTC
Here is the deployment stages:
http://pastebin.test.redhat.com/553202

Comment 12 Nikolai Sednev 2018-02-06 16:11:14 UTC
Created attachment 1392198 [details]
all 13 logs from /var/log/ovirt-hosted-engine-setup/

Comment 13 Sandro Bonazzola 2018-02-22 08:50:06 UTC
Raising severity to medium: it's seems to affect just on negative flows but if we receive any unicode char on output message we badly fail without logging it

Comment 14 Simone Tiraboschi 2018-02-22 13:33:31 UTC
The issue was about parsing unicode chars in error message strings (dd ones for instance), nothing was really failing on the positive flow.

To trigger a failure temporary overwrite /usr/share/ovirt-hosted-engine-setup/ansible/get_network_interfaces.yml with the attached test.yml which will fail on dd with unicode chars in its output and ensure that the error message is properly handled.
Please try with different host locales.

Comment 15 Simone Tiraboschi 2018-02-22 13:34:43 UTC
Created attachment 1399368 [details]
test.yml

Comment 16 Nikolai Sednev 2018-03-18 17:14:03 UTC
Moving to verified as original error message was not reproduced.

Components on host:
ovirt-hosted-engine-ha-2.2.7-1.el7ev.noarch
ovirt-hosted-engine-setup-2.2.13-1.el7ev.noarch
rhvm-appliance-4.2-20180202.0.el7.noarch
Linux 3.10.0-861.el7.x86_64 #1 SMP Wed Mar 14 10:21:01 EDT 2018 x86_64 x86_64 x86_64 GNU/Linux
Red Hat Enterprise Linux Server release 7.5 (Maipo)

Comment 17 Sandro Bonazzola 2018-03-29 11:00:20 UTC
This bugzilla is included in oVirt 4.2.2 release, published on March 28th 2018.

Since the problem described in this bug report should be
resolved in oVirt 4.2.2 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.