Hi There, I've just setup pam_radius_auth and it is working, however there seems to be a weird 20 second delay for no apparent reason between getting the password from the prompt and sending the authentication request to the RADIUS server. The version of pam_radius_auth is 1.4.0 obtained from the CentOS 7 EPEL repository I have entries for the RADIUS server in /etc/hosts but have tried both a hostname and an IP address in /etc/pam_radius.conf and the effect is the same. My sshd pam entries are set as follows -- begin snippet -- auth [success=ignore default=1] pam_succeed_if.so debug user ingroup radius auth required pam_radius_auth.so debug conf=/etc/pam_radius.conf auth required pam_sepermit.so auth substack password-auth auth include postlogin -- end -- The logs are as follows -- begin logs -- Apr 28 16:09:40 bastion sshd[9197]: pam_radius_auth: Got user name stevetest Apr 28 16:09:40 bastion sshd[9197]: pam_radius_auth: ignore last_pass, force_prompt set Apr 28 16:10:00 bastion sshd[9197]: pam_radius_auth: Sending RADIUS request code 1 Apr 28 16:10:00 bastion sshd[9197]: pam_radius_auth: DEBUG: getservbyname(radius, udp) returned 0x7f05695fa1c0. Apr 28 16:10:00 bastion sshd[9197]: pam_radius_auth: Got RADIUS response code 2 Apr 28 16:10:00 bastion sshd[9197]: pam_radius_auth: authentication succeeded -- end logs -- and the server entry is (less the lines starting with a #) # cat /etc/pam_radius.conf | egrep -v ^# auth1 somesecret 3 172.28.208.169:1812 somesecret 3 (If I comment auth1 out the effect is identical - a 20 second delay) The 20 seconds sounds like a timeout of some sort but I'm at a bit of a loss what this would be. Just wondering if anyone else has come across this? OS: CentOS 7.3.1611, minimal installation, patched to whatever the latest patch cluster was as of a week ago. Any ideas would be appreciated, Cheers, -- Steve.
No debug output of the radiusd here. alan On 28 Apr 2017 7:36 am, "Steve Phillips" <steve@focb.co.nz> wrote:
Hi There,
I've just setup pam_radius_auth and it is working, however there seems to be a weird 20 second delay for no apparent reason between getting the password from the prompt and sending the authentication request to the RADIUS server.
The version of pam_radius_auth is 1.4.0 obtained from the CentOS 7 EPEL repository
I have entries for the RADIUS server in /etc/hosts but have tried both a hostname and an IP address in /etc/pam_radius.conf and the effect is the same.
My sshd pam entries are set as follows
-- begin snippet -- auth [success=ignore default=1] pam_succeed_if.so debug user ingroup radius auth required pam_radius_auth.so debug conf=/etc/pam_radius.conf auth required pam_sepermit.so auth substack password-auth auth include postlogin -- end --
The logs are as follows
-- begin logs -- Apr 28 16:09:40 bastion sshd[9197]: pam_radius_auth: Got user name stevetest Apr 28 16:09:40 bastion sshd[9197]: pam_radius_auth: ignore last_pass, force_prompt set Apr 28 16:10:00 bastion sshd[9197]: pam_radius_auth: Sending RADIUS request code 1 Apr 28 16:10:00 bastion sshd[9197]: pam_radius_auth: DEBUG: getservbyname(radius, udp) returned 0x7f05695fa1c0. Apr 28 16:10:00 bastion sshd[9197]: pam_radius_auth: Got RADIUS response code 2 Apr 28 16:10:00 bastion sshd[9197]: pam_radius_auth: authentication succeeded -- end logs --
and the server entry is (less the lines starting with a #)
# cat /etc/pam_radius.conf | egrep -v ^# auth1 somesecret 3 172.28.208.169:1812 somesecret 3
(If I comment auth1 out the effect is identical - a 20 second delay)
The 20 seconds sounds like a timeout of some sort but I'm at a bit of a loss what this would be. Just wondering if anyone else has come across this?
OS: CentOS 7.3.1611, minimal installation, patched to whatever the latest patch cluster was as of a week ago.
Any ideas would be appreciated,
Cheers,
-- Steve.
- List info/subscribe/unsubscribe? See http://www.freeradius.org/ list/users.html
Hey Alan, That’s because the radius system is working fine. The question pertains around why there is a 20 second delay between the user typing the password in and the radius request being generated and put on the wire, not around the radius server receiving the packet and responding to it (less than a second) Cheers, -- Steve. On 28/04/2017, 5:27 PM, "Freeradius-Users on behalf of Alan Buxey" <freeradius-users-bounces+steve=focb.co.nz@lists.freeradius.org on behalf of alan.buxey@gmail.com> wrote: No debug output of the radiusd here. alan On 28 Apr 2017 7:36 am, "Steve Phillips" <steve@focb.co.nz> wrote: > Hi There, > > I've just setup pam_radius_auth and it is working, however there seems to > be a weird 20 second delay for no apparent reason between getting the > password from the prompt and sending the authentication request to the > RADIUS server. > > The version of pam_radius_auth is 1.4.0 obtained from the CentOS 7 EPEL > repository > > I have entries for the RADIUS server in /etc/hosts but have tried both a > hostname and an IP address in /etc/pam_radius.conf and the effect is the > same. > > My sshd pam entries are set as follows > > -- begin snippet -- > auth [success=ignore default=1] pam_succeed_if.so debug user ingroup radius > auth required pam_radius_auth.so debug conf=/etc/pam_radius.conf > auth required pam_sepermit.so > auth substack password-auth > auth include postlogin > -- end -- > > The logs are as follows > > -- begin logs -- > Apr 28 16:09:40 bastion sshd[9197]: pam_radius_auth: Got user name > stevetest > Apr 28 16:09:40 bastion sshd[9197]: pam_radius_auth: ignore last_pass, > force_prompt set > Apr 28 16:10:00 bastion sshd[9197]: pam_radius_auth: Sending RADIUS > request code 1 > Apr 28 16:10:00 bastion sshd[9197]: pam_radius_auth: DEBUG: > getservbyname(radius, udp) returned 0x7f05695fa1c0. > Apr 28 16:10:00 bastion sshd[9197]: pam_radius_auth: Got RADIUS response > code 2 > Apr 28 16:10:00 bastion sshd[9197]: pam_radius_auth: authentication > succeeded > -- end logs -- > > and the server entry is (less the lines starting with a #) > > # cat /etc/pam_radius.conf | egrep -v ^# > auth1 somesecret 3 > 172.28.208.169:1812 somesecret 3 > > (If I comment auth1 out the effect is identical - a 20 second delay) > > The 20 seconds sounds like a timeout of some sort but I'm at a bit of a > loss what this would be. Just wondering if anyone else has come across this? > > OS: CentOS 7.3.1611, minimal installation, patched to whatever the latest > patch cluster was as of a week ago. > > Any ideas would be appreciated, > > Cheers, > > -- > Steve. > > > - > List info/subscribe/unsubscribe? See http://www.freeradius.org/ > list/users.html - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Given that between these two log lines On Fri, Apr 28, 2017 at 04:35:21PM +1000, Steve Phillips wrote:
Apr 28 16:09:40 bastion sshd[9197]: pam_radius_auth: ignore last_pass, force_prompt set
<here>
Apr 28 16:10:00 bastion sshd[9197]: pam_radius_auth: Sending RADIUS request code 1
there is a call to add a RADIUS attribute with details of the remote host the user is connecting from, I would suspect that there is a missing reverse DNS entry for it. Matthew -- Matthew Newton, Ph.D. <mcn4@leicester.ac.uk> Systems Specialist, Infrastructure Services, I.T. Services, University of Leicester, Leicester LE1 7RH, United Kingdom For IT help contact helpdesk extn. 2253, <ithelp@le.ac.uk>
Hey Matthew, The delay happens if I use an IP address or a FQDN, and whether the FQDN is in the DNS system (of which there are two servers on the same subnet/switch) or if it is in my /etc/hosts file. This was one my original thoughts as well as generally delays like this are due to some form of timeout - but there doesn’t seem to be anything in the logs indicating a timeout. -- Steve. On 28/04/2017, 8:10 PM, "Freeradius-Users on behalf of Matthew Newton" <freeradius-users-bounces+steve=focb.co.nz@lists.freeradius.org on behalf of mcn4@leicester.ac.uk> wrote: Given that between these two log lines On Fri, Apr 28, 2017 at 04:35:21PM +1000, Steve Phillips wrote: > Apr 28 16:09:40 bastion sshd[9197]: pam_radius_auth: ignore last_pass, force_prompt set <here> > Apr 28 16:10:00 bastion sshd[9197]: pam_radius_auth: Sending RADIUS request code 1 there is a call to add a RADIUS attribute with details of the remote host the user is connecting from, I would suspect that there is a missing reverse DNS entry for it. Matthew -- Matthew Newton, Ph.D. <mcn4@leicester.ac.uk> Systems Specialist, Infrastructure Services, I.T. Services, University of Leicester, Leicester LE1 7RH, United Kingdom For IT help contact helpdesk extn. 2253, <ithelp@le.ac.uk> - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Ahh, wait - bad form replying to myself I know, but realise what you just mentioned was the host generating the query. I'll look into this and ensure there is a PTR entry, but I'm pretty sure there was. Of note though, surely the system would just use the 'hostname' to populate this rather than trying to do a PTR lookup? -- Steve. On 29/04/2017, 10:54 AM, "Freeradius-Users on behalf of Steve Phillips" <freeradius-users-bounces+steve=focb.co.nz@lists.freeradius.org on behalf of steve@focb.co.nz> wrote: Hey Matthew, The delay happens if I use an IP address or a FQDN, and whether the FQDN is in the DNS system (of which there are two servers on the same subnet/switch) or if it is in my /etc/hosts file. This was one my original thoughts as well as generally delays like this are due to some form of timeout - but there doesn’t seem to be anything in the logs indicating a timeout. -- Steve. On 28/04/2017, 8:10 PM, "Freeradius-Users on behalf of Matthew Newton" <freeradius-users-bounces+steve=focb.co.nz@lists.freeradius.org on behalf of mcn4@leicester.ac.uk> wrote: Given that between these two log lines On Fri, Apr 28, 2017 at 04:35:21PM +1000, Steve Phillips wrote: > Apr 28 16:09:40 bastion sshd[9197]: pam_radius_auth: ignore last_pass, force_prompt set <here> > Apr 28 16:10:00 bastion sshd[9197]: pam_radius_auth: Sending RADIUS request code 1 there is a call to add a RADIUS attribute with details of the remote host the user is connecting from, I would suspect that there is a missing reverse DNS entry for it. Matthew -- Matthew Newton, Ph.D. <mcn4@leicester.ac.uk> Systems Specialist, Infrastructure Services, I.T. Services, University of Leicester, Leicester LE1 7RH, United Kingdom For IT help contact helpdesk extn. 2253, <ithelp@le.ac.uk> - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Hey Matthew, You were right. There was a DNS lookup happening. All fixed and working swimmingly now. Thanks. -- Steve. On 28/04/2017, 8:10 PM, "Freeradius-Users on behalf of Matthew Newton" <freeradius-users-bounces+steve=focb.co.nz@lists.freeradius.org on behalf of mcn4@leicester.ac.uk> wrote: Given that between these two log lines On Fri, Apr 28, 2017 at 04:35:21PM +1000, Steve Phillips wrote: > Apr 28 16:09:40 bastion sshd[9197]: pam_radius_auth: ignore last_pass, force_prompt set <here> > Apr 28 16:10:00 bastion sshd[9197]: pam_radius_auth: Sending RADIUS request code 1 there is a call to add a RADIUS attribute with details of the remote host the user is connecting from, I would suspect that there is a missing reverse DNS entry for it. Matthew -- Matthew Newton, Ph.D. <mcn4@leicester.ac.uk> Systems Specialist, Infrastructure Services, I.T. Services, University of Leicester, Leicester LE1 7RH, United Kingdom For IT help contact helpdesk extn. 2253, <ithelp@le.ac.uk> - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
On Mon, May 01, 2017 at 11:28:02AM +1000, Steve Phillips wrote:
You were right. There was a DNS lookup happening. All fixed and working swimmingly now.
OK good; even without looking at the code I suspected as much. 20 second delay at login time is pretty much always a DNS lookup stuck somewhere. -- Matthew
participants (4)
-
Alan Buxey -
Matthew Newton -
Matthew Newton -
Steve Phillips