Nightly test test_commands.py::TestIPACommand::test_proxycommand_invalid_shell failed in [testing_ipa-4.9_latest_selinux] Nightly PR #804 with an error:
test_commands.py::TestIPACommand::test_proxycommand_invalid_shell
self = <ipatests.test_integration.test_commands.TestIPACommand object at 0x7f7a6aa755b0> def test_proxycommand_invalid_shell(self): """Test that ssh works with a user with an invalid shell. Specifically for this use-case: # getent passwd test test:x:1001:1001::/home/test:/sbin/nologin # sudo -u user ssh -v root@ipa.example.test ruser is our restricted user tuser1 is a regular user we ssh to remotely as """ password = 'Secret123' restricted_user = 'ruser' regular_user = 'tuser1' tasks.kinit_admin(self.master) tasks.user_add(self.master, restricted_user, extra_args=["--shell", "/sbin/nologin"], password=password) tasks.user_add(self.master, regular_user, password=password) user_kinit = "{password}\n{password}\n{password}\n".format( password=password) self.clients[0].run_command([ 'kinit', regular_user], stdin_text=user_kinit) self.clients[0].run_command([ 'kinit', restricted_user], stdin_text=user_kinit) tasks.kdestroy_all(self.clients[0]) # ssh as a restricted user to a user with a valid shell should # work > self.clients[0].run_command( ['sudo', '-u', restricted_user, 'sshpass', '-p', password, 'ssh', '-v', '-o', 'StrictHostKeyChecking=no', 'tuser1@%s' % self.master.hostname, 'cat /etc/hosts'], ) test_integration/test_commands.py:1439: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ self = <ipatests.pytest_ipa.integration.host.Host client0.ipa.test (client)> argv = ['sudo', '-u', 'ruser', 'sshpass', '-p', 'Secret123', ...] set_env = True, stdin_text = None, log_stdout = True, raiseonerr = True cwd = None, bg = False, encoding = 'utf-8', ok_returncode = 0 def run_command(self, argv, set_env=True, stdin_text=None, log_stdout=True, raiseonerr=True, cwd=None, bg=False, encoding='utf-8', ok_returncode=0): """Wrapper around run_command to log stderr on raiseonerr=True :param ok_returncode: return code considered to be correct, you can pass an integer or sequence of integers """ result = super().run_command( argv, set_env=set_env, stdin_text=stdin_text, log_stdout=log_stdout, raiseonerr=False, cwd=cwd, bg=bg, encoding=encoding ) # in FIPS mode SSH may print noise to stderr, remove the string # "FIPS mode initialized" + optional newline. result.stderr_bytes = FIPS_NOISE_RE.sub(b'', result.stderr_bytes) try: result_ok = result.returncode in ok_returncode except TypeError: result_ok = result.returncode == ok_returncode if not result_ok and raiseonerr: result.log.error('stderr: %s', result.stderr_text) > raise subprocess.CalledProcessError( result.returncode, argv, result.stdout_text, result.stderr_text ) E subprocess.CalledProcessError: Command '['sudo', '-u', 'ruser', 'sshpass', '-p', 'Secret123', 'ssh', '-v', '-o', 'StrictHostKeyChecking=no', 'tuser1@master.ipa.test', 'cat /etc/hosts']' returned non-zero exit status 5.
Furthermore, the logs show
debug1: SSH2_MSG_SERVICE_ACCEPT received debug1: Authentications that can continue: publickey,gssapi-keyex,gssapi-with-mic,password,keyboard-interactive debug1: Next authentication method: gssapi-with-mic debug1: Unspecified GSS failure. Minor code may provide more information No Kerberos credentials available (default cache: KCM:) debug1: Unspecified GSS failure. Minor code may provide more information No Kerberos credentials available (default cache: KCM:) debug1: Next authentication method: publickey debug1: Trying private key: /home/ruser/.ssh/id_rsa debug1: Trying private key: /home/ruser/.ssh/id_dsa debug1: Trying private key: /home/ruser/.ssh/id_ecdsa debug1: Trying private key: /home/ruser/.ssh/id_ecdsa_sk debug1: Trying private key: /home/ruser/.ssh/id_ed25519 debug1: Trying private key: /home/ruser/.ssh/id_ed25519_sk debug1: Trying private key: /home/ruser/.ssh/id_xmss debug1: Next authentication method: keyboard-interactive
AVC log shows several denials for rpcbind and renew_ca_cert.
rpcbind
renew_ca_cert
Full logs
The test scenario is the following: - on the server, create ruser with --shell /sbin/nologin and create tuser1 - on the client, perform kinit tuser1 and reset password - on the client, perform kinit ruser and reset password - on the client, perform kdestroy -A - on the client, perform sudo -u ruser sshpass -p password ssh tuser@server.ipa.test cat /etc/hosts
kinit tuser1
kinit ruser
kdestroy -A
sudo -u ruser sshpass -p password ssh tuser@server.ipa.test cat /etc/hosts
In the latest failing run (report), we can see that the kinit tuser1 does not prompt Your password has expired but warns that password will soon expire (but correctly prompts for ruser):
Your password has expired
INFO ipatests.pytest_ipa.integration.host.Host.client0.IPAOpenSSHTransport:transport.py:391 RUN ['kinit', 'tuser1'] DEBUG ipatests.pytest_ipa.integration.host.Host.client0.cmd217:transport.py:513 RUN ['kinit', 'tuser1'] DEBUG ipatests.pytest_ipa.integration.host.Host.client0.cmd217:transport.py:557 Password for tuser1@IPA.TEST: DEBUG ipatests.pytest_ipa.integration.host.Host.client0.cmd217:transport.py:557 Warning: Your password will expire in less than one hour on Fri 02 Apr 2021 05:07:15 PM UTC DEBUG ipatests.pytest_ipa.integration.host.Host.client0.cmd217:transport.py:217 Exit code: 0 INFO ipatests.pytest_ipa.integration.host.Host.client0.IPAOpenSSHTransport:transport.py:391 RUN ['kinit', 'ruser'] DEBUG ipatests.pytest_ipa.integration.host.Host.client0.cmd218:transport.py:513 RUN ['kinit', 'ruser'] DEBUG ipatests.pytest_ipa.integration.host.Host.client0.cmd218:transport.py:557 Password for ruser@IPA.TEST: DEBUG ipatests.pytest_ipa.integration.host.Host.client0.cmd218:transport.py:557 Password expired. You must change it now. DEBUG ipatests.pytest_ipa.integration.host.Host.client0.cmd218:transport.py:557 Enter new password: DEBUG ipatests.pytest_ipa.integration.host.Host.client0.cmd218:transport.py:557 Enter it again: DEBUG ipatests.pytest_ipa.integration.host.Host.client0.cmd218:transport.py:217 Exit code: 0
It looks like the client and server have a small time shift that could explain the issue. A possible fix would be to run kinit on the server instead. @rcritten do you have any other idea?
Failure observed in [testing_ipa-4.9_latest_selinux] Nightly PR #821 , logs
@frenaud yes, running kinit on the server may help. I'll create a PR.
Metadata Update from @rcritten: - Issue assigned to rcritten
https://github.com/freeipa/freeipa/pull/5767
master:
ipa-4-9:
Metadata Update from @frenaud: - Issue close_status updated to: fixed - Issue status updated to: Closed (was: Open)