Radius is running away with the CPU

Scott Lambert lambert at lambertfam.org
Tue Aug 14 06:21:19 CEST 2007


I am attempting to build a setup which authenticates users from 3 realms
in one MySQL database.  Some of my users, actually a large proportion of
them, are currently not using their realm to authenticate.  I am about
to merge the dial pools so I won't be able to use huntgroups or hints to
figure out which realm they are coming from.

I am trying to use the new unlang option to avoid writing an rlm_perl
type script.

FreeRADIUS-snapshot-20070813

I don't know if any of this is "legal".  I'm using one sql module.  I
just call it once for each realm after changing the %{User-Name} to
append that realm.  It just looked like it might work so I tried it.
The debug output makes it look like I am very close.  I haven't been
able to figure out exactly what is wrong with it, yet.

The failure happens in rlm_pap when the user does not specify a realm.
I don't see the cause of the failure in the debug output.  I'm probably
not interpreting the output correctly.

Here are the diffs to the default config coming from the snapshot.

--------------------------------------------------------------------
--- radiusd.conf-orig   Mon Aug 13 20:42:25 2007
+++ radiusd.conf        Mon Aug 13 21:15:41 2007
@@ -210,7 +210,7 @@
        #  Allowed values are:
        #       integer port number (1812)
        #       0 means "use /etc/services for the proper port"
-       port = 0
+       port = 1645
 
        #  Type of packets to listen for.
        #  Allowed values are:
@@ -252,7 +252,7 @@
 listen {
        ipaddr = *
 #      ipv6addr = ::
-       port = 0
+       port = 1646
        type = acct
 #      interface = eth0
 #      clients = per_socket_clients
@@ -1051,7 +1051,7 @@
                #
                # If you're not running a Cisco or Quintum NAS, you don't
                # need this hack.
-               with_cisco_vsa_hack = no
+               with_cisco_vsa_hack = yes
        }
 
        # Livingston-style 'users' file
@@ -1214,33 +1214,33 @@
        #
        #  See rlm_sql_log(5) manpage.
        #
-#      sql_log {
-#              path = ${radacctdir}/sql-relay
-#              acct_table = "radacct"
-#              postauth_table = "radpostauth"
-#
-#              Start = "INSERT INTO ${acct_table} (AcctSessionId, UserName, \
-#               NASIPAddress, FramedIPAddress, AcctStartTime, AcctStopTime, \
-#               AcctSessionTime, AcctTerminateCause) VALUES                 \
-#               ('%{Acct-Session-Id}', '%{User-Name}', '%{NAS-IP-Address}', \
-#               '%{Framed-IP-Address}', '%S', '0', '0', '');"
-#              Stop = "INSERT INTO ${acct_table} (AcctSessionId, UserName,  \
-#               NASIPAddress, FramedIPAddress, AcctStartTime, AcctStopTime, \
-#               AcctSessionTime, AcctTerminateCause) VALUES                 \
-#               ('%{Acct-Session-Id}', '%{User-Name}', '%{NAS-IP-Address}', \
-#               '%{Framed-IP-Address}', '0', '%S', '%{Acct-Session-Time}',  \
-#               '%{Acct-Terminate-Cause}');"
-#              Alive = "INSERT INTO ${acct_table} (AcctSessionId, UserName, \
-#               NASIPAddress, FramedIPAddress, AcctStartTime, AcctStopTime, \
-#               AcctSessionTime, AcctTerminateCause) VALUES                 \
-#               ('%{Acct-Session-Id}', '%{User-Name}', '%{NAS-IP-Address}', \
-#               '%{Framed-IP-Address}', '0', '0', '%{Acct-Session-Time}','');"
-#
-#              Post-Auth = "INSERT INTO ${postauth_table}                   \
-#               (user, pass, reply, date) VALUES                            \
-#               ('%{User-Name}', '%{User-Password:-Chap-Password}',         \
-#               '%{reply:Packet-Type}', '%S');"
-#      }
+       sql_log {
+               path = ${radacctdir}/sql-relay
+               acct_table = "radacct"
+               postauth_table = "radpostauth"
+
+               Start = "INSERT INTO ${acct_table} (AcctSessionId, UserName, \
+                NASIPAddress, FramedIPAddress, AcctStartTime, AcctStopTime, \
+                AcctSessionTime, AcctTerminateCause) VALUES                 \
+                ('%{Acct-Session-Id}', '%{User-Name}', '%{NAS-IP-Address}', \
+                '%{Framed-IP-Address}', '%S', '0', '0', '');"
+               Stop = "INSERT INTO ${acct_table} (AcctSessionId, UserName,  \
+                NASIPAddress, FramedIPAddress, AcctStartTime, AcctStopTime, \
+                AcctSessionTime, AcctTerminateCause) VALUES                 \
+                ('%{Acct-Session-Id}', '%{User-Name}', '%{NAS-IP-Address}', \
+                '%{Framed-IP-Address}', '0', '%S', '%{Acct-Session-Time}',  \
+                '%{Acct-Terminate-Cause}');"
+               Alive = "INSERT INTO ${acct_table} (AcctSessionId, UserName, \
+                NASIPAddress, FramedIPAddress, AcctStartTime, AcctStopTime, \
+                AcctSessionTime, AcctTerminateCause) VALUES                 \
+                ('%{Acct-Session-Id}', '%{User-Name}', '%{NAS-IP-Address}', \
+                '%{Framed-IP-Address}', '0', '0', '%{Acct-Session-Time}','');"
+
+               Post-Auth = "INSERT INTO ${postauth_table}                   \
+                (user, pass, reply, date) VALUES                            \
+                ('%{User-Name}', '%{User-Password:-Chap-Password}',         \
+                '%{reply:Packet-Type}', '%S');"
+       }
 
        #
        #  Create a unique accounting session Id.  Many NASes re-use

--- default-orig        Mon Aug 13 21:00:10 2007
+++ default     Tue Aug 14 03:30:23 2007
@@ -122,7 +122,56 @@
        #  is meant to mirror the "users" file.
        #
        #  See "Authorization Queries" in sql.conf
-#      sql
+        if ( "%{User-Name}" =~ /@/) {
+         sql
+       }
+       else {
+         update request {
+           Stripped-User-Name := "%{User-Name}"
+           User-Name := "%{User-Name}@example1.net"
+         }
+         sql {
+               fail = 1
+               notfound = 2
+               noop = return
+               ok = return
+               updated = return
+               reject = return
+               userlock = return
+               invalid = return
+               handled = return
+         }
+         update request {
+           User-Name := "%{Stripped-User-Name}@example2.com"
+         }
+         sql {
+               fail = 1
+               notfound = 2
+               noop = return
+               ok = return
+               updated = return
+               reject = return
+               userlock = return
+               invalid = return
+               handled = return
+         }
+         update request {
+           User-Name := "%{Stripped-User-Name}@example3.net"
+         }
+         sql {
+               fail = 1
+               notfound = 2
+               noop = return
+               ok = return
+               updated = return
+               reject = return
+               userlock = return
+               invalid = return
+               handled = return
+         }
+       }
+
+         
 
        #
        #  If you are using /etc/smbpasswd, and are also doing
@@ -312,7 +361,7 @@
        #  Log traffic to an SQL database.
        #
        #  See "Accounting queries" in sql.conf
-#      sql
+       sql
 
        #
        #  Instead of sending the query to the SQL server,
@@ -339,11 +388,11 @@
 #  or rlm_sql module can handle this.
 #  The rlm_sql module is *much* faster
 session {
-       radutmp
+#      radutmp
 
        #
        #  See "Simultaneous Use Checking Queries" in sql.conf
-#      sql
+       sql
 }
 
 
@@ -364,7 +413,7 @@
        #  After authenticating the user, do another SQL query.
        #
        #  See "Authentication Logging Queries" in sql.conf
-#      sql
+       sql
 
        #
        #  Instead of sending the query to the SQL server,

--------------------------------------------------------------------

Here are the authentication tests. 

lambert at sysmon ~
22:30:33 Mon Aug 13 $ radtest lambert at example3.net password1 radtest.example1.net 2 blahblah 2
Sending Access-Request of id 82 to radtest.example1.net port 1645
        User-Name = "lambert at example3.net"
        User-Password = "password1"
        NAS-IP-Address = 255.255.255.255
        NAS-Port = 2
        Framed-Protocol = PPP
rad_recv: Access-Accept packet from host radtest.example1.net:1645, id=82, length=32
        Framed-Protocol = PPP
        Framed-Compression = Van-Jacobson-TCP-IP

lambert at sysmon ~
22:33:43 Mon Aug 13 $ radtest lambert password1 radtest.example1.net 2 blahblah 2
Sending Access-Request of id 99 to radtest.example1.net port 1645
        User-Name = "lambert"
        User-Password = "password1"
        NAS-IP-Address = 255.255.255.255
        NAS-Port = 2
        Framed-Protocol = PPP
rad_recv: Access-Reject packet from host radtest.example1.net:1645, id=99, length=20

--------------------------------------------------------------------

And here is the output from "/usr/local/sbin/radiusd -X":

Script started on Tue Aug 14 03:33:25 2007


root at radtest.example1.net /usr/local/etc/raddb

03:33:25 Tue Aug 14 # /usr/local/sbin/radiusd -X
FreeRADIUS Version 2.0.0-pre2, for host i386-unknown-freebsd6.2, built on Aug 13 2007 at 19:41:31
Copyright (C) 2000-2007 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. 
Config:   including file: /usr/local/etc/raddb/radiusd.conf
Config:   including file: /usr/local/etc/raddb/proxy.conf
Config:   including file: /usr/local/etc/raddb/clients.conf
Config:   including file: /usr/local/etc/raddb/snmp.conf
Config:   including file: /usr/local/etc/raddb/eap.conf
Config:   including file: /usr/local/etc/raddb/sql.conf
Config:   including file: /usr/local/etc/raddb/sql/mysql/dialup.conf
Config:   including file: /usr/local/etc/raddb/sql/mysql/counter.conf
Config:   including files in directory: /usr/local/etc/raddb/sites-enabled/
Config:   including file: /usr/local/etc/raddb/sites-enabled/default
Starting - reading configuration files ...
read_config_files:  reading dictionary
main {
	prefix = "/usr/local"
	localstatedir = "/usr/local/var"
	logdir = "/usr/local/var/log/radius"
	libdir = "/usr/local/lib"
	radacctdir = "/usr/local/var/log/radius/radacct"
	hostname_lookups = no
	snmp = no
	max_request_time = 30
	cleanup_delay = 5
	max_requests = 1024
	allow_core_dumps = no
	log_stripped_names = no
	log_file = "/usr/local/var/log/radius/radius.log"
	log_auth = no
	log_auth_badpass = no
	log_auth_goodpass = no
	pidfile = "/usr/local/var/run/radiusd/radiusd.pid"
	checkrad = "/usr/local/sbin/checkrad"
	debug_level = 0
	proxy_requests = yes
 log {
	syslog_facility = "daemon"
 }
 proxy server {
	retry_delay = 5
	retry_count = 3
	default_fallback = no
	dead_time = 120
	wake_all_if_all_dead = no
 }
 security {
	max_attributes = 200
	reject_delay = 1
	status_server = yes
 }
}
 home_server localhost {
	ipaddr = 127.0.0.1 IP address [127.0.0.1]
	port = 1812
	type = "auth"
	secret = "testing123"
	response_window = 20
	max_outstanding = 65536
	zombie_period = 40
	status_check = "status-server"
	ping_check = "none"
	ping_interval = 30
	check_interval = 30
	num_answers_to_alive = 3
	num_pings_to_alive = 3
	revive_interval = 120
	status_check_timeout = 4
 }
 server_pool my_auth_failover {
	type = fail-over
	home_server = localhost
 }
 realm example.com {
	auth_pool = my_auth_failover
 }
 realm LOCAL {
 }
 listen {
	type = "auth"
	ipaddr = *
	port = 1645
 client 127.0.0.1 {
	secret = "testing123"
	shortname = "localhost"
	nastype = "other"
 }
 }
 listen {
	type = "acct"
	ipaddr = *
	port = 1646
 }
radiusd:  entering modules setup
radiusd: Library search path is /usr/local/lib
 instantiate {
 Module: Linked to module rlm_exec
 Module: Instantiating exec
  exec {
	wait = yes
	input_pairs = "request"
	shell_escape = yes
  }
rlm_exec: wait=yes but no output defined. Did you mean output=none?
 Module: Linked to module rlm_expr
 Module: Instantiating expr
 Module: Linked to module rlm_expiration
 Module: Instantiating expiration
  expiration {
	reply-message = "Password Has Expired  "
  }
 Module: Linked to module rlm_logintime
 Module: Instantiating logintime
  logintime {
	reply-message = "You are calling outside your allowed timespan  "
	minimum-timeout = 60
  }
 }
server {
 modules {
 Module: Checking authenticate {...} for more modules to load
 Module: Linked to module rlm_pap
 Module: Instantiating pap
  pap {
	encryption_scheme = "auto"
	auto_header = no
  }
 Module: Linked to module rlm_chap
 Module: Instantiating chap
 Module: Linked to module rlm_mschap
 Module: Instantiating mschap
  mschap {
	use_mppe = yes
	require_encryption = no
	require_strong = no
	with_ntdomain_hack = no
  }
 Module: Linked to module rlm_unix
 Module: Instantiating unix
  unix {
	radwtmp = "/usr/local/var/log/radius/radwtmp"
  }
 Module: Linked to module rlm_eap
 Module: Instantiating eap
  eap {
	default_eap_type = "md5"
	timer_expire = 60
	ignore_unknown_eap_types = no
	cisco_accounting_username_bug = no
  }
  eap: Linked to sub-module rlm_eap_md5
  eap: Instantiating eap-md5
  eap: Linked to sub-module rlm_eap_leap
  eap: Instantiating eap-leap
  eap: Linked to sub-module rlm_eap_gtc
  eap: Instantiating eap-gtc
   gtc {
	challenge = "Password: "
	auth_type = "PAP"
   }
  eap: Linked to sub-module rlm_eap_tls
  eap: Instantiating eap-tls
   tls {
	rsa_key_exchange = no
	dh_key_exchange = yes
	rsa_key_length = 512
	dh_key_length = 512
	verify_depth = 0
	pem_file_type = yes
	private_key_file = "/usr/local/etc/raddb/certs/server.pem"
	certificate_file = "/usr/local/etc/raddb/certs/server.pem"
	CA_file = "/usr/local/etc/raddb/certs/ca.pem"
	private_key_password = "whatever"
	dh_file = "/usr/local/etc/raddb/certs/dh"
	random_file = "/usr/local/etc/raddb/certs/random"
	fragment_size = 1024
	include_length = yes
	check_crl = no
	cipher_list = "DEFAULT"
	make_cert_command = "/usr/local/etc/raddb/certs/bootstrap"
   }
rlm_eap_tls: Loading the certificate file as a chain
  eap: Linked to sub-module rlm_eap_ttls
  eap: Instantiating eap-ttls
   ttls {
	default_eap_type = "md5"
	copy_request_to_tunnel = no
	use_tunneled_reply = no
   }
  eap: Linked to sub-module rlm_eap_peap
  eap: Instantiating eap-peap
   peap {
	default_eap_type = "mschapv2"
	copy_request_to_tunnel = no
	use_tunneled_reply = no
	proxy_tunneled_request_as_eap = yes
   }
  eap: Linked to sub-module rlm_eap_mschapv2
  eap: Instantiating eap-mschapv2
   mschapv2 {
	with_ntdomain_hack = no
   }
 Module: Checking authorize {...} for more modules to load
 Module: Linked to module rlm_preprocess
 Module: Instantiating preprocess
  preprocess {
	huntgroups = "/usr/local/etc/raddb/huntgroups"
	hints = "/usr/local/etc/raddb/hints"
	with_ascend_hack = no
	ascend_channels_per_line = 23
	with_ntdomain_hack = no
	with_specialix_jetstream_hack = no
	with_cisco_vsa_hack = yes
	with_alvarion_vsa_hack = no
  }
 Module: Linked to module rlm_realm
 Module: Instantiating suffix
  realm suffix {
	format = "suffix"
	delimiter = "@"
	ignore_default = no
	ignore_null = no
  }
 Module: Linked to module rlm_files
 Module: Instantiating files
  files {
	usersfile = "/usr/local/etc/raddb/users"
	acctusersfile = "/usr/local/etc/raddb/acct_users"
	preproxy_usersfile = "/usr/local/etc/raddb/preproxy_users"
	compat = "no"
  }
 Module: Linked to module rlm_sql
 Module: Instantiating sql
  sql {
	driver = "rlm_sql_mysql"
	server = "localhost"
	port = ""
	login = "radius"
	password = "kic7ops83"
	radius_db = "radius"
	read_groups = yes
	sqltrace = no
	sqltracefile = "/usr/local/var/log/radius/sqltrace.sql"
	readclients = yes
	deletestalesessions = yes
	num_sql_socks = 5
	sql_user_name = "%{User-Name}"
	default_user_profile = ""
	nas_query = "SELECT id, nasname, shortname, type, secret FROM nas"
	authorize_check_query = "SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id"
	authorize_reply_query = "SELECT id, username, attribute, value, op           FROM radreply           WHERE username = '%{SQL-User-Name}'           ORDER BY id"
	authorize_group_check_query = "SELECT id, groupname, attribute,           Value, op           FROM radgroupcheck           WHERE groupname = '%{Sql-Group}'           ORDER BY id"
	authorize_group_reply_query = "SELECT id, groupname, attribute,           value, op           FROM radgroupreply           WHERE groupname = '%{Sql-Group}'           ORDER BY id"
	accounting_onoff_query = "          UPDATE radacct           SET              acctstoptime       =  '%S',              acctsessiontime    =  unix_timestamp('%S') -                                    unix_timestamp(acctstarttime),              acctterminatecause =  '%{Acct-Terminate-Cause}',              acctstopdelay      =  %{%{Acct-Delay-Time}:-0}           WHERE acctsessiontime =  0           AND acctstoptime      =  0           AND nasipaddress      =  '%{NAS-IP-Address}'           AND acctstarttime     <= '%S'"
	accounting_update_query = "           UPDATE radacct           SET              framedipaddress = '%{Framed-IP-Address}',              acctsessiontime     = '%{Acct-Session-Time}',              acctinputoctets     = '%{%{Acct-Input-Gigawords}:-0}'  << 32 |                                    '%{%{Acct-Input-Octets}:-0}',              acctoutputoctets    = '%{%{Acct-Output-Gigawords}:-0}' << 32 |                                    '%{%{Acct-Output-Octets}:-0}'           WHERE acctsessionid = '%{Acct-Session-Id}'           AND username        = '%{SQL-User-Name}'           AND nasipaddress    = '%{NAS-IP-Address}'"
	accounting_update_query_alt = "           INSERT INTO radacct             (acctsessionid,    acctuniqueid,      username,              realm,            nasipaddress,      nasportid,              nasporttype,      acctstarttime,     acctsessiontime,              acctauthentic,    connectinfo_start, acctinputoctets,              acctoutputoctets, calledstationid,   callingstationid,              servicetype,      framedprotocol,    framedipaddress,              acctstartdelay,   xascendsessionsvrkey)           VALUES             ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}',              '%{SQL-User-Name}',              '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}',              '%{NAS-Port-Type}',              DATE_SUB('%S',                       INTERVAL (%{%{Acct-Session-Time}:-0} +                                 %{%{Acct-Delay-Time}:-0}) SECOND),                       '%{Acct-Session-Time}',              '%{Acct-Authentic}', '',              '%{%{Acct-Input-Gigawords}:-0}' << 32 |              '%{%{Acct-Input-Octets}:-0}',              '%{%{Acct-Output-Gigawords}:-0}' << 32 |              '%{%{Acct-Output-Octets}:-0}',              '%{Called-Station-Id}', '%{Calling-Station-Id}',              '%{Service-Type}', '%{Framed-Protocol}',              '%{Framed-IP-Address}',              '0', '%{X-Ascend-Session-Svr-Key}')"
	accounting_start_query = "           INSERT INTO radacct             (acctsessionid,    acctuniqueid,     username,              realm,            nasipaddress,     nasportid,              nasporttype,      acctstarttime,    acctstoptime,              acctsessiontime,  acctauthentic,    connectinfo_start,              connectinfo_stop, acctinputoctets,  acctoutputoctets,              calledstationid,  callingstationid, acctterminatecause,              servicetype,      framedprotocol,   framedipaddress,              acctstartdelay,   acctstopdelay,    xascendsessionsvrkey)           VALUES             ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}',              '%{SQL-User-Name}',              '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}',              '%{NAS-Port-Type}', '%S', '0',              '0', '%{Acct-Authentic}', '%{Connect-Info}',              '', '0', '0',              '%{Called-Station-Id}', '%{Calling-Station-Id}', '',              '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}',              '%{%{Acct-Delay-Time}:-0}', '0', '%{X-Ascend-Session-Svr-Key}')"
	accounting_start_query_alt = "           UPDATE radacct SET              acctstarttime     = '%S',              acctstartdelay    = '%{%{Acct-Delay-Time}:-0}',              connectinfo_start = '%{Connect-Info}'           WHERE acctsessionid  = '%{Acct-Session-Id}'           AND username         = '%{SQL-User-Name}'           AND nasipaddress     = '%{NAS-IP-Address}'"
	accounting_stop_query = "           UPDATE radacct SET              acctstoptime       = '%S',              acctsessiontime    = '%{Acct-Session-Time}',              acctinputoctets    = '%{%{Acct-Input-Gigawords}:-0}' << 32 |                                   '%{%{Acct-Input-Octets}:-0}',              acctoutputoctets   = '%{%{Acct-Output-Gigawords}:-0}' << 32 |                                   '%{%{Acct-Output-Octets}:-0}',              acctterminatecause = '%{Acct-Terminate-Cause}',              acctstopdelay      = '%{%{Acct-Delay-Time}:-0}',              connectinfo_stop   = '%{Connect-Info}'           WHERE acctsessionid   = '%{Acct-Session-Id}'           AND username          = '%{SQL-User-Name}'           AND nasipaddress      = '%{NAS-IP-Address}'"
	accounting_stop_query_alt = "           INSERT INTO radacct             (acctsessionid, acctuniqueid, username,              realm, nasipaddress, nasportid,              nasporttype, acctstarttime, acctstoptime,              acctsessiontime, acctauthentic, connectinfo_start,              connectinfo_stop, acctinputoctets, acctoutputoctets,              calledstationid, callingstationid, acctterminatecause,              servicetype, framedprotocol, framedipaddress,              acctstartdelay, acctstopdelay)           VALUES             ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}',              '%{SQL-User-Name}',              '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}',              '%{NAS-Port-Type}',              DATE_SUB('%S',                  INTERVAL (%{%{Acct-Session-Time}:-0} +                  %{%{Acct-Delay-Time}:-0}) SECOND),              '%S', '%{Acct-Session-Time}', '%{Acct-Authentic}', '',              '%{Connect-Info}',              '%{%{Acct-Input-Gigawords}:-0}' << 32 |              '%{%{Acct-Input-Octets}:-0}',              '%{%{Acct-Output-Gigawords}:-0}' << 32 |              '%{%{Acct-Output-Octets}:-0}',              '%{Called-Station-Id}', '%{Calling-Station-Id}',              '%{Acct-Terminate-Cause}',              '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}',              '0', '%{%{Acct-Delay-Time}:-0}')"
	group_membership_query = "SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority"
	connect_failure_retry_delay = 60
	simul_count_query = ""
	simul_verify_query = "SELECT radacctid, acctsessionid, username,                                nasipaddress, nasportid, framedipaddress,                                callingstationid, framedprotocol                                FROM radacct                                WHERE username = '%{SQL-User-Name}'                                AND acctstoptime = 0"
	postauth_query = "INSERT INTO radpostauth                           (user, pass, reply, date)                           VALUES (                           '%{User-Name}',                           '%{%{User-Password}:-%{Chap-Password}}',                           '%{reply:Packet-Type}', '%S')"
	safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
  }
rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
rlm_sql (sql): Attempting to connect to radius at localhost:/radius
rlm_sql (sql): starting 0
rlm_sql (sql): Attempting to connect rlm_sql_mysql #0
rlm_sql_mysql: Starting connect to MySQL server for #0
rlm_sql (sql): Connected new DB handle, #0
rlm_sql (sql): starting 1
rlm_sql (sql): Attempting to connect rlm_sql_mysql #1
rlm_sql_mysql: Starting connect to MySQL server for #1
rlm_sql (sql): Connected new DB handle, #1
rlm_sql (sql): starting 2
rlm_sql (sql): Attempting to connect rlm_sql_mysql #2
rlm_sql_mysql: Starting connect to MySQL server for #2
rlm_sql (sql): Connected new DB handle, #2
rlm_sql (sql): starting 3
rlm_sql (sql): Attempting to connect rlm_sql_mysql #3
rlm_sql_mysql: Starting connect to MySQL server for #3
rlm_sql (sql): Connected new DB handle, #3
rlm_sql (sql): starting 4
rlm_sql (sql): Attempting to connect rlm_sql_mysql #4
rlm_sql_mysql: Starting connect to MySQL server for #4
rlm_sql (sql): Connected new DB handle, #4
rlm_sql (sql): Processing generate_sql_clients
rlm_sql (sql) in generate_sql_clients: query is SELECT id, nasname, shortname, type, secret FROM nas
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql (sql): Read entry nasname=sysmon.example1.net,shortname=sysmon,secret=blahblah
rlm_sql (sql): Adding client xx.xy.yz.w (sysmon) to clients list
rlm_sql (sql): Released sql socket id: 4
 Module: Checking preacct {...} for more modules to load
 Module: Linked to module rlm_acct_unique
 Module: Instantiating acct_unique
  acct_unique {
	key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
  }
 Module: Checking accounting {...} for more modules to load
 Module: Linked to module rlm_detail
 Module: Instantiating detail
  detail {
	detailfile = "/usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
	header = "%t"
	detailperm = 384
	dirperm = 493
	locking = no
	log_packet_header = no
  }
 Module: Linked to module rlm_radutmp
 Module: Instantiating radutmp
  radutmp {
	filename = "/usr/local/var/log/radius/radutmp"
	username = "%{User-Name}"
	case_sensitive = yes
	check_with_nas = yes
	perm = 384
	callerid = yes
  }
 Module: Linked to module rlm_attr_filter
 Module: Instantiating attr_filter.accounting_response
  attr_filter attr_filter.accounting_response {
	attrsfile = "/usr/local/etc/raddb/attrs.accounting_response"
	key = "%{User-Name}"
  }
 Module: Checking session {...} for more modules to load
 Module: Checking post-proxy {...} for more modules to load
 Module: Checking post-auth {...} for more modules to load
 Module: Instantiating attr_filter.access_reject
  attr_filter attr_filter.access_reject {
	attrsfile = "/usr/local/etc/raddb/attrs.access_reject"
	key = "%{User-Name}"
  }
 }
}
Initializing the thread pool...
Listening on authentication address * port 1645
Listening on accounting address * port 1646
Listening on proxy address * port 1647
Ready to process requests.
Nothing to do.  Sleeping until we see a request.
rad_recv: Access-Request packet from host xx.xy.yz.w port 1131, id=82, length=75
	User-Name = "lambert at example3.net"
	User-Password = "password1"
	NAS-IP-Address = 255.255.255.255
	NAS-Port = 2
	Framed-Protocol = PPP
+- entering group authorize
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[unix] returns notfound
    rlm_realm: Looking up realm "example3.net" for User-Name = "lambert at example3.net"
    rlm_realm: No such realm "example3.net"
++[suffix] returns noop
  rlm_eap: No EAP-Message, not doing EAP
++[eap] returns noop
    users: Matched entry DEFAULT at line 172
++[files] returns ok
++? if ("%{User-Name}" =~ /@/)
	expand: %{User-Name} -> lambert at example3.net
? Evaluating ("%{User-Name}" =~ /@/) -> TRUE
++? if ("%{User-Name}" =~ /@/) -> TRUE
++- entering if ("%{User-Name}" =~ /@/)
	expand: %{User-Name} -> lambert at example3.net
rlm_sql (sql): sql_set_user escaped user --> 'lambert at example3.net'
rlm_sql (sql): Reserving sql socket id: 3
	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 = 'lambert at example3.net'           ORDER BY id
rlm_sql (sql): User found in radcheck table
	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 = 'lambert at example3.net'           ORDER BY id
	expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = 'lambert at example3.net'           ORDER BY priority
	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 = 'dialup'           ORDER BY id
rlm_sql (sql): User found in group dialup
	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 = 'dialup'           ORDER BY id
rlm_sql (sql): Released sql socket id: 3
+++[sql] returns ok
++- if ("%{User-Name}" =~ /@/) returns ok
++ ... skipping else for request 0: Preceding "if" was taken
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns updated
  rad_check_password:  Found Auth-Type 
auth: type "PAP"
+- entering group PAP
rlm_pap: login attempt with password password1
rlm_pap: Using clear text password.
rlm_pap: User authenticated successfully
++[pap] returns ok
+- entering group post-auth
rlm_sql (sql): Processing sql_postauth
	expand: %{User-Name} -> lambert at example3.net
rlm_sql (sql): sql_set_user escaped user --> 'lambert at example3.net'
	expand: %{User-Password} -> password1
	expand: INSERT INTO radpostauth                           (user, pass, reply, date)                           VALUES (                           '%{User-Name}',                           '%{%{User-Password}:-%{Chap-Password}}',                           '%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth                           (user, pass, reply, date)                           VALUES (                           'lambert at example3.net',                           'password1',                           'Access-Accept', '2007-08-14 03:33:43')
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth                           (user, pass, reply, date)                           VALUES (                           'lambert at example3.net',                           'password1',                           'Access-Accept', '2007-08-14 03:33:43')
rlm_sql (sql): Reserving sql socket id: 2
rlm_sql (sql): Released sql socket id: 2
++[sql] returns ok
Sending Access-Accept of id 82 to xx.xy.yz.w port 1131
	Framed-Protocol = PPP
	Framed-Compression = Van-Jacobson-TCP-IP
Finished request 0 state 5
Going to the next request
Waking up in 4 seconds...
Cleaning up request 0 ID 82 with timestamp +15
Nothing to do.  Sleeping until we see a request.
rad_recv: Access-Request packet from host xx.xy.yz.w port 3307, id=99, length=65
	User-Name = "lambert"
	User-Password = "password1"
	NAS-IP-Address = 255.255.255.255
	NAS-Port = 2
	Framed-Protocol = PPP
+- entering group authorize
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[unix] returns updated
    rlm_realm: No '@' in User-Name = "lambert", looking up realm NULL
    rlm_realm: No such realm "NULL"
++[suffix] returns noop
  rlm_eap: No EAP-Message, not doing EAP
++[eap] returns noop
    users: Matched entry DEFAULT at line 172
++[files] returns ok
++? if ("%{User-Name}" =~ /@/)
	expand: %{User-Name} -> lambert
? Evaluating ("%{User-Name}" =~ /@/) -> FALSE
++? if ("%{User-Name}" =~ /@/) -> FALSE
++- entering else 
	expand: %{User-Name} -> lambert
	expand: %{User-Name}@example1.net -> lambert at example1.net
+++[request] returns ok
	expand: %{User-Name} -> lambert at example1.net
rlm_sql (sql): sql_set_user escaped user --> 'lambert at example1.net'
rlm_sql (sql): Reserving sql socket id: 1
	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 = 'lambert at example1.net'           ORDER BY id
	expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = 'lambert at example1.net'           ORDER BY priority
rlm_sql (sql): Released sql socket id: 1
rlm_sql (sql): User lambert at example1.net not found
+++[sql] returns notfound
	expand: %{Stripped-User-Name}@example2.com -> lambert at example2.com
+++[request] returns notfound
	expand: %{User-Name} -> lambert at example2.com
rlm_sql (sql): sql_set_user escaped user --> 'lambert at example2.com'
rlm_sql (sql): Reserving sql socket id: 0
	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 = 'lambert at example2.com'           ORDER BY id
	expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = 'lambert at example2.com'           ORDER BY priority
rlm_sql (sql): Released sql socket id: 0
rlm_sql (sql): User lambert at example2.com not found
+++[sql] returns notfound
	expand: %{Stripped-User-Name}@example3.net -> lambert at example3.net
+++[request] returns notfound
	expand: %{User-Name} -> lambert at example3.net
rlm_sql (sql): sql_set_user escaped user --> 'lambert at example3.net'
rlm_sql (sql): Reserving sql socket id: 4
	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 = 'lambert at example3.net'           ORDER BY id
rlm_sql (sql): User found in radcheck table
	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 = 'lambert at example3.net'           ORDER BY id
	expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = 'lambert at example3.net'           ORDER BY priority
	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 = 'dialup'           ORDER BY id
rlm_sql (sql): User found in group dialup
	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 = 'dialup'           ORDER BY id
rlm_sql (sql): Released sql socket id: 4
+++[sql] returns ok
++- else  returns ok
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns updated
  rad_check_password:  Found Auth-Type 
auth: type "PAP"
+- entering group PAP
rlm_pap: login attempt with password password1
rlm_pap: Using CRYPT encryption.
rlm_pap: Passwords don't match
++[pap] returns reject
auth: Failed to validate the user.
  Found Post-Auth-Type Reject
+- entering group REJECT
	expand: %{User-Name} -> lambert at example3.net
 attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] returns updated
Delaying reject of request 1 for 1 seconds
Going to the next request
Sending delayed reject for request 1
Sending Access-Reject of id 99 to xx.xy.yz.w port 3307
Waking up in 4 seconds...
Cleaning up request 1 ID 99 with timestamp +27
Nothing to do.  Sleeping until we see a request.


root at radtest.example1.net /usr/local/etc/raddb

03:38:22 Tue Aug 14 # exit
exit

Script done on Tue Aug 14 03:38:25 2007

-- 
Scott Lambert                    KC5MLE                       Unix SysAdmin
lambert at lambertfam.org





More information about the Freeradius-Users mailing list