VSA attributes sent with Access-Reject response
Contact (COEXSI)
contact at coexsi.fr
Tue May 20 10:28:23 CEST 2014
> Put all into in one email. You think I kept your old email, or want to
> visit mailing list archive to dig it up?
Here is a cleaned extract of the configuration:
-----------------------------------------------
authorize {
preprocess
chap
mschap
eap {
ok = return
}
sql
pap
}
authenticate {
Auth-Type PAP {
pap
}
Auth-Type CHAP {
chap
}
Auth-Type MS-CHAP {
mschap
}
eap
Auth-Type eap {
eap {
handled = 1
}
if (handled && (Response-Packet-Type == Access-Challenge)) {
attr_filter.access_challenge.post-auth
handled
}
}
}
post-auth {
sql
Post-Auth-Type REJECT {
sql
attr_filter.access_reject
}
}
preacct {
preprocess
acct_unique
}
accounting {
sql
attr_filter.accounting_response
}
Here is the cleaned startup log:
--------------------------------
Mon May 19 09:14:13 2014 : Info: radiusd: FreeRADIUS Version 2.2.3, for host x86_64-redhat-linux-gnu, built on Jan 23 2014 at 16:59:33
Mon May 19 09:14:13 2014 : Debug: Server was built with:
Mon May 19 09:14:13 2014 : Debug: accounting
Mon May 19 09:14:13 2014 : Debug: authentication
Mon May 19 09:14:13 2014 : Debug: WITH_DHCP
Mon May 19 09:14:13 2014 : Debug: WITH_VMPS
Mon May 19 09:14:13 2014 : Debug: Server core libs:
Mon May 19 09:14:13 2014 : Debug: ssl: OpenSSL 1.0.1e-fips 11 Feb 2013
Mon May 19 09:14:13 2014 : Info: Copyright (C) 1999-2013 The FreeRADIUS server project and contributors.
Mon May 19 09:14:13 2014 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
Mon May 19 09:14:13 2014 : Info: PARTICULAR PURPOSE.
Mon May 19 09:14:13 2014 : Info: You may redistribute copies of FreeRADIUS under the terms of the
Mon May 19 09:14:13 2014 : Info: GNU General Public License.
Mon May 19 09:14:13 2014 : Info: For more information about these matters, see the file named COPYRIGHT.
Mon May 19 09:14:13 2014 : Info: Starting - reading configuration files ...
Mon May 19 09:14:13 2014 : Debug: including configuration file /etc/raddb/radiusd.conf
Mon May 19 09:14:13 2014 : Debug: including files in directory /etc/raddb/modules/
Mon May 19 09:14:13 2014 : Debug: including configuration file /etc/raddb/modules/chap
Mon May 19 09:14:13 2014 : Debug: including configuration file /etc/raddb/modules/expr
Mon May 19 09:14:13 2014 : Debug: including configuration file /etc/raddb/modules/attr_filter
Mon May 19 09:14:13 2014 : Debug: including configuration file /etc/raddb/modules/pap
Mon May 19 09:14:13 2014 : Debug: including configuration file /etc/raddb/modules/acct_unique
Mon May 19 09:14:13 2014 : Debug: including configuration file /etc/raddb/modules/preprocess
Mon May 19 09:14:13 2014 : Debug: including configuration file /etc/raddb/modules/always
Mon May 19 09:14:13 2014 : Debug: including configuration file /etc/raddb/modules/mschap
Mon May 19 09:14:13 2014 : Debug: including configuration file /etc/raddb/eap.conf
Mon May 19 09:14:13 2014 : Debug: including configuration file /etc/raddb/sql.conf
Mon May 19 09:14:13 2014 : Debug: including files in directory /etc/raddb/sites-enabled/
Mon May 19 09:14:13 2014 : Debug: including configuration file /etc/raddb/sites-enabled/partner-1
Mon May 19 09:14:13 2014 : Debug: including configuration file /etc/raddb/partner.conf
Mon May 19 09:14:13 2014 : Debug: including configuration file /etc/raddb/sites-enabled/admin-status
Mon May 19 09:14:13 2014 : Debug: including configuration file /etc/raddb/sites-enabled/admin-pptpserver
Mon May 19 09:14:13 2014 : Debug: including configuration file /etc/raddb/partner.conf
Mon May 19 09:14:13 2014 : Debug: including configuration file /etc/raddb/sites-enabled/partner-2
Mon May 19 09:14:13 2014 : Debug: including configuration file /etc/raddb/partner.conf
Mon May 19 09:14:13 2014 : Debug: main {
Mon May 19 09:14:13 2014 : Debug: user = "radiusd"
Mon May 19 09:14:13 2014 : Debug: group = "radiusd"
Mon May 19 09:14:13 2014 : Debug: allow_core_dumps = no
Mon May 19 09:14:13 2014 : Debug: }
Mon May 19 09:14:13 2014 : Debug: including dictionary file /etc/raddb/dictionary
Mon May 19 09:14:13 2014 : Debug: main {
Mon May 19 09:14:13 2014 : Debug: name = "radiusd"
Mon May 19 09:14:13 2014 : Debug: prefix = "/usr"
Mon May 19 09:14:13 2014 : Debug: localstatedir = "/var"
Mon May 19 09:14:13 2014 : Debug: sbindir = "/usr/sbin"
Mon May 19 09:14:13 2014 : Debug: logdir = "/var/log/radius"
Mon May 19 09:14:13 2014 : Debug: run_dir = "/var/run/radiusd"
Mon May 19 09:14:13 2014 : Debug: libdir = "/usr/lib64/freeradius"
Mon May 19 09:14:13 2014 : Debug: radacctdir = "/var/log/radius/radacct"
Mon May 19 09:14:13 2014 : Debug: hostname_lookups = no
Mon May 19 09:14:13 2014 : Debug: max_request_time = 15
Mon May 19 09:14:13 2014 : Debug: cleanup_delay = 15
Mon May 19 09:14:13 2014 : Debug: max_requests = 150000
Mon May 19 09:14:13 2014 : Debug: pidfile = "/var/run/radiusd/radiusd.pid"
Mon May 19 09:14:13 2014 : Debug: checkrad = "/usr/sbin/checkrad"
Mon May 19 09:14:13 2014 : Debug: debug_level = 0
Mon May 19 09:14:13 2014 : Debug: proxy_requests = no
Mon May 19 09:14:13 2014 : Debug: log {
Mon May 19 09:14:13 2014 : Debug: stripped_names = no
Mon May 19 09:14:13 2014 : Debug: auth = no
Mon May 19 09:14:13 2014 : Debug: auth_badpass = no
Mon May 19 09:14:13 2014 : Debug: auth_goodpass = no
Mon May 19 09:14:13 2014 : Debug: }
Mon May 19 09:14:13 2014 : Debug: security {
Mon May 19 09:14:13 2014 : Debug: max_attributes = 200
Mon May 19 09:14:13 2014 : Debug: reject_delay = 5
Mon May 19 09:14:13 2014 : Debug: status_server = no
Mon May 19 09:14:13 2014 : Debug: }
Mon May 19 09:14:13 2014 : Debug: }
Mon May 19 09:14:13 2014 : Debug: radiusd: #### Loading Realms and Home Servers ####
Mon May 19 09:14:13 2014 : Debug: radiusd: #### Loading Clients ####
Mon May 19 09:14:13 2014 : Debug: radiusd: #### Instantiating modules ####
Mon May 19 09:14:13 2014 : Debug: instantiate {
Mon May 19 09:14:13 2014 : Debug: (Loaded rlm_expr, checking if it's valid)
Mon May 19 09:14:13 2014 : Debug: Module: Linked to module rlm_expr
Mon May 19 09:14:13 2014 : Debug: Module: Instantiating module "expr" from file /etc/raddb/modules/expr
Mon May 19 09:14:13 2014 : Debug: }
Mon May 19 09:14:13 2014 : Debug: radiusd: #### Loading Virtual Servers ####
Mon May 19 09:14:13 2014 : Debug: server { # from file /etc/raddb/radiusd.conf
Mon May 19 09:14:13 2014 : Debug: modules {
Mon May 19 09:14:13 2014 : Debug: } # modules
Mon May 19 09:14:13 2014 : Debug: } # server
Mon May 19 09:14:13 2014 : Debug: server Server-1 { # from file /etc/raddb/sites-enabled/partner-1
Mon May 19 09:14:13 2014 : Debug: modules {
Mon May 19 09:14:13 2014 : Debug: Module: Creating Post-Auth-Type = REJECT
Mon May 19 09:14:13 2014 : Debug: Module: Checking authenticate {...} for more modules to load
Mon May 19 09:14:13 2014 : Debug: (Loaded rlm_pap, checking if it's valid)
Mon May 19 09:14:13 2014 : Debug: Module: Linked to module rlm_pap
Mon May 19 09:14:13 2014 : Debug: Module: Instantiating module "pap" from file /etc/raddb/modules/pap
Mon May 19 09:14:13 2014 : Debug: pap {
Mon May 19 09:14:13 2014 : Debug: encryption_scheme = "auto"
Mon May 19 09:14:13 2014 : Debug: auto_header = yes
Mon May 19 09:14:13 2014 : Debug: }
Mon May 19 09:14:13 2014 : Debug: (Loaded rlm_chap, checking if it's valid)
Mon May 19 09:14:13 2014 : Debug: Module: Linked to module rlm_chap
Mon May 19 09:14:13 2014 : Debug: Module: Instantiating module "chap" from file /etc/raddb/modules/chap
Mon May 19 09:14:13 2014 : Debug: (Loaded rlm_mschap, checking if it's valid)
Mon May 19 09:14:13 2014 : Debug: Module: Linked to module rlm_mschap
Mon May 19 09:14:13 2014 : Debug: Module: Instantiating module "mschap" from file /etc/raddb/modules/mschap
Mon May 19 09:14:13 2014 : Debug: mschap {
Mon May 19 09:14:13 2014 : Debug: use_mppe = yes
Mon May 19 09:14:13 2014 : Debug: require_encryption = no
Mon May 19 09:14:13 2014 : Debug: require_strong = no
Mon May 19 09:14:13 2014 : Debug: with_ntdomain_hack = no
Mon May 19 09:14:13 2014 : Debug: allow_retry = yes
Mon May 19 09:14:13 2014 : Debug: }
Mon May 19 09:14:13 2014 : Debug: (Loaded rlm_eap, checking if it's valid)
Mon May 19 09:14:13 2014 : Debug: Module: Linked to module rlm_eap
Mon May 19 09:14:13 2014 : Debug: Module: Instantiating module "eap" from file /etc/raddb/eap.conf
Mon May 19 09:14:13 2014 : Debug: eap {
Mon May 19 09:14:13 2014 : Debug: default_eap_type = "md5"
Mon May 19 09:14:13 2014 : Debug: timer_expire = 60
Mon May 19 09:14:13 2014 : Debug: ignore_unknown_eap_types = no
Mon May 19 09:14:13 2014 : Debug: cisco_accounting_username_bug = no
Mon May 19 09:14:13 2014 : Debug: max_sessions = 4096
Mon May 19 09:14:13 2014 : Debug: }
Mon May 19 09:14:13 2014 : Debug: Module: Linked to sub-module rlm_eap_md5
Mon May 19 09:14:13 2014 : Debug: Module: Instantiating eap-md5
Mon May 19 09:14:13 2014 : Debug: (Loaded rlm_attr_filter, checking if it's valid)
Mon May 19 09:14:13 2014 : Debug: Module: Linked to module rlm_attr_filter
Mon May 19 09:14:13 2014 : Debug: Module: Instantiating module "attr_filter.access_challenge" from file /etc/raddb/modules/attr_filter
Mon May 19 09:14:13 2014 : Debug: attr_filter attr_filter.access_challenge {
Mon May 19 09:14:13 2014 : Debug: attrsfile = "/etc/raddb/attrs.access_challenge"
Mon May 19 09:14:13 2014 : Debug: key = "%{User-Name}"
Mon May 19 09:14:13 2014 : Debug: relaxed = no
Mon May 19 09:14:13 2014 : Debug: }
Mon May 19 09:14:13 2014 : Debug: reading pairlist file /etc/raddb/attrs.access_challenge
Mon May 19 09:14:13 2014 : Debug: (Loaded rlm_always, checking if it's valid)
Mon May 19 09:14:13 2014 : Debug: Module: Linked to module rlm_always
Mon May 19 09:14:13 2014 : Debug: Module: Instantiating module "handled" from file /etc/raddb/modules/always
Mon May 19 09:14:13 2014 : Debug: always handled {
Mon May 19 09:14:13 2014 : Debug: rcode = "handled"
Mon May 19 09:14:13 2014 : Debug: simulcount = 0
Mon May 19 09:14:13 2014 : Debug: mpp = no
Mon May 19 09:14:13 2014 : Debug: }
Mon May 19 09:14:13 2014 : Debug: Module: Checking authorize {...} for more modules to load
Mon May 19 09:14:13 2014 : Debug: (Loaded rlm_preprocess, checking if it's valid)
Mon May 19 09:14:13 2014 : Debug: Module: Linked to module rlm_preprocess
Mon May 19 09:14:13 2014 : Debug: Module: Instantiating module "preprocess" from file /etc/raddb/modules/preprocess
Mon May 19 09:14:13 2014 : Debug: preprocess {
Mon May 19 09:14:13 2014 : Debug: with_ascend_hack = no
Mon May 19 09:14:13 2014 : Debug: ascend_channels_per_line = 23
Mon May 19 09:14:13 2014 : Debug: with_ntdomain_hack = no
Mon May 19 09:14:13 2014 : Debug: with_specialix_jetstream_hack = no
Mon May 19 09:14:13 2014 : Debug: with_cisco_vsa_hack = no
Mon May 19 09:14:13 2014 : Debug: with_alvarion_vsa_hack = no
Mon May 19 09:14:13 2014 : Debug: }
Mon May 19 09:14:13 2014 : Debug: (Loaded rlm_sql, checking if it's valid)
Mon May 19 09:14:13 2014 : Debug: Module: Linked to module rlm_sql
Mon May 19 09:14:13 2014 : Debug: Module: Instantiating module "sql" from file /etc/raddb/sql.conf
Mon May 19 09:14:13 2014 : Debug: sql {
Mon May 19 09:14:13 2014 : Debug: driver = "rlm_sql_mysql"
Mon May 19 09:14:13 2014 : Debug: server = "xxxx"
Mon May 19 09:14:13 2014 : Debug: port = "3306"
Mon May 19 09:14:13 2014 : Debug: login = "xxxx"
Mon May 19 09:14:13 2014 : Debug: password = "xxxx"
Mon May 19 09:14:13 2014 : Debug: radius_db = "xxxx"
Mon May 19 09:14:13 2014 : Debug: read_groups = yes
Mon May 19 09:14:13 2014 : Debug: sqltrace = no
Mon May 19 09:14:13 2014 : Debug: sqltracefile = "/var/log/radius/sqltrace.sql"
Mon May 19 09:14:13 2014 : Debug: readclients = no
Mon May 19 09:14:13 2014 : Debug: deletestalesessions = yes
Mon May 19 09:14:13 2014 : Debug: num_sql_socks = 100
Mon May 19 09:14:13 2014 : Debug: lifetime = 120
Mon May 19 09:14:13 2014 : Debug: max_queries = 1000
Mon May 19 09:14:13 2014 : Debug: sql_user_name = "%{User-Name}"
Mon May 19 09:14:13 2014 : Debug: default_user_profile = ""
Mon May 19 09:14:13 2014 : Debug: nas_query = "SELECT id,nasname,shortname,type,secret FROM nas"
Mon May 19 09:14:13 2014 : Debug: authorize_check_query = "CALL my_stored_procedure ('%{Virtual-Server}','AUTH_REQ' ,'%{User-Name}','%{Client-IP-Address}','%{Calling-Station-Id}','%{Acct-Session-Id}','%{NAS-Identifier}','%{Called-Station-Id}','%{Framed-Protocol}','%{Acct-Delay-Time}','%{Acct-Terminate-Cause}','%{Acct-Session-Time}','%{Acct-Output-Packets}','%{Acct-Input-Packets}','%{Cleartext-Password}','%{reply:Packet-Type}','%{Acct-Status-Type}')"
Mon May 19 09:14:13 2014 : Debug: authorize_reply_query = "CALL my_stored_procedure ('%{Virtual-Server}','AUTH_REPL' ,'%{User-Name}','%{Client-IP-Address}','%{Calling-Station-Id}','%{Acct-Session-Id}','%{NAS-Identifier}','%{Called-Station-Id}','%{Framed-Protocol}','%{Acct-Delay-Time}','%{Acct-Terminate-Cause}','%{Acct-Session-Time}','%{Acct-Output-Packets}','%{Acct-Input-Packets}','%{Cleartext-Password}','%{reply:Packet-Type}','%{Acct-Status-Type}')"
Mon May 19 09:14:13 2014 : Debug: authorize_group_check_query = ""
Mon May 19 09:14:13 2014 : Debug: authorize_group_reply_query = ""
Mon May 19 09:14:13 2014 : Debug: accounting_onoff_query = "CALL my_stored_procedure ('%{Virtual-Server}','ACCT_ONOFF','%{User-Name}','%{Client-IP-Address}','%{Calling-Station-Id}','%{Acct-Session-Id}','%{NAS-Identifier}','%{Called-Station-Id}','%{Framed-Protocol}','%{Acct-Delay-Time}','%{Acct-Terminate-Cause}','%{Acct-Session-Time}','%{Acct-Output-Packets}','%{Acct-Input-Packets}','%{Cleartext-Password}','%{reply:Packet-Type}','%{Acct-Status-Type}')"
Mon May 19 09:14:13 2014 : Debug: accounting_update_query = "CALL my_stored_procedure ('%{Virtual-Server}','ACCT_UPDT' ,'%{User-Name}','%{Client-IP-Address}','%{Calling-Station-Id}','%{Acct-Session-Id}','%{NAS-Identifier}','%{Called-Station-Id}','%{Framed-Protocol}','%{Acct-Delay-Time}','%{Acct-Terminate-Cause}','%{Acct-Session-Time}','%{Acct-Output-Packets}','%{Acct-Input-Packets}','%{Cleartext-Password}','%{reply:Packet-Type}','%{Acct-Status-Type}')"
Mon May 19 09:14:13 2014 : Debug: accounting_update_query_alt = "CALL my_stored_procedure ('%{Virtual-Server}','ACCT_UPDT' ,'%{User-Name}','%{Client-IP-Address}','%{Calling-Station-Id}','%{Acct-Session-Id}','%{NAS-Identifier}','%{Called-Station-Id}','%{Framed-Protocol}','%{Acct-Delay-Time}','%{Acct-Terminate-Cause}','%{Acct-Session-Time}','%{Acct-Output-Packets}','%{Acct-Input-Packets}','%{Cleartext-Password}','%{reply:Packet-Type}','%{Acct-Status-Type}')"
Mon May 19 09:14:13 2014 : Debug: accounting_start_query = "CALL my_stored_procedure ('%{Virtual-Server}','ACCT_START','%{User-Name}','%{Client-IP-Address}','%{Calling-Station-Id}','%{Acct-Session-Id}','%{NAS-Identifier}','%{Called-Station-Id}','%{Framed-Protocol}','%{Acct-Delay-Time}','%{Acct-Terminate-Cause}','%{Acct-Session-Time}','%{Acct-Output-Packets}','%{Acct-Input-Packets}','%{Cleartext-Password}','%{reply:Packet-Type}','%{Acct-Status-Type}')"
Mon May 19 09:14:13 2014 : Debug: accounting_start_query_alt = "CALL my_stored_procedure ('%{Virtual-Server}','ACCT_START','%{User-Name}','%{Client-IP-Address}','%{Calling-Station-Id}','%{Acct-Session-Id}','%{NAS-Identifier}','%{Called-Station-Id}','%{Framed-Protocol}','%{Acct-Delay-Time}','%{Acct-Terminate-Cause}','%{Acct-Session-Time}','%{Acct-Output-Packets}','%{Acct-Input-Packets}','%{Cleartext-Password}','%{reply:Packet-Type}','%{Acct-Status-Type}')"
Mon May 19 09:14:13 2014 : Debug: accounting_stop_query = "CALL my_stored_procedure ('%{Virtual-Server}','ACCT_STOP' ,'%{User-Name}','%{Client-IP-Address}','%{Calling-Station-Id}','%{Acct-Session-Id}','%{NAS-Identifier}','%{Called-Station-Id}','%{Framed-Protocol}','%{Acct-Delay-Time}','%{Acct-Terminate-Cause}','%{Acct-Session-Time}','%{Acct-Output-Packets}','%{Acct-Input-Packets}','%{Cleartext-Password}','%{reply:Packet-Type}','%{Acct-Status-Type}')"
Mon May 19 09:14:13 2014 : Debug: accounting_stop_query_alt = "CALL my_stored_procedure ('%{Virtual-Server}','ACCT_STOP' ,'%{User-Name}','%{Client-IP-Address}','%{Calling-Station-Id}','%{Acct-Session-Id}','%{NAS-Identifier}','%{Called-Station-Id}','%{Framed-Protocol}','%{Acct-Delay-Time}','%{Acct-Terminate-Cause}','%{Acct-Session-Time}','%{Acct-Output-Packets}','%{Acct-Input-Packets}','%{Cleartext-Password}','%{reply:Packet-Type}','%{Acct-Status-Type}')"
Mon May 19 09:14:13 2014 : Debug: connect_failure_retry_delay = 60
Mon May 19 09:14:13 2014 : Debug: simul_count_query = ""
Mon May 19 09:14:13 2014 : Debug: simul_verify_query = ""
Mon May 19 09:14:13 2014 : Debug: postauth_query = "CALL my_stored_procedure ('%{Virtual-Server}','AUTH_POST' ,'%{User-Name}','%{Client-IP-Address}','%{Calling-Station-Id}','%{Acct-Session-Id}','%{NAS-Identifier}','%{Called-Station-Id}','%{Framed-Protocol}','%{Acct-Delay-Time}','%{Acct-Terminate-Cause}','%{Acct-Session-Time}','%{Acct-Output-Packets}','%{Acct-Input-Packets}','%{Cleartext-Password}','%{reply:Packet-Type}','%{Acct-Status-Type}')"
Mon May 19 09:14:13 2014 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
Mon May 19 09:14:13 2014 : Debug: }
Mon May 19 09:14:13 2014 : Info: rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
Mon May 19 09:14:13 2014 : Info: rlm_sql (sql): Attempting to connect to xxxx at xxxx:3306/xxxx
Mon May 19 09:14:13 2014 : Debug: rlm_sql (sql): starting 0
Mon May 19 09:14:13 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #0
Mon May 19 09:14:13 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #0
Mon May 19 09:14:13 2014 : Info: rlm_sql (sql): Connected new DB handle, #0
... starting the 100 connections ...
Mon May 19 09:14:14 2014 : Debug: rlm_sql (sql): starting 99
Mon May 19 09:14:14 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #99
Mon May 19 09:14:14 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #99
Mon May 19 09:14:14 2014 : Info: rlm_sql (sql): Connected new DB handle, #99
Mon May 19 09:14:14 2014 : Debug: Module: Checking preacct {...} for more modules to load
Mon May 19 09:14:14 2014 : Debug: (Loaded rlm_acct_unique, checking if it's valid)
Mon May 19 09:14:14 2014 : Debug: Module: Linked to module rlm_acct_unique
Mon May 19 09:14:14 2014 : Debug: Module: Instantiating module "acct_unique" from file /etc/raddb/modules/acct_unique
Mon May 19 09:14:14 2014 : Debug: acct_unique {
Mon May 19 09:14:14 2014 : Debug: key = "User-Name, Acct-Session-Id, NAS-IP-Address, NAS-Identifier, NAS-Port"
Mon May 19 09:14:14 2014 : Debug: }
Mon May 19 09:14:14 2014 : Debug: Module: Checking accounting {...} for more modules to load
Mon May 19 09:14:14 2014 : Debug: Module: Instantiating module "attr_filter.accounting_response" from file /etc/raddb/modules/attr_filter
Mon May 19 09:14:14 2014 : Debug: attr_filter attr_filter.accounting_response {
Mon May 19 09:14:14 2014 : Debug: attrsfile = "/etc/raddb/attrs.accounting_response"
Mon May 19 09:14:14 2014 : Debug: key = "%{User-Name}"
Mon May 19 09:14:14 2014 : Debug: relaxed = no
Mon May 19 09:14:14 2014 : Debug: }
Mon May 19 09:14:14 2014 : Debug: reading pairlist file /etc/raddb/attrs.accounting_response
Mon May 19 09:14:14 2014 : Debug: Module: Checking post-auth {...} for more modules to load
Mon May 19 09:14:14 2014 : Debug: Module: Instantiating module "attr_filter.access_reject" from file /etc/raddb/modules/attr_filter
Mon May 19 09:14:14 2014 : Debug: attr_filter attr_filter.access_reject {
Mon May 19 09:14:14 2014 : Debug: attrsfile = "/etc/raddb/attrs.access_reject"
Mon May 19 09:14:14 2014 : Debug: key = "%{User-Name}"
Mon May 19 09:14:14 2014 : Debug: relaxed = no
Mon May 19 09:14:14 2014 : Debug: }
Mon May 19 09:14:14 2014 : Debug: reading pairlist file /etc/raddb/attrs.access_reject
Mon May 19 09:14:14 2014 : Debug: } # modules
Mon May 19 09:14:14 2014 : Debug: } # server
Mon May 19 09:14:14 2014 : Debug: server Status-Server { # from file /etc/raddb/sites-enabled/admin-status
Mon May 19 09:14:14 2014 : Debug: modules {
Mon May 19 09:14:14 2014 : Debug: Module: Creating Autz-Type = Status-Server
Mon May 19 09:14:14 2014 : Debug: Module: Checking authorize {...} for more modules to load
Mon May 19 09:14:14 2014 : Debug: } # modules
Mon May 19 09:14:14 2014 : Debug: } # server
Mon May 19 09:14:14 2014 : Debug: server PPTP-Server { # from file /etc/raddb/sites-enabled/admin-pptpserver
Mon May 19 09:14:14 2014 : Debug: modules {
Mon May 19 09:14:14 2014 : Debug: Module: Checking authenticate {...} for more modules to load
Mon May 19 09:14:14 2014 : Debug: Module: Checking authorize {...} for more modules to load
Mon May 19 09:14:14 2014 : Debug: Module: Checking preacct {...} for more modules to load
Mon May 19 09:14:14 2014 : Debug: Module: Checking accounting {...} for more modules to load
Mon May 19 09:14:14 2014 : Debug: Module: Checking post-auth {...} for more modules to load
Mon May 19 09:14:14 2014 : Debug: } # modules
Mon May 19 09:14:14 2014 : Debug: } # server
Mon May 19 09:14:14 2014 : Debug: server Server-2 { # from file /etc/raddb/sites-enabled/partner-2
Mon May 19 09:14:14 2014 : Debug: modules {
Mon May 19 09:14:14 2014 : Debug: Module: Checking authenticate {...} for more modules to load
Mon May 19 09:14:14 2014 : Debug: Module: Checking authorize {...} for more modules to load
Mon May 19 09:14:14 2014 : Debug: Module: Checking preacct {...} for more modules to load
Mon May 19 09:14:14 2014 : Debug: Module: Checking accounting {...} for more modules to load
Mon May 19 09:14:14 2014 : Debug: Module: Checking post-auth {...} for more modules to load
Mon May 19 09:14:14 2014 : Debug: } # modules
Mon May 19 09:14:14 2014 : Debug: } # server
Mon May 19 09:14:14 2014 : Debug: radiusd: #### Opening IP addresses and Ports ####
Mon May 19 09:14:14 2014 : Debug: listen {
Mon May 19 09:14:14 2014 : Debug: type = "auth"
Mon May 19 09:14:14 2014 : Debug: ipaddr = *
Mon May 19 09:14:14 2014 : Debug: port = 1812
Mon May 19 09:14:14 2014 : Debug: client 0.0.0.0/0 {
Mon May 19 09:14:14 2014 : Debug: require_message_authenticator = no
Mon May 19 09:14:14 2014 : Debug: secret = "xxxx"
Mon May 19 09:14:14 2014 : Debug: }
Mon May 19 09:14:14 2014 : Debug: }
Mon May 19 09:14:14 2014 : Debug: listen {
Mon May 19 09:14:14 2014 : Debug: type = "acct"
Mon May 19 09:14:14 2014 : Debug: ipaddr = *
Mon May 19 09:14:14 2014 : Debug: port = 1813
Mon May 19 09:14:14 2014 : Debug: }
Mon May 19 09:14:14 2014 : Debug: listen {
Mon May 19 09:14:14 2014 : Debug: type = "status"
Mon May 19 09:14:14 2014 : Debug: ipaddr = 127.0.0.1
Mon May 19 09:14:14 2014 : Debug: port = 1801
Mon May 19 09:14:14 2014 : Debug: client 127.0.0.1/32 {
Mon May 19 09:14:14 2014 : Debug: require_message_authenticator = no
Mon May 19 09:14:14 2014 : Debug: secret = "xxxx"
Mon May 19 09:14:14 2014 : Debug: }
Mon May 19 09:14:14 2014 : Debug: }
Mon May 19 09:14:14 2014 : Debug: listen {
Mon May 19 09:14:14 2014 : Debug: type = "auth"
Mon May 19 09:14:14 2014 : Debug: ipaddr = *
Mon May 19 09:14:14 2014 : Debug: port = 1802
Mon May 19 09:14:14 2014 : Debug: client X.X.X.X/X {
Mon May 19 09:14:14 2014 : Debug: require_message_authenticator = no
Mon May 19 09:14:14 2014 : Debug: secret = "xxxx"
Mon May 19 09:14:14 2014 : Debug: }
Mon May 19 09:14:14 2014 : Debug: }
Mon May 19 09:14:14 2014 : Debug: listen {
Mon May 19 09:14:14 2014 : Debug: type = "auth"
Mon May 19 09:14:14 2014 : Debug: ipaddr = *
Mon May 19 09:14:14 2014 : Debug: port = 1822
Mon May 19 09:14:14 2014 : Debug: client 0.0.0.0/0 {
Mon May 19 09:14:14 2014 : Debug: require_message_authenticator = no
Mon May 19 09:14:14 2014 : Debug: secret = "xxxx"
Mon May 19 09:14:14 2014 : Debug: }
Mon May 19 09:14:14 2014 : Debug: }
Mon May 19 09:14:14 2014 : Debug: listen {
Mon May 19 09:14:14 2014 : Debug: type = "acct"
Mon May 19 09:14:14 2014 : Debug: ipaddr = *
Mon May 19 09:14:14 2014 : Debug: port = 1823
Mon May 19 09:14:14 2014 : Debug: }
Mon May 19 09:14:14 2014 : Debug: Listening on authentication address * port 1812 as server Server-1
Mon May 19 09:14:14 2014 : Debug: Listening on accounting address * port 1813 as server Server-1
Mon May 19 09:14:14 2014 : Debug: Listening on status address 127.0.0.1 port 1801 as server Status-Server
Mon May 19 09:14:14 2014 : Debug: Listening on authentication address * port 1802 as server PPTP-Server
Mon May 19 09:14:14 2014 : Debug: Listening on authentication address * port 1822 as server Server-2
Mon May 19 09:14:14 2014 : Debug: Listening on accounting address * port 1823 as server Server-2
Mon May 19 09:14:14 2014 : Info: Ready to process requests.
Here is the Access-Challenge sent with VSA:
-------------------------------------------
rad_recv: Access-Request packet from host X.X.X.X port 32771, id=141, length=152
Acct-Session-Id = "5612ab46"
NAS-Port = 0
NAS-Port-Type = Wireless-802.11
User-Name = "test"
Calling-Station-Id = "XX-XX-XX-XX-XX-XX"
Called-Station-Id = "XX-XX-XX-XX-XX-XX"
Framed-IP-Address = X.X.X.X
EAP-Message = 0x028d00090174657374
NAS-Identifier = "test"
NAS-IP-Address = X.X.X.X
Framed-MTU = 1496
Connect-Info = "HTTPS"
Service-Type = Administrative-User
Message-Authenticator = 0x0be651342e0ab4fbfe8dbd0c99750120
Fri May 16 22:54:28 2014 : Info: server my_server { Fri May 16 22:54:28 2014 : Info: # Executing section authorize from file /etc/raddb/partner.conf Fri May 16 22:54:28 2014 : Info: +group authorize { Fri May 16 22:54:28 2014 : Info: ++[preprocess] = ok Fri May 16 22:54:28 2014 : Info: ++[chap] = noop Fri May 16 22:54:28 2014 : Info: ++[mschap] = noop Fri May 16 22:54:28 2014 : Info: [eap] EAP packet type response id 141 length 9 Fri May 16 22:54:28 2014 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Fri May 16 22:54:28 2014 : Info: ++[eap] = updated Fri May 16 22:54:28 2014 : Info: [sql] expand: %{User-Name} -> test Fri May 16 22:54:28 2014 : Info: [sql] sql_set_user escaped user --> 'test'
Fri May 16 22:54:28 2014 : Debug: Closing socket 99 as its lifetime has been exceeded Fri May 16 22:54:28 2014 : Info: rlm_sql (sql): Trying to (re)connect unconnected handle 99..
Fri May 16 22:54:28 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #99 Fri May 16 22:54:28 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #99 Fri May 16 22:54:28 2014 : Info: rlm_sql (sql): Connected new DB handle, #99 Fri May 16 22:54:28 2014 : Debug: rlm_sql (sql): Reserving sql socket id: 99 Fri May 16 22:54:28 2014 : Debug: rlm_sql (sql): got socket 99 after skipping 0 unconnected handles, tried to reconnect 1 though Fri May 16 22:54:28 2014 : Info: [sql] expand: CALL my_stored_procedure ('%{Virtual-Server}','AUTH_REQ'
,'%{User-Name}','%{Client-IP-Address}','%{Calling-Station-Id}','%{Acct-Sessi
on-Id}','%{NAS-Identifier}','%{Called-Station-Id}','%{Framed-Protocol}','%{A
cct-Delay-Time}','%{Acct-Terminate-Cause}','%{Acct-Session-Time}','%{Acct-Ou
tput-Packets}','%{Acct-Input-Packets}','%{Cleartext-Password}','%{reply:Pack
et-Type}','%{Acct-Status-Type}') -> CALL my_stored_procedure ('my_server','AUTH_REQ'
,'test','X.X.X.X','XX-XX-XX-XX-XX-XX','5612ab46','test','XX-XX-XX-XX-XX-XX',
'','','','','','','','0','')
Fri May 16 22:54:28 2014 : Info: [sql] User found in radcheck table Fri May 16 22:54:28 2014 : Info: [sql] expand: CALL my_stored_procedure ('%{Virtual-Server}','AUTH_REPL'
,'%{User-Name}','%{Client-IP-Address}','%{Calling-Station-Id}','%{Acct-Sessi
on-Id}','%{NAS-Identifier}','%{Called-Station-Id}','%{Framed-Protocol}','%{A
cct-Delay-Time}','%{Acct-Terminate-Cause}','%{Acct-Session-Time}','%{Acct-Ou
tput-Packets}','%{Acct-Input-Packets}','%{Cleartext-Password}','%{reply:Pack
et-Type}','%{Acct-Status-Type}') -> CALL my_stored_procedure ('my_server','AUTH_REPL'
,'test','X.X.X.X','XX-XX-XX-XX-XX-XX','5612ab46','test','XX-XX-XX-XX-XX-XX',
'','','','','','','','0','')
Fri May 16 22:54:28 2014 : Debug: rlm_sql (sql): Released sql socket id: 99 Fri May 16 22:54:28 2014 : Info: ++[sql] = ok Fri May 16 22:54:28 2014 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP Fri May 16 22:54:28 2014 : Info: ++[pap] = noop Fri May 16 22:54:28 2014 : Info: +} # group authorize = updated Fri May 16 22:54:28 2014 : Info: Found Auth-Type = EAP Fri May 16 22:54:28 2014 : Info: # Executing group from file /etc/raddb/partner.conf Fri May 16 22:54:28 2014 : Info: +group authenticate { Fri May 16 22:54:28 2014 : Info: [eap] EAP Identity Fri May 16 22:54:28 2014 : Info: [eap] processing type md5 Fri May 16 22:54:28 2014 : Debug: rlm_eap_md5: Issuing Challenge Fri May 16 22:54:28 2014 : Info: ++[eap] = handled Fri May 16 22:54:28 2014 : Info: +} # group authenticate = handled Fri May 16 22:54:28 2014 : Info: } # server my_server Sending Access-Challenge of id 141 to X.X.X.X port 32771
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
Colubris-AVPair += "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX"
EAP-Message = 0x018e00160410e4221f5be6c61e8cd9c9d5f403e52706
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x4a3d8da24ab389bc6e24b0dbbc2bac25
Fri May 16 22:54:28 2014 : Info: Finished request 0.
Fri May 16 22:54:28 2014 : Debug: Going to the next request
More information about the Freeradius-Users
mailing list