Fix the issue of unprintable RunAnsibleModuleFail object by wangxin · Pull Request #1739 · sonic-net/sonic-mgmt

wangxin · 2020-06-05T11:25:09Z

Description of PR

Summary:
Fixes #1731

Type of change

Bug fix
Testbed and Framework(new/improvement)
Test case(new/improvement)

Approach

What is the motivation for this PR?

Fix issue #1731

How did you do it?

The possible reason is that exception is raised in str method of the RunAnsibleModuleFail class. The change is to catch any possible error of json.dumps while converting the ansible module result to human friendly string. If the json.dumps call failed, use the safer builtin str() function to convert the ansible result to a less human friendly string as a fall back method.

How did you verify/test it?

The original issue is not reproducible on my side. That's why I make this PR as a draft at this point.

What I tested:

Create a simple pytest script to run ansible module that will fail on purpose.
Run the script.
Verify that appropriate exception is logged.

Any platform specific information?

Supported testbed topology if it's a new test case?

Documentation

wangxin · 2020-06-05T11:27:19Z

@nazariig Since I can't reproduce issue #1731 from my side, would please kindly help verify if this PR can fix that issue?

nazariig · 2020-06-06T13:09:45Z

@wangxin let's please have this merged ASAP.

nazariig · 2020-06-07T12:09:49Z

@yvolynets-mlnx please have a look.

tests/common/errors.py

dawnbeauty · 2020-06-15T04:22:11Z

@wangxin I think it's better to reuse the stdout callback plugin from ansible to convet the result obj to strings, since stdout callback would like to filter out some internal vars of ansible for us.
And it's better to create a separate common function instead of a method, sinice we may need the function outside class 'RunAnsibleModuleFail'.

So, i mean just catch the exception when converting the error obj to strings in 'dump_ansible_results'.

lgtm-com · 2020-06-17T06:49:33Z

This pull request introduces 1 alert when merging 4aad8a84cf035dbd88b4b865c033bbe117cb5697 into d09d6d2 - view on LGTM.com

new alerts:

1 for Unused import

lguohan · 2020-06-17T09:58:49Z

can you provide examples?

wangxin · 2020-06-18T08:09:14Z

The fix was tested using a script like this:

test_example.py:

import logging

logger = logging.getLogger(__name__)


def runner(duthost):
    duthost.shell("mv notexit2 notexit3")


def test_case1(duthost):

    try:
        runner(duthost)
    except Exception as e:
        logger.error(str(e))
        logger.error(repr(e))

    runner(duthost)

Log of running this script:

============================= test session starts ==============================
platform linux2 -- Python 2.7.12, pytest-4.6.5, py-1.8.1, pluggy-0.13.1
ansible: 2.8.7
rootdir: /var/johnar/code/sonic-mgmt/tests, inifile: pytest.ini
plugins: repeat-0.8.0, xdist-1.28.0, forked-1.1.3, ansible-2.2.2
collected 1 item

test_example.py::test_case1 
-------------------------------- live log call ---------------------------------
08:07:02 ERROR test_example.py:test_case1:15: run module shell failed, Ansible Results =>
{
    "changed": true, 
    "cmd": "mv notexit2 notexit3", 
    "delta": "0:00:00.052135", 
    "end": "2020-06-18 08:06:54.087825", 
    "invocation": {
        "module_args": {
            "_raw_params": "mv notexit2 notexit3", 
            "_uses_shell": true, 
            "argv": null, 
            "chdir": null, 
            "creates": null, 
            "executable": null, 
            "removes": null, 
            "stdin": null, 
            "stdin_add_newline": true, 
            "strip_empty_ends": true, 
            "warn": true
        }
    }, 
    "msg": "non-zero return code", 
    "rc": 1, 
    "start": "2020-06-18 08:06:54.035690", 
    "stderr": "mv: cannot stat 'notexit2': No such file or directory", 
    "stderr_lines": [
        "mv: cannot stat 'notexit2': No such file or directory"
    ], 
    "stdout": "", 
    "stdout_lines": []
}
08:07:02 ERROR test_example.py:test_case1:16: run module shell failed, Ansible Results =>
{
    "changed": true, 
    "cmd": "mv notexit2 notexit3", 
    "delta": "0:00:00.052135", 
    "end": "2020-06-18 08:06:54.087825", 
    "invocation": {
        "module_args": {
            "_raw_params": "mv notexit2 notexit3", 
            "_uses_shell": true, 
            "argv": null, 
            "chdir": null, 
            "creates": null, 
            "executable": null, 
            "removes": null, 
            "stdin": null, 
            "stdin_add_newline": true, 
            "strip_empty_ends": true, 
            "warn": true
        }
    }, 
    "msg": "non-zero return code", 
    "rc": 1, 
    "start": "2020-06-18 08:06:54.035690", 
    "stderr": "mv: cannot stat 'notexit2': No such file or directory", 
    "stderr_lines": [
        "mv: cannot stat 'notexit2': No such file or directory"
    ], 
    "stdout": "", 
    "stdout_lines": []
}
Loading callback plugin json of type stdout, v2.0 from /usr/local/lib/python2.7/dist-packages/ansible/plugins/callback/json.pyc
Loading callback plugin json of type stdout, v2.0 from /usr/local/lib/python2.7/dist-packages/ansible/plugins/callback/json.pyc
Loading callback plugin json of type stdout, v2.0 from /usr/local/lib/python2.7/dist-packages/ansible/plugins/callback/json.pyc
FAILED                                                                   [100%]

=================================== FAILURES ===================================
__________________________________ test_case1 __________________________________

duthost = <tests.common.devices.SonicHost object at 0x7fe672e81150>

    def test_case1(duthost):
    
        try:
            runner(duthost)
        except Exception as e:
            logger.error(str(e))
            logger.error(repr(e))
    
>       runner(duthost)

duthost    = <tests.common.devices.SonicHost object at 0x7fe672e81150>
e          = run module shell failed, Ansible Results =>
{
    "changed": true, 
    "cmd":... No such file or directory"
    ], 
    "stdout": "", 
    "stdout_lines": []
}

test_example.py:18: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
test_example.py:7: in runner
    duthost.shell("mv notexit2 notexit3")
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <tests.common.devices.SonicHost object at 0x7fe672e81150>
module_args = ('mv notexit2 notexit3',), complex_args = {}
previous_frame = <frame object at 0x7fe670f4cb30>
filename = '/var/johnar/code/sonic-mgmt/tests/test_example.py', line_number = 7
function_name = 'runner'
lines = ['    duthost.shell("mv notexit2 notexit3")\n'], index = 0
module_ignore_errors = False, module_async = False

    def _run(self, *module_args, **complex_args):
    
        previous_frame = inspect.currentframe().f_back
        filename, line_number, function_name, lines, index = inspect.getframeinfo(previous_frame)
    
        logging.debug("{}::{}#{}: [{}] AnsibleModule::{}, args={}, kwargs={}"\
            .format(filename, function_name, line_number, self.hostname,
                    self.module_name, json.dumps(module_args), json.dumps(complex_args)))
    
        module_ignore_errors = complex_args.pop('module_ignore_errors', False)
        module_async = complex_args.pop('module_async', False)
    
        if module_async:
            def run_module(module_args, complex_args):
                return self.module(*module_args, **complex_args)[self.hostname]
            pool = ThreadPool()
            result = pool.apply_async(run_module, (module_args, complex_args))
            return pool, result
    
        res = self.module(*module_args, **complex_args)[self.hostname]
        logging.debug("{}::{}#{}: [{}] AnsibleModule::{} Result => {}"\
            .format(filename, function_name, line_number, self.hostname, self.module_name, json.dumps(res)))
    
        if res.is_failed and not module_ignore_errors:
>           raise RunAnsibleModuleFail("run module {} failed".format(self.module_name), res)
E           RunAnsibleModuleFail: run module shell failed, Ansible Results =>
E           {
E               "changed": true, 
E               "cmd": "mv notexit2 notexit3", 
E               "delta": "0:00:00.011396", 
E               "end": "2020-06-18 08:06:55.134091", 
E               "invocation": {
E                   "module_args": {
E                       "_raw_params": "mv notexit2 notexit3", 
E                       "_uses_shell": true, 
E                       "argv": null, 
E                       "chdir": null, 
E                       "creates": null, 
E                       "executable": null, 
E                       "removes": null, 
E                       "stdin": null, 
E                       "stdin_add_newline": true, 
E                       "strip_empty_ends": true, 
E                       "warn": true
E                   }
E               }, 
E               "msg": "non-zero return code", 
E               "rc": 1, 
E               "start": "2020-06-18 08:06:55.122695", 
E               "stderr": "mv: cannot stat 'notexit2': No such file or directory", 
E               "stderr_lines": [
E                   "mv: cannot stat 'notexit2': No such file or directory"
E               ], 
E               "stdout": "", 
E               "stdout_lines": []
E           }

complex_args = {}
filename   = '/var/johnar/code/sonic-mgmt/tests/test_example.py'
function_name = 'runner'
index      = 0
line_number = 7
lines      = ['    duthost.shell("mv notexit2 notexit3")\n']
module_args = ('mv notexit2 notexit3',)
module_async = False
module_ignore_errors = False
previous_frame = <frame object at 0x7fe670f4cb30>
res        = {'stderr_lines': [u"mv: cannot stat 'notexit2': No such file or directory"], u...': True, u'stdin': None}}, 'stdout_lines': [], u'msg': u'non-zero return code'}
self       = <tests.common.devices.SonicHost object at 0x7fe672e81150>

common/devices.py:82: RunAnsibleModuleFail
=========================== short test summary info ============================
FAILED test_example.py::test_case1 - RunAnsibleModuleFail: run module shell f...
========================== 1 failed in 10.04 seconds ===========================

wangxin · 2020-06-19T08:07:36Z

retest this please

daall · 2020-06-19T17:13:58Z

retest vsimage please

Fix issue #1731 Signed-off-by: Xin Wang <[email protected]>

wangxin · 2020-06-22T05:14:19Z

Resolved the merge conflicts.

Issue #1731 was not fully fixed by PR #1739. When RunAnsibleModuleFail exception is raised by running ptf script, the unprintable exception issue was still observed. The reason is that the ansible result may contain unicode string. Concatenating ascii string with unicode string may raise uncaught exception and cause this issue. The fix is to concatenate unicode string with the ansible result. Then encode it to ascii string. Signed-off-by: Xin Wang <[email protected]>

8b149a3 Load the database global_db only once for show cli (sonic-net#1712) cd0e560 [config][interface][speed] Fixed the config interface speed in multiasic issue (sonic-net#1739) b595ba6 [fast-reboot] revert the change of disabling counter polling before fast-reboot (sonic-net#1744) 8518820 [minigraph] Donot enable PFC watchdog for MgmtTsToR (sonic-net#1734) 2213774 [CLI][show][bgp] Fix the show ip bgp network command (sonic-net#1733) 3526507 [configlet] Python3 compatible syntax for extracting a key from the dict (sonic-net#1721) 5b56b97 [sonic_installer] don't print errors when installing an image not supporting app ext (sonic-net#1719) a581955 [LLDP] Fix lldpshow script to enable display multiple MAC addresses on the same remote physical interface (sonic-net#1657)

wangxin marked this pull request as ready for review June 7, 2020 00:46

nazariig requested a review from lguohan June 7, 2020 12:08

daall added Jenkins-Pilot and removed Jenkins-Pilot labels Jun 8, 2020

yvolynets-mlnx reviewed Jun 9, 2020

View reviewed changes

tests/common/errors.py Outdated Show resolved Hide resolved

nazariig added Bug 🐛 Critical Pytest 🐍 labels Jun 10, 2020

tahmed-dev approved these changes Jun 19, 2020

View reviewed changes

Fix the issue of unprintable RunAnsibleModuleFail object

f10bcdc

Fix issue #1731 Signed-off-by: Xin Wang <[email protected]>

wangxin merged commit 8e946c6 into sonic-net:master Jun 22, 2020

wangxin deleted the fix-unprintable-exception branch June 28, 2020 10:28

wangxin mentioned this pull request Jul 4, 2020

Fix unprintable RunAnsibleModuleFail exception #1846

Merged

3 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix the issue of unprintable RunAnsibleModuleFail object#1739

Fix the issue of unprintable RunAnsibleModuleFail object#1739
wangxin merged 1 commit intosonic-net:masterfrom
wangxin:fix-unprintable-exception

wangxin commented Jun 5, 2020

Uh oh!

wangxin commented Jun 5, 2020

Uh oh!

nazariig commented Jun 6, 2020

Uh oh!

nazariig commented Jun 7, 2020

Uh oh!

Uh oh!

dawnbeauty commented Jun 15, 2020

Uh oh!

lgtm-com bot commented Jun 17, 2020

Uh oh!

lguohan commented Jun 17, 2020

Uh oh!

wangxin commented Jun 18, 2020

Uh oh!

wangxin commented Jun 19, 2020

Uh oh!

daall commented Jun 19, 2020

Uh oh!

wangxin commented Jun 22, 2020

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

7 participants

Conversation

wangxin commented Jun 5, 2020

Description of PR

Type of change

Approach

What is the motivation for this PR?

How did you do it?

How did you verify/test it?

Any platform specific information?

Supported testbed topology if it's a new test case?

Documentation

Uh oh!

wangxin commented Jun 5, 2020

Uh oh!

nazariig commented Jun 6, 2020

Uh oh!

nazariig commented Jun 7, 2020

Uh oh!

Uh oh!

dawnbeauty commented Jun 15, 2020

Uh oh!

lgtm-com bot commented Jun 17, 2020

Uh oh!

lguohan commented Jun 17, 2020

Uh oh!

wangxin commented Jun 18, 2020

Uh oh!

wangxin commented Jun 19, 2020

Uh oh!

daall commented Jun 19, 2020

Uh oh!

wangxin commented Jun 22, 2020

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

7 participants