Workaround for no Exception issue for some failed ansible modules #1786

wangxin · 2020-06-18T09:22:12Z

Description of PR

Summary:
Fixes # (issue)

Currently pytest-ansible depends on the 'failed' or 'rc' field in the module result
to determine whether the result is failed. Some ansible modules only have 'failed'
field in their results. Due to an issue of pytest-ansible:
ansible/pytest-ansible#47
The module results returned by pytest-ansible do not have such 'failed' field
even when the ansible module failed. In this case, the is_failed property will
always be False. Consequently, no exception will be raised when running
such ansible modules failed.

This commit is a workaround for this pytest-ansible issue. According to current ansible
behavior, the 'exception' field will be available in failed ansible module result
most of the time. I added checking for the 'exception' filed in ansible module results.
When such field is observed in the result, we raise RunAnsibleModuleFail exception too.

Ideally I hope it could be fixed in pytest-ansible.

Type of change

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

Approach

What is the motivation for this PR?

When some ansible built-in modules failed, no exception is raised. The test case may be considered as passed. This does not make sense.

How did you do it?

Not just check res.is_failed property while checking ansible module execution result. Add checking availability of 'exception' field in the result dictionary. If the 'exception' field is found, raise RunAnsibleModuleFail exception as well.

How did you verify/test it?

I prepared a test script like below:

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)


def test_case2(duthost):

    try:
        duthost.copy(src="veos.vtb", dest="/notexist/nonexist.txt")
    except Exception as e:
        logger.error(str(e))
        logger.error(repr(e))

    res = duthost.copy(src="veos.vtb", dest="/notexist/nonexist.txt")


def test_case3(duthost):

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

    duthost.lldp_facts()

Without this fix, tese_case1 failed because it has none-zero 'rc` in the result. However, both test_case2 and test_case3 passed.

With this fix, all the test cases failed as expected:

$ pytest --inventory veos.vtb --host-pattern vlab-01  --testbed vms-kvm-t0 --testbed_file vtestbed.csv --showlocals --assert plain --log-cli-level error test_example.py --skip_sanity --disable_loganalyzer -ra
============================= 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 3 items

test_example.py::test_case1 
-------------------------------- live log call ---------------------------------
09:14:27 ERROR test_example.py:test_case1:15: run module shell failed
Ansible Results => changed=true 
  cmd: mv notexit2 notexit3
  delta: '0:00:00.005805'
  end: '2020-06-18 09:14:19.278487'
  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 09:14:19.272682'
  stderr: 'mv: cannot stat ''notexit2'': No such file or directory'
  stderr_lines: <omitted>
  stdout: ''
  stdout_lines: <omitted>
09:14:27 ERROR test_example.py:test_case1:16: run module shell failed
Loading callback plugin yaml of type stdout, v2.0 from /usr/local/lib/python2.7/dist-packages/ansible/plugins/callback/yaml.pyc
Loading callback plugin yaml of type stdout, v2.0 from /usr/local/lib/python2.7/dist-packages/ansible/plugins/callback/yaml.pyc
FAILED                                                                   [ 33%]
test_example.py::test_case2 
-------------------------------- live log call ---------------------------------
09:14:31 ERROR test_example.py:test_case2:26: run module copy failed
Ansible Results => changed=false 
  checksum: cc77ab054848f92d926b4a43a7bc57bb54916e9b
  diff: []
  invocation:
    module_args:
      _original_basename: veos.vtb
      attributes: null
      backup: false
      checksum: cc77ab054848f92d926b4a43a7bc57bb54916e9b
      content: null
      delimiter: null
      dest: /notexist/nonexist.txt
      directory_mode: null
      follow: false
      force: true
      group: null
      local_follow: null
      mode: null
      owner: null
      regexp: null
      remote_src: null
      selevel: null
      serole: null
      setype: null
      seuser: null
      src: /home/admin/.ansible/tmp/ansible-tmp-1592471670.59-4036809725063/source
      unsafe_writes: null
      validate: null
  msg: Destination directory /notexist does not exist
09:14:31 ERROR test_example.py:test_case2:27: run module copy failed
Loading callback plugin yaml of type stdout, v2.0 from /usr/local/lib/python2.7/dist-packages/ansible/plugins/callback/yaml.pyc
Loading callback plugin yaml of type stdout, v2.0 from /usr/local/lib/python2.7/dist-packages/ansible/plugins/callback/yaml.pyc
FAILED                                                                   [ 66%]
test_example.py::test_case3 
-------------------------------- live log call ---------------------------------
09:14:35 ERROR test_example.py:test_case3:37: run module lldp_facts failed
Ansible Results => changed=false 
  invocation:
    module_args:
      community: false
  msg: 'missing required arguments: host, version'
09:14:35 ERROR test_example.py:test_case3:38: run module lldp_facts failed
Loading callback plugin yaml of type stdout, v2.0 from /usr/local/lib/python2.7/dist-packages/ansible/plugins/callback/yaml.pyc
Loading callback plugin yaml of type stdout, v2.0 from /usr/local/lib/python2.7/dist-packages/ansible/plugins/callback/yaml.pyc
FAILED                                                                   [100%]

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

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

    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 0x7f95a07af950>
e          = run module shell failed

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

self = <tests.common.devices.SonicHost object at 0x7f95a07af950>
module_args = ('mv notexit2 notexit3',), complex_args = {}
previous_frame = <frame object at 0x7f959e84db30>
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 or 'exception' in res) and not module_ignore_errors:
>           raise RunAnsibleModuleFail("run module {} failed".format(self.module_name), res)
E           RunAnsibleModuleFail: run module shell failed
E           Ansible Results => changed=true 
E             cmd: mv notexit2 notexit3
E             delta: '0:00:00.008106'
E             end: '2020-06-18 09:14:19.634774'
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             msg: non-zero return code
E             rc: 1
E             start: '2020-06-18 09:14:19.626668'
E             stderr: 'mv: cannot stat ''notexit2'': No such file or directory'
E             stderr_lines: <omitted>
E             stdout: ''
E             stdout_lines: <omitted>

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 0x7f959e84db30>
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 0x7f95a07af950>

common/devices.py:82: RunAnsibleModuleFail
__________________________________ test_case2 __________________________________

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

    def test_case2(duthost):
    
        try:
            duthost.copy(src="veos.vtb", dest="/notexist/nonexist.txt")
        except Exception as e:
            logger.error(str(e))
            logger.error(repr(e))
    
>       res = duthost.copy(src="veos.vtb", dest="/notexist/nonexist.txt")

duthost    = <tests.common.devices.SonicHost object at 0x7f95a07af950>
e          = run module copy failed

test_example.py:29: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <tests.common.devices.SonicHost object at 0x7f95a07af950>
module_args = ()
complex_args = {'dest': '/notexist/nonexist.txt', 'src': 'veos.vtb'}
previous_frame = <frame object at 0x2217860>
filename = '/var/johnar/code/sonic-mgmt/tests/test_example.py', line_number = 29
function_name = 'test_case2'
lines = ['    res = duthost.copy(src="veos.vtb", dest="/notexist/nonexist.txt")\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 or 'exception' in res) and not module_ignore_errors:
>           raise RunAnsibleModuleFail("run module {} failed".format(self.module_name), res)
E           RunAnsibleModuleFail: run module copy failed
E           Ansible Results => changed=false 
E             checksum: cc77ab054848f92d926b4a43a7bc57bb54916e9b
E             diff: []
E             invocation:
E               module_args:
E                 _original_basename: veos.vtb
E                 attributes: null
E                 backup: false
E                 checksum: cc77ab054848f92d926b4a43a7bc57bb54916e9b
E                 content: null
E                 delimiter: null
E                 dest: /notexist/nonexist.txt
E                 directory_mode: null
E                 follow: false
E                 force: true
E                 group: null
E                 local_follow: null
E                 mode: null
E                 owner: null
E                 regexp: null
E                 remote_src: null
E                 selevel: null
E                 serole: null
E                 setype: null
E                 seuser: null
E                 src: /home/admin/.ansible/tmp/ansible-tmp-1592471671.65-17999273502145/source
E                 unsafe_writes: null
E                 validate: null
E             msg: Destination directory /notexist does not exist

complex_args = {'dest': '/notexist/nonexist.txt', 'src': 'veos.vtb'}
filename   = '/var/johnar/code/sonic-mgmt/tests/test_example.py'
function_name = 'test_case2'
index      = 0
line_number = 29
lines      = ['    res = duthost.copy(src="veos.vtb", dest="/notexist/nonexist.txt")\n']
module_args = ()
module_async = False
module_ignore_errors = False
previous_frame = <frame object at 0x2217860>
res        = {u'msg': u'Destination directory /notexist does not exist', u'exception': u'WA...e}}, 'checksum': u'cc77ab054848f92d926b4a43a7bc57bb54916e9b', 'changed': False}
self       = <tests.common.devices.SonicHost object at 0x7f95a07af950>

common/devices.py:82: RunAnsibleModuleFail
__________________________________ test_case3 __________________________________

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

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

duthost    = <tests.common.devices.SonicHost object at 0x7f95a07af950>
e          = run module lldp_facts failed

test_example.py:40: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <tests.common.devices.SonicHost object at 0x7f95a07af950>
module_args = (), complex_args = {}
previous_frame = <frame object at 0x259c2e0>
filename = '/var/johnar/code/sonic-mgmt/tests/test_example.py', line_number = 40
function_name = 'test_case3', lines = ['    duthost.lldp_facts()\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 or 'exception' in res) and not module_ignore_errors:
>           raise RunAnsibleModuleFail("run module {} failed".format(self.module_name), res)
E           RunAnsibleModuleFail: run module lldp_facts failed
E           Ansible Results => changed=false 
E             invocation:
E               module_args:
E                 community: false
E             msg: 'missing required arguments: host, version'

complex_args = {}
filename   = '/var/johnar/code/sonic-mgmt/tests/test_example.py'
function_name = 'test_case3'
index      = 0
line_number = 40
lines      = ['    duthost.lldp_facts()\n']
module_args = ()
module_async = False
module_ignore_errors = False
previous_frame = <frame object at 0x259c2e0>
res        = {u'invocation': {u'module_args': {u'community': False}}, u'msg': u'missing req...raise TypeError(to_native(msg))\n', 'changed': False, '_ansible_no_log': False}
self       = <tests.common.devices.SonicHost object at 0x7f95a07af950>

common/devices.py:82: RunAnsibleModuleFail
=========================== short test summary info ============================
FAILED test_example.py::test_case1 - RunAnsibleModuleFail: run module shell f...
FAILED test_example.py::test_case2 - RunAnsibleModuleFail: run module copy fa...
FAILED test_example.py::test_case3 - RunAnsibleModuleFail: run module lldp_fa...
========================== 3 failed in 17.62 seconds ===========================

Any platform specific information?

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

Documentation

Currently pytest-ansible depends on the 'failed' or 'rc' field in the module result to determine whether the result is failed. Some ansible modules only have 'failed' field in their results. Due to an issue of pytest-ansible: ansible/pytest-ansible#47 The module results returned by pytest-ansible do not have such 'failed' field even when the ansible module failed. In this case, the `is_failed` property will always be `False`. Consequent, no exception will be raised when running some ansible module failed. This commit is a workaround for this issue. According to current ansible behavior, the 'exception' field will be available in failed ansible module result most of the time. When such field is observed in the result, we raise `RunAnsibleModuleFail` exception too. Signed-off-by: Xin Wang <xiwang5@microsoft.com>

neethajohn · 2020-06-19T17:27:16Z

retest this please

wangxin · 2020-06-22T06:04:21Z

The vsimage testing failed issue is fixed in #1799.

PR #1786 fixed an issue that no exception is raised for some failed ansible modules. With that fix, the controle plane acl testing will fail. The reason is that calling some of the ansible modules in this script is expected to fail. However, because of the issue fixed by #1786, no exception is raised . The test script explicitly check error message to determine if the ansible module calling is failed or not. With the fix of #1786, exception will be raised while calling ansible modules that are expected to fail. We need to add `module_ignore_errors=True` for these modules. Then we check the msg field of ansible module results to determine whether the testing is expected or not. Signed-off-by: Xin Wang <xiwang5@microsoft.com>

wangxin · 2020-06-24T10:43:43Z

retest this please

wangxin added Pytest 🐍 KVM Testing 🧪 labels Jun 18, 2020

wangxin requested review from lguohan and a team June 18, 2020 09:22

wangxin removed the KVM Testing 🧪 label Jun 18, 2020

neethajohn approved these changes Jun 18, 2020

View reviewed changes

tahmed-dev approved these changes Jun 19, 2020

View reviewed changes

wangxin mentioned this pull request Jun 22, 2020

Fix control plane ACL testing for PR #1786 #1799

Merged

3 tasks

jleveque approved these changes Jun 22, 2020

View reviewed changes

wangxin merged commit 1706d54 into sonic-net:master Jun 28, 2020

wangxin mentioned this pull request Jun 28, 2020

Add check and waiting for exabgp http server #1813

Merged

3 tasks

This was referenced Aug 7, 2020

localhost wait_for does not return a failure nor exception #1941

Closed

Fix the issue of no 'failed' field in failed ansible module result #2063

Merged

wangxin deleted the workaround-for-failed-ansible-modules branch September 24, 2020 02:34

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Workaround for no Exception issue for some failed ansible modules #1786

Workaround for no Exception issue for some failed ansible modules #1786

wangxin commented Jun 18, 2020 •

edited

Loading

neethajohn commented Jun 19, 2020

wangxin commented Jun 22, 2020

wangxin commented Jun 24, 2020

Workaround for no Exception issue for some failed ansible modules #1786

Workaround for no Exception issue for some failed ansible modules #1786

Conversation

wangxin commented Jun 18, 2020 • edited Loading

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

neethajohn commented Jun 19, 2020

wangxin commented Jun 22, 2020

wangxin commented Jun 24, 2020

wangxin commented Jun 18, 2020 •

edited

Loading