Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[BUG] salt.client.ssh.shell.Shell.exec_cmd can fail to report any exit status #64588

Closed
lkubb opened this issue Jun 30, 2023 · 1 comment
Closed
Labels
Bug broken, incorrect, or confusing behavior needs-triage Salt-SSH

Comments

@lkubb
Copy link
Contributor

lkubb commented Jun 30, 2023

Description
In rare cases, salt.client.ssh.shell.Shell.exec_cmd queries the exit status of its VT before it is closed completely and its value was set, resulting in a None retcode. Also, if os.WIFEXITED is False (e.g. irregular exit because of a signal), it returns None as well.

Setup
irrelevant

Steps to Reproduce the behavior
Run many salt-ssh integration tests with a patch that accounts and checks for retcode is None and find that retcode is seldomly (but reliably) reported as None (by salt.client.ssh.Single.cmd_block), even though the actual command returns the correct data:

[08:24:48] FAILED
   tests/integration/cli/test_custom_module.py::SSHCustomModuleTest::test_ssh_sls_with_custom_module
[15:43:15] 15:43:15,614 [salt.client.ssh                                :289 ][ERROR   ][         Process-1(2918)] {'local': 'An Exception occurred while executing state.sls: Got None retcode: {"stdout": "{\\n    \\"local\\": {\\n        \\"jid\\": \\"20230630154314751314\\",\\n        \\"return\\": {\\n            \\"module_|-regular-module_|-test.echo_|-run\\": {\\n                \\"name\\": \\"test.echo\\",\\n                \\"changes\\": {\\n                    \\"ret\\": \\"hello\\"\\n                },\\n                \\"comment\\": \\"Module function test.echo executed\\",\\n                \\"result\\": true,\\n                \\"__sls__\\": \\"custom_module\\",\\n                \\"__run_num__\\": 0,\\n                \\"start_time\\": \\"15:43:15.257899\\",\\n                \\"duration\\": 1.576,\\n                \\"__id__\\": \\"regular-module\\"\\n            },\\n            \\"module_|-custom-module_|-test.recho_|-run\\": {\\n                \\"name\\": \\"test.recho\\",\\n                ...
[15:43:16] FAILED
           =================================== FAILURES ===================================
           _____________ SSHCustomModuleTest.test_ssh_sls_with_custom_module ______________
           
           self = <tests.integration.cli.test_custom_module.SSHCustomModuleTest testMethod=test_ssh_sls_with_custom_module>
           
               @pytest.mark.slow_test
               def test_ssh_sls_with_custom_module(self):
                   """
                   Test sls with custom module work using SSHCase environment
                   """
                   expected = {
                       "module_|-regular-module_|-test.echo_|-run": "hello",
                       "module_|-custom-module_|-test.recho_|-run": "olleh",
                   }
                   cmd = self.run_function("state.sls", arg=["custom_module"])
                   for key in cmd:
                       if not isinstance(cmd, dict) or not isinstance(cmd[key], dict):
           >               raise AssertionError("{} is not a proper state return".format(cmd))
           E               AssertionError: An Exception occurred while executing state.sls: Got None retcode: {"stdout": "{\n    \"local\": {\n        \"jid\": \"20230630154314751314\",\n        \"return\": {\n            \"module_|-regular-module_|-test.echo_|-run\": {\n                \"name\": \"test.echo\",\n                \"changes\": {\n                    \"ret\": \"hello\"\n                },\n                \"comment\": \"Module function test.echo executed\",\n                \"result\": true,\n                \"__sls__\": \"custom_module\",\n                \"__run_num__\": 0,\n                \"start_time\": \"15:43:15.257899\",\n                \"duration\": 1.576,\n                \"__id__\": \"regular-module\"\n            },\n            \"module_|-custom-module_|-test.recho_|-run\": {\n                \"name\": \"test.recho\",\n                \"changes\": {\n                    \"ret\": \"olleh\"\n                },\n                \"comment\": \"Module function test.recho execute...
           cmd        = ('An Exception occurred while executing state.sls: Got None retcode: '
            '{"stdout": "{\\n    \\"local\\": {\\n        \\"jid\\": '
            '\\"20230630154314751314\\",\\n        \\"return\\": {\\n            '
            '\\"module_|-regular-module_|-test.echo_|-run\\": {\\n                '
            '\\"name\\": \\"test.echo\\",\\n                \\"changes\\": '
            '{\\n                    \\"ret\\": \\"hello\\"\\n                '
            '},\\n                \\"comment\\": \\"Module function test.echo '
            'executed\\",\\n                \\"result\\": true,\\n                '
            '\\"__sls__\\": \\"custom_module\\",\\n                \\"__run_num__\\": '
            '0,\\n                \\"start_time\\": '
            '\\"15:43:15.257899\\",\\n                \\"duration\\": '
            '1.576,\\n                \\"__id__\\": \\"regular-module\\"\\n            '
            '},\\n            \\"module_|-custom-module_|-test.recho_|-run\\": '
            '{\\n                \\"name\\": \\"test.recho\\",\\n                '
            '\\"changes\\": {\\n                    \\"ret\\": '
            '\\"olleh\\"\\n                },\\n                \\"comment\\": \\"Module '
            'function test.recho executed\\",\\n                \\"result\\": '
            'true,\\n                \\"__sls__\\": '
            '\\"custom_module\\",\\n                \\"__run_num__\\": '
            '1,\\n                \\"start_time\\": '
            '\\"15:43:15.259576\\",\\n                \\"duration\\": '
            '1.537,\\n                \\"__id__\\": \\"custom-module\\"\\n            '
            '}\\n        },\\n        \\"retcode\\": 0,\\n        \\"out\\": '
            '\\"highstate\\",\\n        \\"id\\": \\"localhost\\",\\n        \\"fun\\": '
            '\\"state.pkg\\",\\n        \\"fun_args\\": [\\n            '
            '\\"/var/tmp/.fd2f49/salt_state.tgz\\",\\n            '
            '\\"test=None\\",\\n            '
            '\\"pkg_sum=062c2d1789d0f14ac22c3eac3c4e70c2df0083bc639d725fdb3dd28937dbd9cb\\",\\n            '
            '\\"hash_type=sha256\\"\\n        ]\\n    }\\n}", "stderr": "", "retcode": 1, '
            '"parsed": {"local": {"jid": "20230630154314751314", "return": '
            '{"module_|-regular-module_|-test.echo_|-run": {"name": "test.echo", '
            '"changes": {"ret": "hello"}, "comment": "Module function test.echo '
            'executed", "result": true, "__sls__": "custom_module", "__run_num__": 0, '
            '"start_time": "15:43:15.257899", "duration": 1.576, "__id__": '
            '"regular-module"}, "module_|-custom-module_|-test.recho_|-run": {"name": '
            '"test.recho", "changes": {"ret": "olleh"}, "comment": "Module function '
            'test.recho executed", "result": true, "__sls__": "custom_module", '
            '"__run_num__": 1, "start_time": "15:43:15.259576", "duration": 1.537, '
            '"__id__": "custom-module"}}, "retcode": 0, "out": "highstate", "id": '
            '"localhost", "fun": "state.pkg", "fun_args": '
            '["/var/tmp/.fd2f49/salt_state.tgz", "test=None", '
            '"pkg_sum=062c2d1789d0f14ac22c3eac3c4e70c2df0083bc639d725fdb3dd28937dbd9cb", '
            '"hash_type=sha256"]}}, "_error": "Got None retcode", "return": {"jid": '
            '"20230630154314751314", "return": '
            '{"module_|-regular-module_|-test.echo_|-run": {"name": "test.echo", '
            '"changes": {"ret": "hello"}, "comment": "Module function test.echo '
            'executed", "result": true, "__sls__": "custom_module", "__run_num__": 0, '
            '"start_time": "15:43:15.257899", "duration": 1.576, "__id__": '
            '"regular-module"}, "module_|-custom-module_|-test.recho_|-run": {"name": '
            '"test.recho", "changes": {"ret": "olleh"}, "comment": "Module function '
            'test.recho executed", "result": true, "__sls__": "custom_module", '
            '"__run_num__": 1, "start_time": "15:43:15.259576", "duration": 1.537, '
            '"__id__": "custom-module"}}, "retcode": 0, "out": "highstate", "id": '
            '"localhost", "fun": "state.pkg", "fun_args": '
            '["/var/tmp/.fd2f49/salt_state.tgz", "test=None", '
            '"pkg_sum=062c2d1789d0f14ac22c3eac3c4e70c2df0083bc639d725fdb3dd28937dbd9cb", '
            '"hash_type=sha256"]}}')
           expected   = {'module_|-custom-module_|-test.recho_|-run': 'olleh',
            'module_|-regular-module_|-test.echo_|-run': 'hello'}
           key        = 'A'
           self       = <tests.integration.cli.test_custom_module.SSHCustomModuleTest testMethod=test_ssh_sls_with_custom_module>
           
           tests/integration/cli/test_custom_module.py:73: AssertionError
           __________________________ test_retcode_exe_run_fail ___________________________
           
           salt_ssh_cli = SaltSsh(id='master-cUqIRC', config_file='/tmp/stsuite/master-cUqIRC/conf/master', config_dir='/tmp/stsuite/master-cUqI...suite/master-cUqIRC/conf/roster'), client_key='/tmp/stsuite/sshd/client_key', target_host='localhost', ssh_user='root')
           
               def test_retcode_exe_run_fail(salt_ssh_cli):
                   """
                   Verify salt-ssh passes through the retcode it receives.
                   """
                   ret = salt_ssh_cli.run("file.touch", "/tmp/non/ex/is/tent")
                   assert ret.returncode == EX_AGGREGATE
           >       assert isinstance(ret.data, str)
           E       assert False
           E        +  where False = isinstance({'_error': 'Got None retcode', 'parsed': None, 'retcode': 1, 'stderr': "Error running 'file.touch': No such file or directory", ...}, str)
           E        +    where {'_error': 'Got None retcode', 'parsed': None, 'retcode': 1, 'stderr': "Error running 'file.touch': No such file or directory", ...} = ProcessResult(returncode=20, stdout='{\n"localhost": {\n"stdout": "",\n"stderr": "Error running \'file.touch\': No such file or directory",\n"retcode": 1,\n"parsed": null,\n"_error": "Got None retcode"\n}\n}\n', stderr='Coverage.py warning: No data was collected. (no-data-collected)\n', cmdline=['/tmp/testing/.nox/ci-test-onedir/bin/python', '/tmp/stsuite/scripts/cli_salt_ssh.py', '--ignore-host-keys', '--roster-file=/tmp/stsuite/master-cUqIRC/conf/roster', '--priv=/tmp/stsuite/sshd/client_key', '--user=root', '--config-dir=/tmp/stsuite/master-cUqIRC/conf', '--out=json', '--out-indent=0', '--log-level=critical', 'localhost', 'file.touch', '/tmp/non/ex/is/tent'], data_key=None, data={'stdout': '', 'stderr': "Error running 'file.touch': No such file or directory", 'retcode': 1, 'parsed': None, '_error': 'Got None retcode'}).data
           
           ret        = ProcessResult(returncode=20, stdout='{\n"localhost": {\n"stdout": "",\n"stderr": "Error running \'file.touch\': No such file or directory",\n"retcode": 1,\n"parsed": null,\n"_error": "Got None retcode"\n}\n}\n', stderr='Coverage.py warning: No data was collected. (no-data-collected)\n', cmdline=['/tmp/testing/.nox/ci-test-onedir/bin/python', '/tmp/stsuite/scripts/cli_salt_ssh.py', '--ignore-host-keys', '--roster-file=/tmp/stsuite/master-cUqIRC/conf/roster', '--priv=/tmp/stsuite/sshd/client_key', '--user=root', '--config-dir=/tmp/stsuite/master-cUqIRC/conf', '--out=json', '--out-indent=0', '--log-level=critical', 'localhost', 'file.touch', '/tmp/non/ex/is/tent'], data_key=None, data={'stdout': '', 'stderr': "Error running 'file.touch': No such file or directory", 'retcode': 1, 'parsed': None, '_error': 'Got None retcode'})

Expected behavior
Do not return None as an exit status. Return the actual exit status for regular exits, return a non-zero integer > 128 for irregular death by signal.

Versions Report
Present in current master.

Additional context

return ret_stdout, ret_stderr, term.exitstatus
finally:
term.close(terminate=True, kill=True)

salt/salt/utils/vt.py

Lines 770 to 774 in 2d02017

elif _wifsignaled(status):
self.status = status
self.exitstatus = None
self.signalstatus = _wtermsig(status)
self.terminated = True

This behavior is likely the cause of #64575 and became an issue because #64515 keeps track of the highest received retcode using max.

@lkubb lkubb added Bug broken, incorrect, or confusing behavior needs-triage labels Jun 30, 2023
@lkubb
Copy link
Contributor Author

lkubb commented Dec 12, 2023

Fixed by #64576

@lkubb lkubb closed this as completed Dec 12, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Bug broken, incorrect, or confusing behavior needs-triage Salt-SSH
Projects
None yet
Development

No branches or pull requests

2 participants