authentication request failed for SSH using freeradius server.
Hailun Tan
dearambermini at gmail.com
Mon Jun 25 09:14:22 CEST 2018
Hi,
I figured out why the server failed to respond..
I need to set "require-message-authenticator = no" for that particular
client IP address in the client.conf under /etc/freeradius on the server
side.
However, there are still heaps of other issues after this one was shot down.
Now it seems the password for the user cannot be passed to the radius
server correctly when ssh was executed.
After checking the /var/log/auth.log on the client machine, it has
following items (in bold face) which worries me:
Jun 25 16:23:15 dev-ldap-server sshd[25675]: pam_radius_auth: Got user name
micfox
Jun 25 16:23:15 dev-ldap-server sshd[25675]: pam_radius_auth: ignore
last_pass, force_prompt set
Jun 25 16:23:15 dev-ldap-server sshd[25672]: Postponed keyboard-interactive
for invalid user micfox from 127.0.0.1 port 37892 ssh2 [preauth]
Jun 25 16:23:19 dev-ldap-server sshd[25675]: pam_radius_auth: Sending
RADIUS request code 1
Jun 25 16:23:19 dev-ldap-server sshd[25675]: pam_radius_auth: DEBUG:
get_ipaddr(10.10.150.134) returned 0.
Jun 25 16:23:20 dev-ldap-server sshd[25675]: pam_radius_auth: Got RADIUS
response code 3
Jun 25 16:23:20 dev-ldap-server sshd[25675]: pam_radius_auth:
authentication failed
Jun 25 16:23:20 dev-ldap-server sshd[25675]: pam_radius_auth: Got user name
micfox
Jun 25 16:23:20 dev-ldap-server sshd[25675]: pam_radius_auth: ignore
last_pass, force_prompt set
*Jun 25 16:23:20 dev-ldap-server sshd[25675]: pam_radius_auth: Got password
#010#012#015INCOR*
Jun 25 16:23:20 dev-ldap-server sshd[25675]: pam_radius_auth: Sending
RADIUS request code 1
Jun 25 16:23:20 dev-ldap-server sshd[25675]: pam_radius_auth: DEBUG:
get_ipaddr(10.10.150.134) returned 0.
Jun 25 16:23:21 dev-ldap-server sshd[25675]: pam_radius_auth: Got RADIUS
response code 3
Jun 25 16:23:21 dev-ldap-server sshd[25675]: pam_radius_auth:
authentication failed
*"#010#012#015INCOR" *is definitely not the password the user "micfox" has
*.*
I run the freeradius in debug mode on the server side. As expected, the
authentication failed due to the incorrect password.
Ready to process requests.
rad_recv: Access-Request packet from host 10.10.150.136 port 52388, id=151,
length=91
User-Name = "micfox"
* User-Password = "\010\n\r\177INCOR"*
NAS-IP-Address = 10.10.150.136
NAS-Identifier = "sshd"
NAS-Port = 26140
NAS-Port-Type = Virtual
Service-Type = Authenticate-Only
Calling-Station-Id = "10.10.150.136"
# Executing section authorize from file /etc/freeradius/sites-enabled/
default
+group authorize {
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
++[digest] = noop
[suffix] No '@' in User-Name = "micfox", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] = noop
[eap] No EAP-Message, not doing EAP
++[eap] = noop
[sql] expand: %{User-Name} -> micfox
[sql] sql_set_user escaped user --> 'micfox'
rlm_sql (sql): Reserving sql socket id: 14
[sql] expand: SELECT id, username, attribute, value, op FROM
radcheck WHERE username = '%{SQL-User-Name}' ORDER BY
id -> SELECT id, username, attribute, value, op FROM
radcheck WHERE username = 'micfox' ORDER BY id
[sql] User found in radcheck table
[sql] expand: SELECT id, username, attribute, value, op FROM
radreply WHERE username = '%{SQL-User-Name}' ORDER BY
id -> SELECT id, username, attribute, value, op FROM
radreply WHERE username = 'micfox' ORDER BY id
[sql] expand: SELECT groupname FROM radusergroup
WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT
groupname FROM radusergroup WHERE username =
'micfox' ORDER BY priority
[sql] expand: SELECT id, groupname, attribute, Value,
op FROM radgroupcheck WHERE groupname =
'%{Sql-Group}' ORDER BY id -> SELECT id, groupname,
attribute, Value, op FROM radgroupcheck WHERE
groupname = 'test' ORDER BY id
[sql] User found in group test
[sql] expand: SELECT id, groupname, attribute, value,
op FROM radgroupreply WHERE groupname =
'%{Sql-Group}' ORDER BY id -> SELECT id, groupname,
attribute, value, op FROM radgroupreply WHERE
groupname = 'test' ORDER BY id
rlm_sql (sql): Released sql socket id: 14
++[sql] = ok
++[expiration] = noop
++[logintime] = noop
++[pap] = updated
+} # group authorize = updated
Found Auth-Type = PAP
# Executing group from file /etc/freeradius/sites-enabled/default
+group PAP {
*[pap] login attempt with password "? INCOR"*[pap] Using clear text
password "micfox001"
[pap] Passwords don't match
++[pap] = reject
+} # group PAP = reject
Failed to authenticate the user.
WARNING: Unprintable characters in the password. Double-check the shared
secret on the server and the NAS!
Using Post-Auth-Type Reject
# Executing group from file /etc/freeradius/sites-enabled/default
+group REJECT {
[sql] expand: %{User-Name} -> micfox
[sql] sql_set_user escaped user --> 'micfox'
[sql] expand: %{User-Password} -> =5C010=5Cn=5Cr=5C177INCOR
[sql] expand: INSERT INTO radpostauth
(username, pass, reply, authdate) VALUES
( '%{User-Name}',
'%{%{User-Password}:-%{Chap-Password}}',
'%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth
(username, pass, reply, authdate) VALUES
( 'micfox',
'=5C010=5Cn=5Cr=5C177INCOR', 'Access-Reject',
'2018-06-25 16:45:25')
rlm_sql (sql) in sql_postauth: query is INSERT INTO
radpostauth (username, pass, reply,
authdate) VALUES (
'micfox', '=5C010=5Cn=5Cr=5C177INCOR',
'Access-Reject', '2018-06-25 16:45:25')
rlm_sql (sql): Reserving sql socket id: 13
rlm_sql (sql): Released sql socket id: 13
++[sql] = ok
[eap] Request didn't contain an EAP-Message, not inserting EAP-Failure
++[eap] = noop
[attr_filter.access_reject] expand: %{User-Name} -> micfox
attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] = updated
+} # group REJECT = updated
Delaying reject of request 8 for 1 seconds
*=============*
I then check the code in pam_radius_auth.c for the shared library
paM_radius_auth.so. I wonder where the password was actually retrieved from
the conversation function of PAM session. That is the first question I
would like to ask.
However, it is not the end of the problems. I now edited the code in
pam_radius_auth.c to offer a hard-coded correct password for the user
,micfox (i.e., the correct password is "micfox001"). Then the user
authentication passes in both client and server side for this connection.
However, the user still cannot open the ssh session. On the client side,
the /var/user/auth.log shows the following error:
======================
Jun 25 16:45:29 dev-ldap-server sshd[26137]: pam_radius_auth: Got user name
micfox
Jun 25 16:45:29 dev-ldap-server sshd[26137]: pam_radius_auth: Sending
RADIUS request code 1
Jun 25 16:45:29 dev-ldap-server sshd[26137]: pam_radius_auth: DEBUG:
get_ipaddr(10.10.150.134) returned 0.
Jun 25 16:45:30 dev-ldap-server sshd[26137]: pam_radius_auth: Got RADIUS
response code 3
Jun 25 16:45:30 dev-ldap-server sshd[26137]: pam_radius_auth:
authentication failed
Jun 25 16:45:30 dev-ldap-server sshd[26137]: pam_radius_auth: Got user name
micfox
Jun 25 16:45:30 dev-ldap-server sshd[26137]: pam_radius_auth: ignore
last_pass, force_prompt set
Jun 25 16:45:30 dev-ldap-server sshd[26137]: pam_radius_auth: Got password
micfox001
Jun 25 16:45:30 dev-ldap-server sshd[26137]: pam_radius_auth: Sending
RADIUS request code 1
Jun 25 16:45:30 dev-ldap-server sshd[26137]: pam_radius_auth: DEBUG:
get_ipaddr(10.10.150.134) returned 0.
Jun 25 16:45:31 dev-ldap-server sshd[26137]: pam_radius_auth: Got RADIUS
response code 2
Jun 25 16:45:31 dev-ldap-server sshd[26137]: pam_radius_auth:
authentication succeeded
J*un 25 16:45:31 dev-ldap-server sshd[26137]: Failed password for invalid
user micfox from 10.10.150.136 port 33330 ssh2*
Jun 25 17:09:01 dev-ldap-server CRON[26274]: pam_unix(cron:session):
session opened for user root by (uid=0)
Jun 25 17:09:03 dev-ldap-server CRON[26274]: pam_unix(cron:session):
session closed for user root
================
I am totally lost for that bold-face message. even though the user
authentication passes, why is the "Failed password for invalid user" still
shows up???
Can ssh actually use pam_radius_auth.so for user authentication?? Please
advise how to fix it as I really do not have any clue now...
On Mon, Jun 25, 2018 at 2:56 PM, Hailun Tan <dearambermini at gmail.com> wrote:
> I am trying to perform the user authentication via freeradius server on
> the ssh conection.
>
> I have setup the free radius server according to the wiki pages:
>
> https://wiki.freeradius.org/guide/Getting-Started
>
>
> In addition, I managed to install the dolaradius to manage the free
> radius. I have run the radtest for the servers.
>
> The configurations for the radius server is:
> free radius server IP: 10.10.150.134
> free radius server port: 1812
> master secret: NOJA
> user name: micfox
> user password: micfox001
>
>
> On the client machine (client IP: 10.10.150.136), I run the following
> command:
>
> *dev-ldap-server: radtest micfox micfox001 10.10.150.134:1812
> <http://10.10.150.134:1812> 1812 NOJA*
> Sending Access-Request of id 5 to 10.10.150.134 port 1812
> User-Name = "micfox"
> User-Password = "micfox001"
> NAS-IP-Address = 10.10.150.136
> NAS-Port = 1812
> Message-Authenticator = 0x00000000000000000000000000000000
> rad_recv: Access-Accept packet from host 10.10.150.134 port 1812, id=5,
> length=38
> Service-Type = Framed-User
> Framed-Protocol = PPP
> Framed-Compression = Van-Jacobson-TCP-IP
>
> So it should prove the free radius server is up and running.
>
>
> However, I have configured to use the pam-freeradius-auth.so to hookup
> with the PAM modules on the client machine to authenticate the ssh user. it
> does not work. I have updated the /etc/pam.d/sshd as follows:
> ===========
>
>
> *auth sufficient pam_radius_auth.so debug skip_passwd*# PAM configuration
> for the Secure Shell service
>
> # Standard Un*x authentication.
> @include common-auth
>
> # Disallow non-root logins when /etc/nologin exists.
> account required pam_nologin.so
>
> # Uncomment and edit /etc/security/access.conf if you need to set complex
> # access limits that are hard to express in sshd_config.
> # account required pam_access.so
>
> # Standard Un*x authorization.
> @include common-account
>
> # SELinux needs to be the first session rule. This ensures that any
> # lingering context has been cleared. Without this it is possible that a
> # module could execute code in the wrong domain.
> session [success=ok ignore=ignore module_unknown=ignore
> default=bad] pam_selinux.so close
>
> # Set the loginuid process attribute.
> session required pam_loginuid.so
>
> # Create a new session keyring.
> session optional pam_keyinit.so force revoke
>
> # Standard Un*x session setup and teardown.
> @include common-session
>
> # Print the message of the day upon successful login.
> # This includes a dynamically generated part from /run/motd.dynamic
> # and a static (admin-editable) part from /etc/motd.
> session optional pam_motd.so motd=/run/motd.dynamic
> session optional pam_motd.so noupdate
>
> # Print the status of the user's mailbox upon successful login.
> session optional pam_mail.so standard noenv # [1]
>
> # Set up user limits from /etc/security/limits.conf.
> session required pam_limits.so
>
> # Read environment variables from /etc/environment and
> # /etc/security/pam_env.conf.
> session required pam_env.so # [1]
> # In Debian 4.0 (etch), locale-related environment variables were moved to
> # /etc/default/locale, so read that as well.
> session required pam_env.so user_readenv=1
> envfile=/etc/default/locale
>
> # SELinux needs to intervene at login time to ensure that the process
> starts
> # in the proper default security context. Only sessions which are intended
> # to run in the user's context should be run after this.
> session [success=ok ignore=ignore module_unknown=ignore
> default=bad] pam_selinux.so open
>
> # Standard Un*x password updating.
> @include common-password
>
>
> But now when I run the ssh micfox at 10.10.150.136 (freeradius client's iP).
> the /var/log/auth.log has the following error messages:
>
>
> Jun 25 12:05:51 dev-ldap-server sshd[6441]: pam_radius_auth: Got user name
> micfox
> Jun 25 12:05:51 dev-ldap-server sshd[6441]: pam_radius_auth: ignore
> last_pass, force_prompt set
> Jun 25 12:05:51 dev-ldap-server sshd[6441]: pam_radius_auth: Sending
> RADIUS request code 1
> Jun 25 12:05:51 dev-ldap-server sshd[6441]: pam_radius_auth: DEBUG:
> get_ipaddr(10.10.150.134) is available. (1812)
> Jun 25 12:05:51 dev-ldap-server sshd[6441]: pam_radius_auth: DEBUG:
> talk_radius(0x86960a0a) is available (1812,port).
> Jun 25 12:05:51 dev-ldap-server sshd[6441]: pam_radius_auth: DEBUG:
> waiting for response from radius server 10.10.150.134 with port 1812
> (master secret: NOJA).
> *Jun 25 12:05:54 dev-ldap-server sshd[6441]: pam_radius_auth: RADIUS
> server 10.10.150.134 failed to respond*
> Jun 25 12:05:54 dev-ldap-server sshd[6441]: pam_radius_auth: All RADIUS
> servers failed to respond.
> Jun 25 12:05:54 dev-ldap-server sshd[6441]: pam_radius_auth:
> authentication failed
> Jun 25 12:05:54 dev-ldap-server sshd[6438]: Postponed keyboard-interactive
> for invalid user micfox from 127.0.0.1 port 37362 ssh2 [preauth]
>
>
>
> The RADIUS server always failed to respond..
>
> I have configured the /etc/pam_radius_auth.conf as follows:
>
>
>
> # pam_radius_auth configuration file. Copy to: /etc/raddb/server
> #
> # For proper security, this file SHOULD have permissions 0600,
> # that is readable by root, and NO ONE else. If anyone other than
> # root can read this file, then they can spoof responses from the server!
> #
> # There are 3 fields per line in this file. There may be multiple
> # lines. Blank lines or lines beginning with '#' are treated as
> # comments, and are ignored. The fields are:
> #
> # server[:port] secret [timeout]
> #
> # the port name or number is optional. The default port name is
> # "radius", and is looked up from /etc/services The timeout field is
> # optional. The default timeout is 3 seconds.
> #
> # If multiple RADIUS server lines exist, they are tried in order. The
> # first server to return success or failure causes the module to return
> # success or failure. Only if a server fails to response is it skipped,
> # and the next server in turn is used.
> #
> # The timeout field controls how many seconds the module waits before
> # deciding that the server has failed to respond.
> #
> # server[:port] shared_secret timeout (s)
> *10.10.150.134:1831 <http://10.10.150.134:1831> NOJA 3*
> #other-server other-secret 3
>
> #
> # having localhost in your radius configuration is a Good Thing.
> #
> # See the INSTALL file for pam.conf hints.
>
>
> I believed I should have setup everything correctly?? why is the
> radius-pam-auth.so not working with the error message,
>
> * RADIUS server 10.10.150.134 failed to respond??*
> I have prolonged the timeout parameter from 3 seconds to 60 seconds but it
> did not work.
>
> If the radius server is not correctly set, it should not even pass the
> radtest before. But why there is no response from the radius server for
> freeradius-pam-auth.so if the server does work?? what could go wrong from
> the configurations on the pam-radius module?
>
> Please advise
>
More information about the Freeradius-Users
mailing list