Quantcast

pam_radius_auth delay

classic Classic list List threaded Threaded
8 messages Options
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

pam_radius_auth delay

Steve Phillips
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
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: pam_radius_auth delay

Alan Buxey
No debug output of the radiusd here.

alan

On 28 Apr 2017 7:36 am, "Steve Phillips" <[hidden email]> 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
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: pam_radius_auth delay

Matthew Newton
In reply to this post by Steve Phillips
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. <[hidden email]>

Systems Specialist, Infrastructure Services,
I.T. Services, University of Leicester, Leicester LE1 7RH, United Kingdom

For IT help contact helpdesk extn. 2253, <[hidden email]>
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: pam_radius_auth delay

Steve Phillips
In reply to this post by Alan Buxey
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=[hidden email] on behalf of [hidden email]> wrote:

    No debug output of the radiusd here.
   
    alan
   
    On 28 Apr 2017 7:36 am, "Steve Phillips" <[hidden email]> 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

-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

smime.p7s (7K) Download Attachment
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: pam_radius_auth delay

Steve Phillips
In reply to this post by Matthew Newton
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=[hidden email] on behalf of [hidden email]> 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. <[hidden email]>
   
    Systems Specialist, Infrastructure Services,
    I.T. Services, University of Leicester, Leicester LE1 7RH, United Kingdom
   
    For IT help contact helpdesk extn. 2253, <[hidden email]>
    -
    List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

smime.p7s (7K) Download Attachment
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: pam_radius_auth delay

Steve Phillips
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=[hidden email] on behalf of [hidden email]> 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=[hidden email] on behalf of [hidden email]> 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. <[hidden email]>
       
        Systems Specialist, Infrastructure Services,
        I.T. Services, University of Leicester, Leicester LE1 7RH, United Kingdom
       
        For IT help contact helpdesk extn. 2253, <[hidden email]>
        -
        List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
    -
    List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

smime.p7s (7K) Download Attachment
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: pam_radius_auth delay

Steve Phillips
In reply to this post by Matthew Newton
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=[hidden email] on behalf of [hidden email]> 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. <[hidden email]>
   
    Systems Specialist, Infrastructure Services,
    I.T. Services, University of Leicester, Leicester LE1 7RH, United Kingdom
   
    For IT help contact helpdesk extn. 2253, <[hidden email]>
    -
    List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

smime.p7s (7K) Download Attachment
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: pam_radius_auth delay

Matthew Newton-2
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
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Loading...