Remote Execution fails after upgrading to Foreman version 3.7

avi8t · August 11, 2023, 6:52pm

Problem:
After upgrading to Foreman 3.7 -Katello 4.9 from Foreman 3.2 - Katello 4.4 , remote execution no longer works

Expected outcome:
Remote execution can log in with an SSH user, then su to the “Effective User” root and run a command, like “yum update -y”

Foreman and Proxy versions:
Foreman version 3.7
Katello 4.9
Foreman_Remote_Execution Plugin 10.0.5

Other relevant data:
Foreman server with Remote proxy: 10.XXX.XXX.13
Remote Server with a Foreman user called user1 and associated keys installed in .ssh:
10.XXX.XXX.199

Can run following command successfully from 10.XXX.XXX.13:
ssh -i ~user1-proxy/.ssh/id_rsa_user1_proxy user1@10.XXX.XXX.199 “su -l root -c "yum update"”

Have checked:
chmod u+s /sbin/unix_chkpwd (It was already correct)
Changed the root password on both sides for testing.
Checked pam su-l auth settings
Verified the mode is set to ssh in /etc/foreman-proxy/settings.d/remote_execution_ssh.ym

/etc/foreman-proxy/settings.d/remote_execution_ssh.yml on 10.XXX.XXX.13

---
:enabled: https
:ssh_identity_key_file: /var/lib/foreman-proxy/ssh/id_rsa_foreman_proxy
:local_working_dir: /var/tmp
:remote_working_dir: /var/foreman
:kerberos_auth: true

:cockpit_integration: true

# Whether to run remote execution jobs asynchronously
:mode: ssh

Failure logs

Aug 11 16:04:08 ip-10-XXX-XXX-199.ec2.internal sshd[31218]: Accepted key RSA SHA256:aTVkN7lHZMSl33DqY2y0TsXXXXXXoh1m/+E2EnWP2do found at /home/user1/.ssh/authorized_keys:1
Aug 11 16:04:08 ip-10-XXX-XXX-199.ec2.internal sshd[31218]: Postponed publickey for user1 from 10.XXX.XXX.13 port 45734 ssh2 [preauth]
Aug 11 16:04:08 ip-10-XXX-XXX-199.ec2.internal sshd[31218]: Accepted key RSA SHA256:aTVkN7lHZMSl33DqY2y0TsXXXXXXoh1m/+E2EnWP2do found at /home/user1/.ssh/authorized_keys:1
Aug 11 16:04:08 ip-10-XXX-XXX-199.ec2.internal sshd[31218]: Accepted publickey for user1 from 10.XXX.XXX.13 port 45734 ssh2: RSA SHA256:aTVkN7lHZMSl33DqY2y0TsXXXXXXoh1m/+E2EnWP2do
Aug 11 16:04:08 ip-10-XXX-XXX-199.ec2.internal sshd[31218]: pam_unix(sshd:session): session opened for user user1 by (uid=0)
Aug 11 16:04:08 ip-10-XXX-XXX-199.ec2.internal sshd[31218]: User child is on pid 31222
Aug 11 16:04:08 ip-10-XXX-XXX-199.ec2.internal sshd[31222]: Starting session: command for user1 from 10.XXX.XXX.13 port 45734 id 0
Aug 11 16:04:08 ip-10-XXX-XXX-199.ec2.internal sshd[31222]: Close session: user user1 from 10.XXX.XXX.13 port 45734 id 0
--Duplicate lines ommited--
Aug 11 16:04:08 ip-10-XXX-XXX-199.ec2.internal sshd[31222]: Starting session: command for user1 from 10.XXX.XXX.13 port 45734 id 0
Aug 11 16:04:08 ip-10-XXX-XXX-199.ec2.internal sshd[31222]: Close session: user user1 from 10.XXX.XXX.13 port 45734 id 0
Aug 11 16:04:08 ip-10-XXX-XXX-199.ec2.internal sshd[31222]: Starting session: command on pts/1 for user1 from 10.XXX.XXX.13 port 45734 id 0
Aug 11 16:04:08 ip-10-XXX-XXX-199.ec2.internal su[31339]: pam_unix(su-l:session): session opened for user root by user1(uid=1003)
Aug 11 16:04:08 ip-10-XXX-XXX-199.ec2.internal su[31339]: pam_unix(su-l:session): session closed for user root
Aug 11 16:04:08 ip-10-XXX-XXX-199.ec2.internal sshd[31222]: Close session: user user1 from 10.XXX.XXX.13 port 45734 id 0
Aug 11 16:04:08 ip-10-XXX-XXX-199.ec2.internal sshd[31222]: Starting session: command for user1 from 10.XXX.XXX.13 port 45734 id 0
Aug 11 16:04:08 ip-10-XXX-XXX-199.ec2.internal sshd[31222]: Close session: user user1 from 10.XXX.XXX.13 port 45734 id 0
--Duplicate lines ommited
Aug 11 16:04:09 ip-10-XXX-XXX-199.ec2.internal sshd[31222]: Close session: user user1 from 10.XXX.XXX.13 port 45734 id 0
Aug 11 16:04:09 ip-10-XXX-XXX-199.ec2.internal sshd[31222]: Starting session: command on pts/1 for user1 from 10.XXX.XXX.13 port 45734 id 0
Aug 11 16:04:09 ip-10-XXX-XXX-199.ec2.internal unix_chkpwd[31496]: password check failed for user (root)
Aug 11 16:04:09 ip-10-XXX-XXX-199.ec2.internal su[31494]: pam_unix(su-l:auth): authentication failure; logname= uid=1003 euid=0 tty= ruser=user1 rhost=  user=root
Aug 11 16:04:11 ip-10-XXX-XXX-199.ec2.internal systemd[31210]: pam_unix(systemd-user:session): session closed for user root
Aug 11 16:04:12 ip-10-XXX-XXX-199.ec2.internal sshd[31222]: Close session: user user1 from 10.XXX.XXX.13 port 45734 id 0
Aug 11 16:04:13 ip-10-XXX-XXX-199.ec2.internal sshd[31222]: Starting session: command for user1 from 10.XXX.XXX.13 port 45734 id 0
Aug 11 16:04:13 ip-10-XXX-XXX-199.ec2.internal sshd[31222]: Close session: user user1 from 10.XXX.XXX.13 port 45734 id 0
Aug 11 16:04:13 ip-10-XXX-XXX-199.ec2.internal sshd[31222]: Received disconnect from 10.XXX.XXX.13 port 45734:11: disconnected by user
Aug 11 16:04:13 ip-10-XXX-XXX-199.ec2.internal sshd[31222]: Disconnected from user user1 10.XXX.XXX.13 port 45734
Aug 11 16:04:13 ip-10-XXX-XXX-199.ec2.internal sshd[31218]: pam_unix(sshd:session): session closed for user user1

Manual Test:
10.XXX.XXX.13
** ssh -i ~user1-proxy/.ssh/id_rsa_user1_proxy user1@10.XXX.XXX.199 “su -l root -c "yum update"”**

and the logs on 10.XXX.XXX.199

Aug 11 15:50:48 ip-10-XXX-XXX-199.ec2.internal sshd[29676]: Connection from 10.XXX.XXX.13 port 42204 on 10.XXX.XXX.199 port 22
Aug 11 15:50:48 ip-10-XXX-XXX-199.ec2.internal sshd[29676]: Accepted key RSA SHA256:aTVkN7lHZMSl33DqY2y0TsXXXXXXoh1m/+E2EnWP2do found at /home/user1/.ssh/authorized_keys:1
Aug 11 15:50:48 ip-10-XXX-XXX-199.ec2.internal sshd[29676]: Postponed publickey for user1 from 10.XXX.XXX.13 port 42204 ssh2 [preauth]
Aug 11 15:50:48 ip-10-XXX-XXX-199.ec2.internal sshd[29676]: Accepted key RSA SHA256:aTVkN7lHZMSl33DqY2y0TsXXXXXXoh1m/+E2EnWP2do found at /home/user1/.ssh/authorized_keys:1
Aug 11 15:50:48 ip-10-XXX-XXX-199.ec2.internal sshd[29676]: Accepted publickey for user1 from 10.XXX.XXX.13 port 42204 ssh2: RSA SHA256:aTVkN7lHZMSl33DqY2y0TsXXXXXXoh1m/+E2EnWP2do
Aug 11 15:50:48 ip-10-XXX-XXX-199.ec2.internal sshd[29676]: pam_unix(sshd:session): session opened for user user1 by (uid=0)
Aug 11 15:50:48 ip-10-XXX-XXX-199.ec2.internal sshd[29676]: User child is on pid 29680
Aug 11 15:50:48 ip-10-XXX-XXX-199.ec2.internal sshd[29680]: Starting session: command for user1 from 10.XXX.XXX.13 port 42204 id 0
Aug 11 15:50:51 ip-10-XXX-XXX-199.ec2.internal su[29681]: pam_unix(su-l:session): session opened for user root by (uid=1003)
Aug 11 15:51:01 ip-10-XXX-XXX-199.ec2.internal systemd[29757]: pam_unix(systemd-user:session): session opened for user root by (uid=0)
Aug 11 15:51:04 ip-10-XXX-XXX-199.ec2.internal su[29681]: pam_unix(su-l:session): session closed for user root
Aug 11 15:51:04 ip-10-XXX-XXX-199.ec2.internal sshd[29680]: Received disconnect from 10.XXX.XXX.13 port 42204:11: disconnected by user
Aug 11 15:51:04 ip-10-XXX-XXX-199.ec2.internal sshd[29680]: Disconnected from user user1 10.XXX.XXX.13 port 42204
Aug 11 15:51:04 ip-10-XXX-XXX-199.ec2.internal sshd[29676]: pam_unix(sshd:session): session closed for user user1

aruzicka · August 14, 2023, 8:17am

How does the actual failure look like? What’s in the job output?

avi8t · August 14, 2023, 12:05pm

Hi,
Failure looks like an authentication error when su’ing to root.

Thanks.

aruzicka · August 15, 2023, 8:31am

Using su with password to change the user seems to be broken at the moment[1]. Would using sudo instead be an option for you?

[1] - Bug #36681: Changing effective user with password using su seems to be broken at the time - Foreman Remote Execution - Foreman

avi8t · August 15, 2023, 11:48am

Hi,

I’m not sure sudo will work for us at the moment but will look into it. I’m probably just going to fall back to our previous version and just monitor new releases for a bit.

Thanks for the help.