Clone Function Called with each Authentication Request

David D dave at voicenotice.com
Fri Oct 10 08:08:25 CEST 2008


Hi,

I'm testing an Authentication script and it's working great.

I need to optimize the performance and move some data stored in files into
memory.
To accomplish this, we planned on placing the routine to read the data into
memory in the clone 
function, so it would load once.  
 
>From reading the documentation and the posts I could find.  
It's my understanding that the CLONE function will only be called once for
each new thread created.

In my testing I've noticed that the CLONE function get's called for each
Authentication request, so it appears
the thread is initialized for each call, even though I see it load up all 32
threads when radiusd initializes.

The debug output shows all 32 threads calling the clone function and then it
shows the clone function called again
when an authentication request comes in.

Any ideas on what I could check or change?

VERSION:
radius0-dev:/etc/raddb # radiusd -v
radiusd: FreeRADIUS Version 1.1.3, for host x86_64-unknown-linux-gnu, built
on May  8 2007 at 19:12:20
Copyright (C) 2000-2006 The FreeRADIUS server project.
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
PARTICULAR PURPOSE.
You may redistribute copies of FreeRADIUS under the terms of the
GNU General Public License.
For more information about these matte

PERL THREAD INFO:
perl -V | grep  thread
    osname=linux, osvers=2.6.18, archname=x86_64-linux-thread-multi
    config_args='-ds -e -Dprefix=/usr -Dvendorprefix=/usr
-Dinstallusrbinperl -Dusethreads -Di_db -Di_dbm -Di_ndbm -Di_gdbm
-Duseshrplib=true -Doptimize=-O2 -fmessage-length=0 -Wall
-D_FORTIFY_SOURCE=2 -g -Wall -pipe'
    usethreads=define use5005threads=undef useithreads=define
usemultiplicity=define
    libs=-lm -ldl -lcrypt -lpthread
    perllibs=-lm -ldl -lcrypt -lpthread
    dlsrc=dl_dlopen.xs, dlext=so, d_dlsymun=undef, ccdlflags='-Wl,-E
-Wl,-rpath,/usr/lib/perl5/5.8.8/x86_64-linux-thread-multi/CORE'
    /usr/lib/perl5/5.8.8/x86_64-linux-thread-multi
    /usr/lib/perl5/site_perl/5.8.8/x86_64-linux-thread-multi
    /usr/lib/perl5/vendor_perl/5.8.8/x86_64-linux-thread-multi
radius0-dev:~ #                               

RADIUSD -X LOADING 

radiusd -X
Starting - reading configuration files ...
reread_config:  reading radiusd.conf
Config:   including file: /etc/raddb/clients.conf
Config:   including file: /etc/raddb/clients.conf-db000
Config:   including file: /etc/raddb/clients.conf-db001
Config:   including file: /etc/raddb/clients.conf-db002
Config:   including file: /etc/raddb/clients.conf-db003
Config:   including file: /etc/raddb/clients.conf-db004
Config:   including file: /etc/raddb/clients.conf-db005
Config:   including file: /etc/raddb/clients.conf-db006
Config:   including file: /etc/raddb/clients.conf-db007
Config:   including file: /etc/raddb/clients.conf-db008
Config:   including file: /etc/raddb/clients.conf-db009
Config:   including file: /etc/raddb/clients.conf-db010
Config:   including file: /etc/raddb/clients.conf-db011
Config:   including file: /etc/raddb/clients.conf-db012
Config:   including file: /etc/raddb/clients.conf-db013
Config:   including file: /etc/raddb/clients.conf-db014
Config:   including file: /etc/raddb/clients.conf-db015
Config:   including file: /etc/raddb/clients.conf-db016
Config:   including file: /etc/raddb/clients.conf-db017
Config:   including file: /etc/raddb/clients.conf-db018
Config:   including file: /etc/raddb/clients.conf-db019
Config:   including file: /etc/raddb/clients.conf-db020
Config:   including file: /etc/raddb/clients.conf-db021
Config:   including file: /etc/raddb/clients.conf-db022
Config:   including file: /etc/raddb/clients.conf-db023
Config:   including file: /etc/raddb/clients.conf-db024
Config:   including file: /etc/raddb/clients.conf-db025
Config:   including file: /etc/raddb/clients.conf-db026
Config:   including file: /etc/raddb/clients.conf-db027
Config:   including file: /etc/raddb/clients.conf-db028
Config:   including file: /etc/raddb/clients.conf-db029
Config:   including file: /etc/raddb/clients.conf-db030
Config:   including file: /etc/raddb/clients.conf-db031
Config:   including file: /etc/raddb/clients.conf-db032
 main: prefix = "/"
 main: localstatedir = "/var"
 main: logdir = "/var/log"
 main: libdir = "/usr/lib/freeradius"
 main: radacctdir = "/var/log/radius/radacct"
 main: hostname_lookups = no
 main: max_request_time = 15
 main: cleanup_delay = 5
 main: max_requests = 453000
 main: delete_blocked_requests = 0
 main: port = 0
 main: allow_core_dumps = no
 main: log_stripped_names = no
 main: log_file = "/var/log/radius/radius.log"
 main: log_auth = no
 main: log_auth_badpass = no
 main: log_auth_goodpass = no
 main: pidfile = "/var/run/radiusd/radiusd.pid"
 main: user = "radiusd"
 main: group = "radiusd"
 main: usercollide = no
 main: lower_user = "no"
 main: lower_pass = "no"
 main: nospace_user = "no"
 main: nospace_pass = "no"
 main: checkrad = "/usr/sbin/checkrad"
 main: proxy_requests = no
 security: max_attributes = 200
 security: reject_delay = 1
 security: status_server = no
 main: debug_level = 0
read_config_files:  reading dictionary
read_config_files:  reading naslist
read_config_files:  reading clients
read_config_files:  reading realms
radiusd:  entering modules setup
Module: Library search path is /usr/lib/freeradius
Module: Loaded perl
 perl: module = "/etc/raddb/autocutoffv4.pl"
 perl: func_authorize = "authorize"
 perl: func_authenticate = "authenticate"
 perl: func_accounting = "accounting"
 perl: func_preacct = "preacct"
 perl: func_checksimul = "checksimul"
 perl: func_detach = "detach"
 perl: func_xlat = "xlat"
 perl: func_pre_proxy = "pre_proxy"
 perl: func_post_proxy = "post_proxy"
 perl: func_post_auth = "post_auth"
 perl: perl_flags = "(null)"
 perl: func_start_accounting = "(null)"
 perl: func_stop_accounting = "(null)"
 perl: max_clones = 32
 perl: start_clones = 32
 perl: min_spare_clones = 0
 perl: max_spare_clones = 32
 perl: cleanup_delay = 5
 perl: max_request_per_clone = 0

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2

  IN CLONE FUNCTION 2
Module: Instantiated perl (perl)
Module: Loaded preprocess
 preprocess: huntgroups = "/etc/raddb/huntgroups"
 preprocess: hints = "/etc/raddb/hints"
 preprocess: with_ascend_hack = no
 preprocess: ascend_channels_per_line = 23
 preprocess: with_ntdomain_hack = no
 preprocess: with_specialix_jetstream_hack = no
 preprocess: with_cisco_vsa_hack = no
 preprocess: with_alvarion_vsa_hack = no
Module: Instantiated preprocess (preprocess)
Module: Loaded realm
 realm: format = "suffix"
 realm: delimiter = "@"
 realm: ignore_default = no
 realm: ignore_null = no
Module: Instantiated realm (suffix)
Module: Loaded files
 files: usersfile = "/etc/raddb/users"
 files: acctusersfile = "/etc/raddb/acct_users"
 files: preproxy_usersfile = "/etc/raddb/preproxy_users"
 files: compat = "no"
Module: Instantiated files (files)
Module: Loaded detail
 detail: detailfile = "/var/log/radius/radacct/%{Client-IP-Address}/detail"
 detail: detailperm = 416
 detail: dirperm = 493
 detail: locking = no
Module: Instantiated detail (detail)
Listening on authentication *:1812
Listening on accounting *:1813
Ready to process requests.
rad_recv: Access-Request packet from host 198.144.213.39:21646, id=113,
length=95
        User-Name = "74.167.228.5"
        User-Password = "cisco"
        Cisco-AVPair = "h323-ivr-out=transactionID:55"
        NAS-IP-Address = 197.144.217.39
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 0
  modcall[authorize]: module "preprocess" returns ok for request 0
    rlm_realm: No '@' in User-Name = "74.167.228.5", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 0
    users: Matched entry DEFAULT at line 156
  modcall[authorize]: module "files" returns ok for request 0
modcall: leaving group authorize (returns ok) for request 0
  rad_check_password:  Found Auth-Type Perl
auth: type "Perl"
  Processing the authenticate section of radiusd.conf
modcall: entering group Perl for request 0
perl_pool: item 0x555555922ad0 asigned new request. Handled so far: 1
found interpetator at address 0x555555922ad0
rlm_perl: RAD_REQUEST: Client-IP-Address = 197.144.217.39
rlm_perl: RAD_REQUEST: Cisco-AVPair = h323-ivr-out=transactionID:55
rlm_perl: RAD_REQUEST: User-Name = 74.167.228.5
rlm_perl: RAD_REQUEST: User-Password = cisco
rlm_perl: RAD_REQUEST: NAS-IP-Address = 197.144.217.39
  IN CLONE FUNCTION 2    <==================CALLED AGAIN ON AUTHENTICATION
REQUEST
 In Authenticate
 In Authenticate 4
 In Authenticate
 

rlm_perl: Added pair Auth-Type = Perl
perl_pool total/active/spare [32/0/32]
Unreserve perl at address 0x555555922ad0
  modcall[authenticate]: module "perl" returns reject for request 0
modcall: leaving group Perl (returns reject) for request 0
auth: Failed to validate the user.
Delaying request 0 for 1 seconds
Finished request 0
Going to the next request
--- Walking the entire request list ---
Waking up in 1 seconds...
--- Walking the entire request list ---
Waking up in 1 seconds...
--- Walking the entire request list ---
Sending Access-Reject of id 113 to 198.144.213.39 port 21646
Waking up in 4 seconds...
rad_recv: Accounting-Request packet from host 198.144.213.39:21646, id=114,
length=888
        Acct-Session-Id = "000000A7"
        Calling-Station-Id = "david"
        Called-Station-Id = "11"
        Cisco-AVPair = "call-id=bd06bf19b46a803a at RFNUZWxlY29t"
        Cisco-AVPair = "iphop=count:1"
        Cisco-AVPair = "iphop=hop1:74.167.228.5"
        h323-setup-time = "h323-setup-time=05:58:35.039 UTC Fri Oct 10 2008"
        h323-gw-id = "h323-gw-id=cisco2691-0."
        h323-conf-id = "h323-conf-id=4F2CF580 95C711DD 8070BD8A E0E2182D"
        h323-call-origin = "h323-call-origin=answer"
        h323-call-type = "h323-call-type=VoIP"
        Cisco-AVPair = "h323-incoming-conf-id=4F2CF580 95C711DD 8070BD8A
E0E2182D"
        Cisco-AVPair = "subscriber=Unknown"
        Cisco-AVPair = "session-protocol=sipv2"
        Cisco-AVPair = "gw-rxd-cdn=ton:0,npi:0,#:11"
        Acct-Input-Octets = 0
        Acct-Output-Octets = 0
        Acct-Input-Packets = 0
        Acct-Output-Packets = 0
        Acct-Session-Time = 0
        h323-connect-time = "h323-connect-time=05:58:37.172 UTC Fri Oct 10
2008"
        h323-disconnect-time = "h323-disconnect-time=05:58:37.172 UTC Fri
Oct 10 2008"
        h323-disconnect-cause = "h323-disconnect-cause=39"
        h323-remote-address = "h323-remote-address=74.167.228.5"
        Cisco-AVPair = "release-source=7"
        h323-voice-quality = "h323-voice-quality=0"
        Cisco-AVPair = "remote-media-address=74.167.228.5"
        Cisco-AVPair = "gw-rxd-cgn=ton:0,npi:0,pi:0,si:0,#:david"
        User-Name = "david"
        Acct-Status-Type = Stop
        Service-Type = Login-User
        NAS-IP-Address = 197.144.217.39
        Acct-Delay-Time = 0
  Processing the preacct section of radiusd.conf
modcall: entering group preacct for request 1
    rlm_realm: No '@' in User-Name = "david", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[preacct]: module "suffix" returns noop for request 1
  modcall[preacct]: module "files" returns noop for request 1
  modcall[preacct]: module "preprocess" returns noop for request 1
modcall: leaving group preacct (returns noop) for request 1
  Processing the accounting section of radiusd.conf
modcall: entering group accounting for request 1
radius_xlat:  '/var/log/radius/radacct/198.144.213.39/detail'
rlm_detail: /var/log/radius/radacct/%{Client-IP-Address}/detail expands to
/var/log/radius/radacct/197.144.217.39/detail
  modcall[accounting]: module "detail" returns ok for request 1
modcall: leaving group accounting (returns ok) for request 1
Sending Accounting-Response of id 114 to 197.144.217.39 port 21646
Finished request 1
Going to the next request
Waking up in 4 seconds...
--- Walking the entire request list ---
Cleaning up request 0 ID 113 with timestamp 48eeef0b
Waking up in 2 seconds...
--- Walking the entire request list ---
Cleaning up request 1 ID 114 with timestamp 48eeef0d
Nothing to do.  Sleeping until we see a request.


PERL SECTION OF RADIUSD.CONF

perl {
               #
               #  The Perl script to execute on authorize, authenticate,
               #  accounting, xlat, etc.  This is very similar to using
               #  'rlm_exec' module, but it is persistent, and therefore
               #  faster.
               #
               module = /etc/raddb/autocutoffv4.pl

               #
               #  The following hashes are given to the module and
               #  filled with value-pairs (Attribute names and values)
               #
               #  %RAD_CHECK           Read-only       Check items
               #  %RAD_REQUEST         Read-only       Attributes from the
request
               #  %RAD_REPLY           Read-write      Attributes for the
reply
               #
               #  The return codes from functions in the perl_script
               #  are passed directly back to the server.  These
               #  codes are defined in doc/configurable_failover,
               #  src/include/modules.h (RLM_MODULE_REJECT, etc),
               #  and are pre-defined in the 'example.pl' program
               #  which is included.
               #

               #
               #  List of functions in the module to call.
               #  Comment out and change if you want to use other
               #  function names than the defaults.
               #
               func_authenticate = authenticate
               #func_authorize = authorize
               #func_preacct = preacct
               #func_accounting = accounting
               #func_checksimul = checksimul
               #func_pre_proxy = pre_proxy
               #func_post_proxy = post_proxy
               #func_post_auth = post_auth
               #func_xlat = xlat
               #func_detach = detach

               #
               #  Comment out the following line if you whish
               #  to use seperate functions for Start and Stop
               #  accounting packets. In that case, the
               #  func_accounting function is not called.
               #
               #func_start_accounting = accounting_start
               #func_stop_accounting = accounting_stop

               #  Uncomment the following lines if your perl is
               #  compiled with ithreads support.
               #  the settings bellow are the default one.
               #
               max_clones = 32
               start_clones = 32
               min_spare_clones = 0
               max_spare_clones = 32
               cleanup_delay = 5
               max_request_per_clone = 0
       }



-- 
View this message in context: http://www.nabble.com/Clone-Function-Called-with-each-Authentication-Request-tp19912540p19912540.html
Sent from the FreeRadius - Dev mailing list archive at Nabble.com.




More information about the Freeradius-Devel mailing list