Page MenuHomeVyOS Platform

Radius SSH login displays "permission denied" on 1.4 rolling release
Closed, ResolvedPublicBUG

Description

The latest rolling release of VyOS 1.4 no longer permits SSH login from privileged radius users. Upon a successful radius response, the console outputs:

You are currently logged onto VyOS

/sbin/radius_shell: Permission denied

the SSH session immediately closes at that point. This is my configuration I have for radius:

set system login radius server xx.xx.xx.xx key 'myradiuskey'
set system login radius server xx.xx.xx.xx port '1812'
set system login radius server xx.xx.xx.xx timeout '2'
set system login radius source-address 'yy.yy.yy.yy'

My radius server shows a successful login attempt. When I downgrade to "1.4-rolling-202210020218", it works as expected.

Details

Difficulty level
Unknown (require assessment)
Version
1.4-rolling-202301190656
Why the issue appeared?
Will be filled on close
Is it a breaking change?
Unspecified (possibly destroys the router)
Issue type
Bug (incorrect behavior)

Event Timeline

Confirm.
Version: VyOS 1.4-rolling-202301200317

It is a problem with mapping user to radius_priv_user
This problem began after https://github.com/vyos/vyos-1x/commit/765f84386b6e94984ff79db2eab36d51f759159b#diff-0ab0ed71ce757261c4a6ae2f3a5bc441d6257d477bfb5435ae38f230777ff81cR51
If I set in sshd_config

PasswordAuthentication yes
ChallengeResponseAuthentication no

then authentication via radius works.
Else user maps to radius_user.

Some debugging, the authentication with user vyosunpriv

For 1.3

Feb 15 13:27:49 r1 sshd[3153]: Accepted password for vyosunpriv from 192.168.122.1 port 38352 ssh2
Feb 15 13:27:49 r1 sshd[3153]: pam_unix(sshd:session): session opened for user vyosunpriv by (uid=0)
Feb 15 13:27:49 r1 systemd-logind[718]: New session 18 of user radius_user.
Feb 15 13:27:49 r1 systemd[1]: Created slice User Slice of UID 1001.
Feb 15 13:27:49 r1 systemd[1]: Starting User Runtime Directory /run/user/1001...
Feb 15 13:27:49 r1 systemd[1]: Started User Runtime Directory /run/user/1001.
Feb 15 13:27:49 r1 systemd[1]: Starting User Manager for UID 1001...
Feb 15 13:27:49 r1 systemd[3156]: pam_unix(systemd-user:session): session opened for user vyosunpriv by (uid=0)
Feb 15 13:27:49 r1 systemd[3156]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Feb 15 13:27:49 r1 systemd[3156]: Reached target Timers.
Feb 15 13:27:49 r1 systemd[3156]: Listening on GnuPG cryptographic agent and passphrase cache.
Feb 15 13:27:49 r1 systemd[3156]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Feb 15 13:27:49 r1 systemd[3156]: Listening on Podman API Socket.
Feb 15 13:27:49 r1 systemd[3156]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Feb 15 13:27:49 r1 systemd[3156]: Listening on GnuPG network certificate management daemon.
Feb 15 13:27:49 r1 systemd[3156]: Reached target Sockets.
Feb 15 13:27:49 r1 systemd[3156]: Reached target Paths.
Feb 15 13:27:49 r1 systemd[3156]: Reached target Basic System.
Feb 15 13:27:49 r1 systemd[1]: Started User Manager for UID 1001.
Feb 15 13:27:49 r1 systemd[1]: Started Session 18 of user radius_user.
Feb 15 13:27:49 r1 systemd[3156]: Reached target Default.
Feb 15 13:27:49 r1 systemd[3156]: Startup finished in 23ms.
Feb 15 13:27:49 r1 systemd[3156]: opt-vyatta-config-tmp-new_config_3168.mount: Succeeded.
Feb 15 13:27:49 r1 systemd[1880]: opt-vyatta-config-tmp-new_config_3168.mount: Succeeded.
Feb 15 13:27:49 r1 systemd[1]: opt-vyatta-config-tmp-new_config_3168.mount: Succeeded.

In 1.4

Feb 15 13:23:41 r14 sshd[2527]: Accepted keyboard-interactive/pam for vyosunpriv from 192.168.122.1 port 39712 ssh2
Feb 15 13:23:41 r14 sshd[2527]: session file /run/mapuser/8 PID=2529 no longer active, removed
Feb 15 13:23:41 r14 sshd[2527]: pam_unix(sshd:session): session opened for user vyosunpriv(uid=1000) by (uid=0)
Feb 15 13:23:41 r14 systemd[1]: Created slice User Slice of UID 1000.
Feb 15 13:23:41 r14 systemd[1]: Starting User Runtime Directory /run/user/1000...
Feb 15 13:23:41 r14 systemd-logind[945]: New session 9 of user radius_user.
Feb 15 13:23:41 r14 systemd[1]: Finished User Runtime Directory /run/user/1000.
Feb 15 13:23:41 r14 systemd[1]: Starting User Manager for UID 1000...
Feb 15 13:23:41 r14 systemd[2531]: pam_unix(systemd-user:session): session opened for user radius_user(uid=1000) by (uid=0)
Feb 15 13:23:41 r14 systemd[2531]: Queued start job for default target Main User Target.
Feb 15 13:23:41 r14 systemd[2531]: Created slice User Application Slice.
Feb 15 13:23:41 r14 systemd[2531]: Reached target Paths.
Feb 15 13:23:41 r14 systemd[2531]: Reached target Timers.
Feb 15 13:23:41 r14 systemd[2531]: Listening on GnuPG network certificate management daemon.
Feb 15 13:23:41 r14 systemd[2531]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Feb 15 13:23:41 r14 systemd[2531]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Feb 15 13:23:41 r14 systemd[2531]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Feb 15 13:23:41 r14 systemd[2531]: Listening on GnuPG cryptographic agent and passphrase cache.
Feb 15 13:23:41 r14 systemd[2531]: Reached target Sockets.
Feb 15 13:23:41 r14 systemd[2531]: Reached target Basic System.
Feb 15 13:23:41 r14 systemd[2531]: Reached target Main User Target.
Feb 15 13:23:41 r14 systemd[2531]: Startup finished in 73ms.
Feb 15 13:23:41 r14 systemd[1]: Started User Manager for UID 1000.
Feb 15 13:23:41 r14 systemd[1]: Started Session 9 of user radius_user.
Feb 15 13:23:41 r14 systemd[2020]: opt-vyatta-config-tmp-new_config_2547.mount: Succeeded.
Feb 15 13:23:41 r14 systemd[1]: opt-vyatta-config-tmp-new_config_2547.mount: Succeeded.
Feb 15 13:23:41 r14 systemd[2531]: opt-vyatta-config-tmp-new_config_2547.mount: Succeeded.
Feb 15 13:23:41 r14 sshd[2610]: Received disconnect from 192.168.122.1 port 39712:11: disconnected by user
Feb 15 13:23:41 r14 sshd[2610]: Disconnected from user vyosunpriv 192.168.122.1 port 39712
Feb 15 13:23:41 r14 sshd[2527]: pam_unix(sshd:session): session closed for user vyosunpriv
Feb 15 13:23:41 r14 systemd[1]: session-9.scope: Succeeded.
Feb 15 13:23:41 r14 systemd-logind[945]: Session 9 logged out. Waiting for processes to exit.
Feb 15 13:23:41 r14 systemd-logind[945]: Removed session 9.
^C
vyos@r14:~$

So there are 2 pam_unix(sessions) "sshd" and "systemd"
All work fine in 1.3 when in both sessions user vyosunpriv

Feb 15 13:27:49 r1 sshd[3153]: pam_unix(sshd:session): session opened for user vyosunpriv by (uid=0)
Feb 15 13:27:49 r1 systemd[3156]: pam_unix(systemd-user:session): session opened for user vyosunpriv by (uid=0)

In 1.4 they are different, one for user vyosunpriv and the second for user radius_user

Feb 15 13:23:41 r14 sshd[2527]: pam_unix(sshd:session): session opened for user vyosunpriv(uid=1000) by (uid=0)
Feb 15 13:23:41 r14 systemd[2531]: pam_unix(systemd-user:session): session opened for user radius_user(uid=1000) by (uid=0)

In this case, it cannot connect to the VyOS

Also we can see it in RADIUS acct log 2 requests from the user vyosunpriv
for 1.3, where all works

Wed Feb 15 13:41:48 2023
	User-Name = "vyosunpriv"
	NAS-IP-Address = 127.0.1.1
	NAS-Identifier = "sshd"
	NAS-Port = 3340
	NAS-Port-Type = Virtual
	Acct-Status-Type = Start
	Acct-Session-Id = "00003340"
	Acct-Authentic = RADIUS
	Calling-Station-Id = "192.168.122.1"
	Event-Timestamp = "Feb 15 2023 13:41:48 UTC"
	Tmp-String-9 = "ai:"
	Acct-Unique-Session-Id = "50ec34967a1e26bcd155fed2462dc35b"
	Timestamp = 1676468508

Wed Feb 15 13:41:48 2023
	User-Name = "vyosunpriv"
	NAS-IP-Address = 127.0.1.1
	NAS-Identifier = "systemd-user"
	NAS-Port = 3345
	NAS-Port-Type = Virtual
	Acct-Status-Type = Start
	Acct-Session-Id = "00003345"
	Acct-Authentic = RADIUS
	Event-Timestamp = "Feb 15 2023 13:41:48 UTC"
	Tmp-String-9 = "ai:"
	Acct-Unique-Session-Id = "11da9c3f82ba3e4bb1322952147046e5"
	Timestamp = 1676468508

For 1.4 one request from vyosunpriv and another from radius_user

Wed Feb 15 13:43:18 2023
	User-Name = "vyosunpriv"
	NAS-IP-Address = 127.0.1.1
	NAS-Identifier = "sshd"
	NAS-Port = 4387
	NAS-Port-Type = Virtual
	Acct-Status-Type = Start
	Acct-Session-Id = "00004387"
	Acct-Authentic = RADIUS
	Calling-Station-Id = "192.168.122.1"
	Event-Timestamp = "Feb 15 2023 13:43:18 UTC"
	Tmp-String-9 = "ai:"
	Acct-Unique-Session-Id = "0fb0c8d360347a8a3da95f702bf275cb"
	Timestamp = 1676468598

Wed Feb 15 13:43:18 2023
	User-Name = "radius_user"
	NAS-IP-Address = 127.0.1.1
	NAS-Identifier = "systemd-user"
	NAS-Port = 4391
	NAS-Port-Type = Virtual
	Acct-Status-Type = Start
	Acct-Session-Id = "00004391"
	Acct-Authentic = RADIUS
	Event-Timestamp = "Feb 15 2023 13:43:18 UTC"
	Tmp-String-9 = "ai:"
	Acct-Unique-Session-Id = "752ebf3085023933146dc714f90fa963"
	Timestamp = 1676468598

Not sure is it a root case, but it different

zsdc changed the task status from Open to In progress.Feb 24 2023, 9:49 AM
zsdc claimed this task.
Viacheslav changed the task status from In progress to Needs testing.Feb 25 2023, 5:30 AM
Viacheslav triaged this task as High priority.

Hello - I upgraded to the latest rolling release (1.4-rolling-202302250317), and it appears to be working. I am able to login with a radius account successfully. Thank you for your efforts! I see in you PR's above, the second link is to change the shell from "bash" to "vbash". It appears once I login with a radius privileged account, the shell continues to default to "bash":

kcooper@Test-VyOS:~$ echo $SHELL
/bin/bash

kcooper@Test-VyOS:~$ id kcooper
uid=1001(kcooper) gid=102(vyattacfg) groups=102(vyattacfg),4(adm),6(disk),27(sudo),30(dip),100(users),114(frrvty),115(frr)

Thank you for your help!

Ken

syncer lowered the priority of this task from High to Low.
syncer moved this task from Need Triage to Finished on the VyOS 1.4 Sagitta board.