Strange problems in large proxy setup

Kostas Zorbadelos kzorba at otenet.gr
Fri Feb 23 15:22:01 CET 2007


My greetings to the list.

We have deployed a large setup using freeradius 1.1.3 in a proxy
configuration in front of FUNK radius. During the day we have about
150.000 concurrent DSL users online. Our setup takes the
access-request from the NAS, checks whether the user has any other
active sessions and if he is allowed to have a session the request is
proxied to the FUNK server that performs the actual authentication. So
the setup is a classical proxy setup. This policy decision of whether
the user is allowed to have a session is taken by a module we have
developed for this purpose (we call it rlm_concurrency). We use the
ldap module to find the maximum allowed sessions for a user.
Our setup involves no accounting, just authentication/authorization.

-------        --------------            -------- 
| NAS | -----> | Freeradius |  <-------> | FUNK |
-------        --------------            -------- 


This is the actual config we have in our freeradius server:

authorize {
        preprocess
        # The following config instructs freeradius to stop processing
        # requests if it matches the user in the local users file
        files {
           ok = return
        }

        ldap
        concurrency
        suffix

}

Here is a debugging output from freeradius with this config:

============== Debugging output (radiusd -X) ====================== 

Nothing to do.  Sleeping until we see a request.
rad_recv: Access-Request packet from host 62.103.1.111:1645, id=4, length=127
        Framed-Protocol = PPP
        User-Name = "foouser"
        User-Password = "XXXXXX"
        Calling-Station-Id = "XXXXXXXXX"
        NAS-Port-Type = Async
        Connect-Info = "33600/31200 V34+/V42bis/LAPM"
        NAS-Port = 4115
        NAS-Port-Id = "Async2/2"
        Service-Type = Framed-User
        NAS-IP-Address = 62.103.1.111
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 9
  modcall[authorize]: module "preprocess" returns ok for request 9
  modcall[authorize]: module "files" returns notfound for request 9
rlm_ldap: - authorize
rlm_ldap: performing user authorization for foouser
radius_xlat:  '(&(uid=foouser)(radiusAccountStatus=activated))'
radius_xlat:  '...'
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in ou=..., with filter (&(uid=foouser)(radiusAccountStatus=activated))
rlm_ldap: looking for check items in directory...
rlm_ldap: Adding radiusMaxLogins as Simultaneous-Use, value 1 & op=21
rlm_ldap: looking for reply items in directory...
rlm_ldap: user foouser authorized to use remote access
rlm_ldap: ldap_release_conn: Release Id: 0
  modcall[authorize]: module "ldap" returns ok for request 9
rlm_concurrency: Found NAS-IP-Address: 62.103.1.111
rlm_concurrency: User: foouser, Max-Sessions found: 1
rlm_concurrency: Accepted User foouser. Active sessions: 0, Maximum allowed sessions: 1
  modcall[authorize]: module "concurrency" returns ok for request 9
    rlm_realm: No '@' in User-Name = "foouser", looking up realm NULL
    rlm_realm: Found realm "NULL"
    rlm_realm: Proxying request from user foouser to realm NULL
    rlm_realm: Adding Realm = "NULL"
    rlm_realm: Preparing to proxy authentication request to realm "NULL"
  modcall[authorize]: module "suffix" returns updated for request 9
modcall: leaving group authorize (returns updated) for request 9
Sending Access-Request of id 9 to YYYY port 1645
        Framed-Protocol = PPP
        User-Name = "foouser"
        User-Password = "XXXXXX"
        Calling-Station-Id = "XXXXXXXXXXXXXX"
        NAS-Port-Type = Async
        Connect-Info = "33600/31200 V34+/V42bis/LAPM"
        NAS-Port = 4115
        NAS-Port-Id = "Async2/2"
        Service-Type = Framed-User
        NAS-IP-Address = 62.103.1.111
        Proxy-State = 0x34
--- Walking the entire request list ---
Waking up in 0 seconds...
...
Waking up in 0 seconds...
rad_recv: Access-Accept packet from host YYYY, id=9, length=107
        Proxy-State = 0x34
        Class = 0x5342522d434c20444e3d22646570616b222041543d22323030222055533d22222053493d223630373737383736302200
        Filter-Id = "USER-FILTER-OUT.out"
        Framed-Protocol = PPP
        Service-Type = Framed-User
 authorize: Skipping authorize in post-proxy stage
  rad_check_password:  Found Auth-Type
  rad_check_password: Auth-Type = Accept, accepting the user
Login OK: [foouser] (from client KARP3845 port 4115 cli 2237021227)
Sending Access-Accept of id 4 to 62.103.1.111 port 1645
        Class = 0x5342522d434c20444e3d22646570616b222041543d22323030222055533d22222053493d223630373737383736302200
        Filter-Id = "USER-FILTER-OUT.out"
        Framed-Protocol = PPP
        Service-Type = Framed-User

============== End Debugging output (radiusd -X) ====================== 


We have noticed no problems with our module and also no problems
whatsoever in a low traffic testing environment. However we have observed
the following strange behaviour in our production setup with its high
volume of requests.  

In a normal authentication request, we get the following lines in
radius.log in case of succesfull authentication: 

Fri Feb 23 13:04:46 2007 : Info: rlm_concurrency: Accepted User kzorba. Active sessions: 0, Maximum allowed sessions: 2
Fri Feb 23 13:04:46 2007 : Auth: Login OK: [kzorba] (from client KARP3845 port 4099 cli 2103841077)

In case of user rejection in the FUNK server we get:

Fri Feb 23 13:04:46 2007 : Info: rlm_concurrency: Accepted User foouser. Active sessions: 0, Maximum allowed sessions: 1
 Fri Feb 23 00:22:39 2007 : Auth: Login incorrect (Home Server says so): [foouser] (from client ATHE10KI port 1128333394 cli atm 4)

In some cases though, freeradius seems to reject the user (and the FUNK
server makes no log in this scenario). We make successive access requests
lets say for user kzorba (with valid credentials). In most cases
everything works OK, but in some cases we get:


Fri Feb 23 13:04:14 2007 : Info: rlm_concurrency: Accepted User kzorba. Active sessions: 0, Maximum allowed sessions: 2
Fri Feb 23 13:04:14 2007 : Auth: Login incorrect: [kzorba] (from client KARP3845 port 4102 cli 2103841077)

The rejection does not seem to come from the home FUNK server. We have
run freeradius in debug mode in testing environment (output given
above) and everything 
seem to work fine with our configuration, however in our production
setup only with its high traffic we get these random failures. The
failures are frequent enough to be noticed by us and also our
customers that manage to access our network after a few failed attempts.

Here is our proxy.conf:

proxy server {

        synchronous = yes
        retry_delay = 0                    
        retry_count = 0

        dead_time = 30

        default_fallback = yes

        post_proxy_authorize = no

}

#######################################################################
#
#  Configuration for the proxy realms.

realm NULL {
        type            = radius
	...
        nostrip
}
#
#  This realm is for ALL OTHER requests.
#
realm DEFAULT {
        type            = radius
	...
        nostrip
}

Any suggestions/ideas are highly welcome. I will audit the server's
code to get a good idea of how it works but it will take me some time
(I know just enough to develop a module for now). If you need anything
that can trace the issue please let me know.


Thanks in advance,

Kostas





More information about the Freeradius-Users mailing list