- Freeradius-Users - lists.freeradius.org

Newbee question
by Maria Sanchez 30 Jun '10

30 Jun '10

Hi, I am getting familiar with FreeRadius since it is being proposed in the designs as our Authentication/Authorization server. I have successfully installed and started the server and I have done some calls using the radtest client script. I am currently only using the users file to create new users since my goal at this time is validating concepts.... I am currently trying to assign a Role to one of my users and get that value returned to the client. I am still using the radtest client. The only information I found related to configuring roles indicated that I had to enter a new attribute in the dictionary file, add the attribute in the users file with the value I needed and add the dictionary file as a parameter to the radtest (-d directory) to be able to see the attribute in the returned message... Well this is not working as described... Any idea or reference document I can use to have this configured? Thanks for your help! Maria

4 5

originate-coa virtual server
by Ben Wiechman 30 Jun '10

30 Jun '10

The originate-coa virtual server includes a switch condition using the Response-Packet-Type attribute in the post-proxy section. However this attribute is not populated for responses to coa or disconnect requests. The Packet-Type attribute is populated in the proxy-reply list (which is perhaps to be inferred from the comments in the originate-coa file). Is the lack of information in the Response-Packet-Type attribute expected in a response to a coa or disconnect request and the switch should be updated to use %{proxy-reply:Packet-Type} (this does work) or should the Response-Packet-Type attribute be populated for a response to a coa or disconnect request? This is using 2.1.10 up to git 288647f (to pull in the coa correlation fixes) Snippet: Tue Jun 29 15:27:09 2010 : Info: +- entering group post-proxy {...} Tue Jun 29 15:27:09 2010 : Info: expand: %{proxy-reply:Response-Packet-Type} -> Tue Jun 29 15:27:09 2010 : Info: expand: %{proxy-request:Response-Packet-Type} -> Tue Jun 29 15:27:09 2010 : Info: expand: %{request:Response-Packet-Type} -> Tue Jun 29 15:27:09 2010 : Info: expand: %{reply:Response-Packet-Type} -> Tue Jun 29 15:27:09 2010 : Info: expand: %{proxy-reply:Packet-Type} -> Disconnect-NAK Tue Jun 29 15:27:09 2010 : Info: expand: %{proxy-request:Packet-Type} -> Disconnect-Request Tue Jun 29 15:27:09 2010 : Info: expand: %{request:Packet-Type} -> Accounting-Request Tue Jun 29 15:27:09 2010 : Info: expand: %{reply:Packet-Type} -> Accounting-Response Tue Jun 29 15:27:09 2010 : Info: expand: %{Packet-Type} -> Accounting-Request Full Debug: [root@radius-dev sites-enabled]# radiusd -Xx Tue Jun 29 15:26:26 2010 : Info: FreeRADIUS Version 2.1.10, for host x86_64-redhat-linux-gnu, built on Jun 14 2010 at 15:41:02 Tue Jun 29 15:26:26 2010 : Info: Copyright (C) 1999-2009 The FreeRADIUS server project and contributors. Tue Jun 29 15:26:26 2010 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A Tue Jun 29 15:26:26 2010 : Info: PARTICULAR PURPOSE. Tue Jun 29 15:26:26 2010 : Info: You may redistribute copies of FreeRADIUS under the terms of the Tue Jun 29 15:26:26 2010 : Info: GNU General Public License v2. Tue Jun 29 15:26:26 2010 : Info: Starting - reading configuration files ... Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/radiusd.conf Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/proxy.conf Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/clients.conf Tue Jun 29 15:26:26 2010 : Debug: including files in directory /etc/raddb/modules/ Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/otp Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/detail.wimax Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/realm Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/checkval Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/detail.example.com Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/policy Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/wimax Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/smsotp Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/sql_log Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/passwd Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/preprocess Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/perl Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/attr_rewrite Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/detail.wisper Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/always Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/counter Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/linelog Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/ippool Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/digest Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/etc_group Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/ntlm_auth Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/exec Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/chap Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/files Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/pap Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/mac2ip Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/smbpasswd Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/sqlcounter_expire_on_login Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/inner-eap Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/mschap Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/unix Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/pam Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/mac2vlan Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/echo Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/expr Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/attr_filter Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/detail Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/expiration Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/cui Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/acct_unique Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/logintime Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/radutmp Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/detail.log Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/modules/sradutmp Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/eap.conf Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/sql-wisper.conf Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/sql/mysql/dialup.conf Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/sql/mysql/dialup.conf Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/sql/mysql/wimax.conf Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/policy.conf Tue Jun 29 15:26:26 2010 : Debug: including files in directory /etc/raddb/sites-enabled/ Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/sites-enabled/buffered-sql-wisper Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/sites-enabled/wimax-asn Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/sites-enabled/default Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/sites-enabled/eap-stress-test Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/sites-enabled/status Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/sites-enabled/originate-coa-wimax Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/sites-enabled/control-socket Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/sites-enabled/buffered-sql-wimax Tue Jun 29 15:26:26 2010 : Debug: including configuration file /etc/raddb/sites-enabled/inner-tunnel Tue Jun 29 15:26:26 2010 : Debug: main { Tue Jun 29 15:26:26 2010 : Debug: user = "radiusd" Tue Jun 29 15:26:26 2010 : Debug: group = "radiusd" Tue Jun 29 15:26:26 2010 : Debug: allow_core_dumps = no Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: including dictionary file /etc/raddb/dictionary Tue Jun 29 15:26:26 2010 : Debug: main { Tue Jun 29 15:26:26 2010 : Debug: prefix = "/usr" Tue Jun 29 15:26:26 2010 : Debug: localstatedir = "/var" Tue Jun 29 15:26:26 2010 : Debug: logdir = "/var/log/radius" Tue Jun 29 15:26:26 2010 : Debug: libdir = "/usr/lib64/freeradius" Tue Jun 29 15:26:26 2010 : Debug: radacctdir = "/var/log/radius/radacct" Tue Jun 29 15:26:26 2010 : Debug: hostname_lookups = no Tue Jun 29 15:26:26 2010 : Debug: max_request_time = 30 Tue Jun 29 15:26:26 2010 : Debug: cleanup_delay = 3 Tue Jun 29 15:26:26 2010 : Debug: max_requests = 25000 Tue Jun 29 15:26:26 2010 : Debug: pidfile = "/var/run/radiusd/radiusd.pid" Tue Jun 29 15:26:26 2010 : Debug: checkrad = "/usr/sbin/checkrad" Tue Jun 29 15:26:26 2010 : Debug: debug_level = 0 Tue Jun 29 15:26:26 2010 : Debug: proxy_requests = yes Tue Jun 29 15:26:26 2010 : Debug: log { Tue Jun 29 15:26:26 2010 : Debug: stripped_names = no Tue Jun 29 15:26:26 2010 : Debug: auth = yes Tue Jun 29 15:26:26 2010 : Debug: auth_badpass = no Tue Jun 29 15:26:26 2010 : Debug: auth_goodpass = no Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: security { Tue Jun 29 15:26:26 2010 : Debug: max_attributes = 200 Tue Jun 29 15:26:26 2010 : Debug: reject_delay = 1 Tue Jun 29 15:26:26 2010 : Debug: status_server = yes Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: radiusd: #### Loading Realms and Home Servers #### Tue Jun 29 15:26:26 2010 : Debug: proxy server { Tue Jun 29 15:26:26 2010 : Debug: retry_delay = 5 Tue Jun 29 15:26:26 2010 : Debug: retry_count = 3 Tue Jun 29 15:26:26 2010 : Debug: default_fallback = no Tue Jun 29 15:26:26 2010 : Debug: dead_time = 120 Tue Jun 29 15:26:26 2010 : Debug: wake_all_if_all_dead = no Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: home_server localhost { Tue Jun 29 15:26:26 2010 : Debug: ipaddr = 127.0.0.1 Tue Jun 29 15:26:26 2010 : Debug: port = 1812 Tue Jun 29 15:26:26 2010 : Debug: type = "auth" Tue Jun 29 15:26:26 2010 : Debug: secret = "secret" Tue Jun 29 15:26:26 2010 : Debug: response_window = 20 Tue Jun 29 15:26:26 2010 : Debug: max_outstanding = 65536 Tue Jun 29 15:26:26 2010 : Debug: require_message_authenticator = no Tue Jun 29 15:26:26 2010 : Debug: zombie_period = 40 Tue Jun 29 15:26:26 2010 : Debug: status_check = "status-server" Tue Jun 29 15:26:26 2010 : Debug: ping_interval = 30 Tue Jun 29 15:26:26 2010 : Debug: check_interval = 30 Tue Jun 29 15:26:26 2010 : Debug: num_answers_to_alive = 3 Tue Jun 29 15:26:26 2010 : Debug: num_pings_to_alive = 3 Tue Jun 29 15:26:26 2010 : Debug: revive_interval = 120 Tue Jun 29 15:26:26 2010 : Debug: status_check_timeout = 4 Tue Jun 29 15:26:26 2010 : Debug: irt = 2 Tue Jun 29 15:26:26 2010 : Debug: mrt = 16 Tue Jun 29 15:26:26 2010 : Debug: mrc = 5 Tue Jun 29 15:26:26 2010 : Debug: mrd = 30 Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: home_server_pool my_auth_failover { Tue Jun 29 15:26:26 2010 : Debug: type = fail-over Tue Jun 29 15:26:26 2010 : Debug: home_server = localhost Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: realm example.com { Tue Jun 29 15:26:26 2010 : Debug: auth_pool = my_auth_failover Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: realm LOCAL { Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: home_server wichorus-coa { Tue Jun 29 15:26:26 2010 : Debug: ipaddr = 172.17.2.20 Tue Jun 29 15:26:26 2010 : Debug: port = 3799 Tue Jun 29 15:26:26 2010 : Debug: type = "coa" Tue Jun 29 15:26:26 2010 : Debug: secret = "secret" Tue Jun 29 15:26:26 2010 : Debug: response_window = 30 Tue Jun 29 15:26:26 2010 : Debug: max_outstanding = 65536 Tue Jun 29 15:26:26 2010 : Debug: zombie_period = 40 Tue Jun 29 15:26:26 2010 : Debug: status_check = "none" Tue Jun 29 15:26:26 2010 : Debug: ping_interval = 30 Tue Jun 29 15:26:26 2010 : Debug: check_interval = 30 Tue Jun 29 15:26:26 2010 : Debug: num_answers_to_alive = 3 Tue Jun 29 15:26:26 2010 : Debug: num_pings_to_alive = 3 Tue Jun 29 15:26:26 2010 : Debug: revive_interval = 300 Tue Jun 29 15:26:26 2010 : Debug: status_check_timeout = 4 Tue Jun 29 15:26:26 2010 : Debug: irt = 2 Tue Jun 29 15:26:26 2010 : Debug: mrt = 16 Tue Jun 29 15:26:26 2010 : Debug: mrc = 5 Tue Jun 29 15:26:26 2010 : Debug: mrd = 30 Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: home_server_pool coa { Tue Jun 29 15:26:26 2010 : Debug: type = fail-over Tue Jun 29 15:26:26 2010 : Debug: virtual_server = originate-coa-wimax Tue Jun 29 15:26:26 2010 : Debug: home_server = wichorus-coa Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: radiusd: #### Loading Clients #### Tue Jun 29 15:26:26 2010 : Debug: client 172.17.2.20 { Tue Jun 29 15:26:26 2010 : Debug: require_message_authenticator = no Tue Jun 29 15:26:26 2010 : Debug: secret = "secret" Tue Jun 29 15:26:26 2010 : Debug: shortname = "wichorus-asn" Tue Jun 29 15:26:26 2010 : Debug: nastype = "other" Tue Jun 29 15:26:26 2010 : Debug: virtual_server = "wimax-asn" Tue Jun 29 15:26:26 2010 : Debug: coa_server = "coa" Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: radiusd: #### Instantiating modules #### Tue Jun 29 15:26:26 2010 : Debug: instantiate { Tue Jun 29 15:26:26 2010 : Debug: (Loaded rlm_exec, checking if it's valid) Tue Jun 29 15:26:26 2010 : Debug: Module: Linked to module rlm_exec Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating exec Tue Jun 29 15:26:26 2010 : Debug: exec { Tue Jun 29 15:26:26 2010 : Debug: wait = no Tue Jun 29 15:26:26 2010 : Debug: input_pairs = "request" Tue Jun 29 15:26:26 2010 : Debug: shell_escape = yes Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: (Loaded rlm_expr, checking if it's valid) Tue Jun 29 15:26:26 2010 : Debug: Module: Linked to module rlm_expr Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating expr Tue Jun 29 15:26:26 2010 : Debug: (Loaded rlm_expiration, checking if it's valid) Tue Jun 29 15:26:26 2010 : Debug: Module: Linked to module rlm_expiration Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating expiration Tue Jun 29 15:26:26 2010 : Debug: expiration { Tue Jun 29 15:26:26 2010 : Debug: reply-message = "Password Has Expired " Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: (Loaded rlm_logintime, checking if it's valid) Tue Jun 29 15:26:26 2010 : Debug: Module: Linked to module rlm_logintime Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating logintime Tue Jun 29 15:26:26 2010 : Debug: logintime { Tue Jun 29 15:26:26 2010 : Debug: reply-message = "You are calling outside your allowed timespan " Tue Jun 29 15:26:26 2010 : Debug: minimum-timeout = 60 Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: radiusd: #### Loading Virtual Servers #### Tue Jun 29 15:26:26 2010 : Debug: server buffered-sql-wisper { Tue Jun 29 15:26:26 2010 : Debug: modules { Tue Jun 29 15:26:26 2010 : Debug: Module: Checking preacct {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: (Loaded rlm_preprocess, checking if it's valid) Tue Jun 29 15:26:26 2010 : Debug: Module: Linked to module rlm_preprocess Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating preprocess Tue Jun 29 15:26:26 2010 : Debug: preprocess { Tue Jun 29 15:26:26 2010 : Debug: huntgroups = "/etc/raddb/huntgroups" Tue Jun 29 15:26:26 2010 : Debug: hints = "/etc/raddb/hints" Tue Jun 29 15:26:26 2010 : Debug: with_ascend_hack = no Tue Jun 29 15:26:26 2010 : Debug: ascend_channels_per_line = 23 Tue Jun 29 15:26:26 2010 : Debug: with_ntdomain_hack = no Tue Jun 29 15:26:26 2010 : Debug: with_specialix_jetstream_hack = no Tue Jun 29 15:26:26 2010 : Debug: with_cisco_vsa_hack = no Tue Jun 29 15:26:26 2010 : Debug: with_alvarion_vsa_hack = no Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: (Loaded rlm_acct_unique, checking if it's valid) Tue Jun 29 15:26:26 2010 : Debug: Module: Linked to module rlm_acct_unique Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating acct_unique Tue Jun 29 15:26:26 2010 : Debug: acct_unique { Tue Jun 29 15:26:26 2010 : Debug: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: Module: Checking accounting {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: (Loaded rlm_sql, checking if it's valid) Tue Jun 29 15:26:26 2010 : Debug: Module: Linked to module rlm_sql Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating sqlmain Tue Jun 29 15:26:26 2010 : Debug: sql sqlmain { Tue Jun 29 15:26:26 2010 : Debug: driver = "rlm_sql_mysql" Tue Jun 29 15:26:26 2010 : Debug: server = "172.17.0.150" Tue Jun 29 15:26:26 2010 : Debug: port = "" Tue Jun 29 15:26:26 2010 : Debug: login = "radius" Tue Jun 29 15:26:26 2010 : Debug: password = "blah" Tue Jun 29 15:26:26 2010 : Debug: radius_db = "radius2" Tue Jun 29 15:26:26 2010 : Debug: read_groups = yes Tue Jun 29 15:26:26 2010 : Debug: sqltrace = no Tue Jun 29 15:26:26 2010 : Debug: sqltracefile = "/var/log/radius/sqltrace.sql" Tue Jun 29 15:26:26 2010 : Debug: readclients = yes Tue Jun 29 15:26:26 2010 : Debug: deletestalesessions = yes Tue Jun 29 15:26:26 2010 : Debug: num_sql_socks = 15 Tue Jun 29 15:26:26 2010 : Debug: lifetime = 0 Tue Jun 29 15:26:26 2010 : Debug: max_queries = 0 Tue Jun 29 15:26:26 2010 : Debug: sql_user_name = "%{User-Name}" Tue Jun 29 15:26:26 2010 : Debug: default_user_profile = "" Tue Jun 29 15:26:26 2010 : Debug: nas_query = "SELECT id, nasname, shortname, type, secret, server FROM nas" Tue Jun 29 15:26:26 2010 : Debug: authorize_check_query = "SELECT id, username, attribute, value, op FROM radcheck WHERE username = BINARY '%{SQL-User-Name}' ORDER BY id" Tue Jun 29 15:26:26 2010 : Debug: authorize_reply_query = "SELECT id, username, attribute, value, op FROM radreply WHERE username = BINARY '%{SQL-User-Name}' ORDER BY id" Tue Jun 29 15:26:26 2010 : Debug: authorize_group_check_query = "SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id" Tue Jun 29 15:26:26 2010 : Debug: authorize_group_reply_query = "SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id" Tue Jun 29 15:26:26 2010 : Debug: 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 acctstoptime IS NULL AND nasipaddress = '%{NAS-IP-Address}' AND acctstarttime <= '%S'" Tue Jun 29 15:26:26 2010 : Debug: 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}'" Tue Jun 29 15:26:26 2010 : Debug: 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}')" Tue Jun 29 15:26:26 2010 : Debug: 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', NULL, '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}')" Tue Jun 29 15:26:26 2010 : Debug: 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}'" Tue Jun 29 15:26:26 2010 : Debug: 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}'" Tue Jun 29 15:26:26 2010 : Debug: 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}')" Tue Jun 29 15:26:26 2010 : Debug: group_membership_query = "SELECT groupname FROM radusergroup WHERE username = BINARY '%{SQL-User-Name}' ORDER BY priority" Tue Jun 29 15:26:26 2010 : Debug: connect_failure_retry_delay = 60 Tue Jun 29 15:26:26 2010 : Debug: simul_count_query = "" Tue Jun 29 15:26:26 2010 : Debug: simul_verify_query = "SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL" Tue Jun 29 15:26:26 2010 : Debug: postauth_query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')" Tue Jun 29 15:26:26 2010 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /{}" Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Attempting to connect to radius@172.17.0.150:/radius2 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlmain): starting 0 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Attempting to connect rlm_sql_mysql #0 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #0 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Connected new DB handle, #0 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlmain): starting 1 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Attempting to connect rlm_sql_mysql #1 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #1 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Connected new DB handle, #1 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlmain): starting 2 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Attempting to connect rlm_sql_mysql #2 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #2 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Connected new DB handle, #2 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlmain): starting 3 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Attempting to connect rlm_sql_mysql #3 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #3 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Connected new DB handle, #3 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlmain): starting 4 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Attempting to connect rlm_sql_mysql #4 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #4 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Connected new DB handle, #4 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlmain): starting 5 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Attempting to connect rlm_sql_mysql #5 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #5 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Connected new DB handle, #5 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlmain): starting 6 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Attempting to connect rlm_sql_mysql #6 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #6 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Connected new DB handle, #6 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlmain): starting 7 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Attempting to connect rlm_sql_mysql #7 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #7 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Connected new DB handle, #7 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlmain): starting 8 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Attempting to connect rlm_sql_mysql #8 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #8 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Connected new DB handle, #8 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlmain): starting 9 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Attempting to connect rlm_sql_mysql #9 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #9 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Connected new DB handle, #9 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlmain): starting 10 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Attempting to connect rlm_sql_mysql #10 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #10 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Connected new DB handle, #10 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlmain): starting 11 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Attempting to connect rlm_sql_mysql #11 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #11 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Connected new DB handle, #11 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlmain): starting 12 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Attempting to connect rlm_sql_mysql #12 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #12 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Connected new DB handle, #12 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlmain): starting 13 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Attempting to connect rlm_sql_mysql #13 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #13 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Connected new DB handle, #13 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlmain): starting 14 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Attempting to connect rlm_sql_mysql #14 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #14 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlmain): Connected new DB handle, #14 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlmain): Processing generate_sql_clients Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlmain) in generate_sql_clients: query is SELECT id, nasname, shortname, type, secret, server FROM nas Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlmain): Reserving sql socket id: 14 ...snip... Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlmain): Released sql socket id: 14 Tue Jun 29 15:26:26 2010 : Debug: } # modules Tue Jun 29 15:26:26 2010 : Debug: } # server Tue Jun 29 15:26:26 2010 : Debug: server wimax-asn { Tue Jun 29 15:26:26 2010 : Debug: modules { Tue Jun 29 15:26:26 2010 : Debug: Module: Checking authenticate {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: (Loaded rlm_eap, checking if it's valid) Tue Jun 29 15:26:26 2010 : Debug: Module: Linked to module rlm_eap Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating eap Tue Jun 29 15:26:26 2010 : Debug: eap { Tue Jun 29 15:26:26 2010 : Debug: default_eap_type = "ttls" Tue Jun 29 15:26:26 2010 : Debug: timer_expire = 60 Tue Jun 29 15:26:26 2010 : Debug: ignore_unknown_eap_types = yes Tue Jun 29 15:26:26 2010 : Debug: cisco_accounting_username_bug = no Tue Jun 29 15:26:26 2010 : Debug: max_sessions = 2048 Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: Module: Linked to sub-module rlm_eap_tls Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating eap-tls Tue Jun 29 15:26:26 2010 : Debug: tls { Tue Jun 29 15:26:26 2010 : Debug: rsa_key_exchange = no Tue Jun 29 15:26:26 2010 : Debug: dh_key_exchange = yes Tue Jun 29 15:26:26 2010 : Debug: rsa_key_length = 512 Tue Jun 29 15:26:26 2010 : Debug: dh_key_length = 512 Tue Jun 29 15:26:26 2010 : Debug: verify_depth = 0 Tue Jun 29 15:26:26 2010 : Debug: pem_file_type = yes Tue Jun 29 15:26:26 2010 : Debug: private_key_file = "/etc/raddb/certs/radius-dev_key.pem" Tue Jun 29 15:26:26 2010 : Debug: certificate_file = "/etc/raddb/certs/radius-dev_chain.pem" Tue Jun 29 15:26:26 2010 : Debug: CA_file = "/etc/raddb/certs/ca.pem" Tue Jun 29 15:26:26 2010 : Debug: private_key_password = "blah" Tue Jun 29 15:26:26 2010 : Debug: dh_file = "/etc/raddb/certs/dh" Tue Jun 29 15:26:26 2010 : Debug: random_file = "/etc/raddb/certs/random" Tue Jun 29 15:26:26 2010 : Debug: fragment_size = 1024 Tue Jun 29 15:26:26 2010 : Debug: include_length = yes Tue Jun 29 15:26:26 2010 : Debug: check_crl = no Tue Jun 29 15:26:26 2010 : Debug: cipher_list = "DEFAULT" Tue Jun 29 15:26:26 2010 : Debug: cache { Tue Jun 29 15:26:26 2010 : Debug: enable = yes Tue Jun 29 15:26:26 2010 : Debug: lifetime = 24 Tue Jun 29 15:26:26 2010 : Debug: max_entries = 0 Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: Module: Linked to sub-module rlm_eap_ttls Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating eap-ttls Tue Jun 29 15:26:26 2010 : Debug: ttls { Tue Jun 29 15:26:26 2010 : Debug: default_eap_type = "mschapv2" Tue Jun 29 15:26:26 2010 : Debug: copy_request_to_tunnel = no Tue Jun 29 15:26:26 2010 : Debug: use_tunneled_reply = yes Tue Jun 29 15:26:26 2010 : Debug: virtual_server = "inner-tunnel" Tue Jun 29 15:26:26 2010 : Debug: include_length = yes Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: Module: Linked to sub-module rlm_eap_mschapv2 Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating eap-mschapv2 Tue Jun 29 15:26:26 2010 : Debug: mschapv2 { Tue Jun 29 15:26:26 2010 : Debug: with_ntdomain_hack = no Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: Module: Checking authorize {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: Module: Loading virtual module init_wimax Tue Jun 29 15:26:26 2010 : Debug: Module: Loading virtual module verify_wimax_asn Tue Jun 29 15:26:26 2010 : Debug: (Loaded rlm_always, checking if it's valid) Tue Jun 29 15:26:26 2010 : Debug: Module: Linked to module rlm_always Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating reject Tue Jun 29 15:26:26 2010 : Debug: always reject { Tue Jun 29 15:26:26 2010 : Debug: rcode = "reject" Tue Jun 29 15:26:26 2010 : Debug: simulcount = 0 Tue Jun 29 15:26:26 2010 : Debug: mpp = no Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating noop Tue Jun 29 15:26:26 2010 : Debug: always noop { Tue Jun 29 15:26:26 2010 : Debug: rcode = "noop" Tue Jun 29 15:26:26 2010 : Debug: simulcount = 0 Tue Jun 29 15:26:26 2010 : Debug: mpp = no Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: (Loaded rlm_wimax, checking if it's valid) Tue Jun 29 15:26:26 2010 : Debug: Module: Linked to module rlm_wimax Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating wimax Tue Jun 29 15:26:26 2010 : Debug: wimax { Tue Jun 29 15:26:26 2010 : Debug: delete_mppe_keys = yes Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: (Loaded rlm_realm, checking if it's valid) Tue Jun 29 15:26:26 2010 : Debug: Module: Linked to module rlm_realm Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating suffix Tue Jun 29 15:26:26 2010 : Debug: realm suffix { Tue Jun 29 15:26:26 2010 : Debug: format = "suffix" Tue Jun 29 15:26:26 2010 : Debug: delimiter = "@" Tue Jun 29 15:26:26 2010 : Debug: ignore_default = no Tue Jun 29 15:26:26 2010 : Debug: ignore_null = no Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: Module: Checking preacct {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: Module: Checking accounting {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: (Loaded rlm_detail, checking if it's valid) Tue Jun 29 15:26:26 2010 : Debug: Module: Linked to module rlm_detail Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating detail_wimax Tue Jun 29 15:26:26 2010 : Debug: detail detail_wimax { Tue Jun 29 15:26:26 2010 : Debug: detailfile = "/var/log/radius/radacct/wimax/detail-%Y%m%d" Tue Jun 29 15:26:26 2010 : Debug: header = "%t" Tue Jun 29 15:26:26 2010 : Debug: detailperm = 432 Tue Jun 29 15:26:26 2010 : Debug: dirperm = 493 Tue Jun 29 15:26:26 2010 : Debug: locking = no Tue Jun 29 15:26:26 2010 : Debug: log_packet_header = no Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating sqlsession Tue Jun 29 15:26:26 2010 : Debug: sql sqlsession { Tue Jun 29 15:26:26 2010 : Debug: driver = "rlm_sql_mysql" Tue Jun 29 15:26:26 2010 : Debug: server = "172.17.0.150" Tue Jun 29 15:26:26 2010 : Debug: port = "" Tue Jun 29 15:26:26 2010 : Debug: login = "radius" Tue Jun 29 15:26:26 2010 : Debug: password = "blah" Tue Jun 29 15:26:26 2010 : Debug: radius_db = "radius2" Tue Jun 29 15:26:26 2010 : Debug: read_groups = no Tue Jun 29 15:26:26 2010 : Debug: sqltrace = no Tue Jun 29 15:26:26 2010 : Debug: sqltracefile = "/var/log/radius/sqltrace.sql" Tue Jun 29 15:26:26 2010 : Debug: readclients = no Tue Jun 29 15:26:26 2010 : Debug: deletestalesessions = no Tue Jun 29 15:26:26 2010 : Debug: num_sql_socks = 15 Tue Jun 29 15:26:26 2010 : Debug: lifetime = 0 Tue Jun 29 15:26:26 2010 : Debug: max_queries = 0 Tue Jun 29 15:26:26 2010 : Debug: sql_user_name = "%{User-Name}" Tue Jun 29 15:26:26 2010 : Debug: default_user_profile = "" Tue Jun 29 15:26:26 2010 : Debug: nas_query = "SELECT id,nasname,shortname,type,secret FROM nas" Tue Jun 29 15:26:26 2010 : Debug: authorize_check_query = "SELECT id, username, 'WiMAX-hHA-IP-MIP4' as attribute, `hha-ip-address` as value, '==' as op FROM wimax WHERE username = BINARY '%{SQL-User-Name}'" Tue Jun 29 15:26:26 2010 : Debug: authorize_reply_query = "select id, username, 'WiMAX-MN-hHA-MIP4-Key' as attribute, `mn-ha-key` as value, ':=' as op FROM wimax WHERE username = BINARY '%{SQL-User-Name}' AND `mn-ha-key-spi` = %{WiMAX-MN-hHA-MIP4-SPI}" Tue Jun 29 15:26:26 2010 : Debug: authorize_group_check_query = "" Tue Jun 29 15:26:26 2010 : Debug: authorize_group_reply_query = "" Tue Jun 29 15:26:26 2010 : Debug: accounting_onoff_query = "" Tue Jun 29 15:26:26 2010 : Debug: accounting_update_query = "" Tue Jun 29 15:26:26 2010 : Debug: accounting_update_query_alt = "" Tue Jun 29 15:26:26 2010 : Debug: accounting_start_query = "" Tue Jun 29 15:26:26 2010 : Debug: accounting_start_query_alt = "" Tue Jun 29 15:26:26 2010 : Debug: accounting_stop_query = " DELETE FROM wimax WHERE `username` = BINARY '%{SQL-User-Name}' AND `wimax-session-id` = '%{Acct-Multi-Session-Id}'" Tue Jun 29 15:26:26 2010 : Debug: accounting_stop_query_alt = "" Tue Jun 29 15:26:26 2010 : Debug: connect_failure_retry_delay = 60 Tue Jun 29 15:26:26 2010 : Debug: simul_count_query = "" Tue Jun 29 15:26:26 2010 : Debug: simul_verify_query = "" Tue Jun 29 15:26:26 2010 : Debug: postauth_query = "INSERT INTO wimax (`username`, `wimax-session-id`, `calling-station-id`, `nas-id`, `nas-ip-address`, `framed-ip-address`, `mip-rk`, `fa-rk`, `fa-rk-spi`, `mn-ha-key`, `mn-ha-spi`, `hha-ip-address`, `vha-ip-address`, `authdate`, `lifetime` ) VALUES ( '%{SQL-User-Name}', %{reply:WiMAX-AAA-Session-Id}, '%{Calling-Station-Id}', '%{NAS-Identifier}', '%{NAS-IP-Address}', '%{reply:Framed-IP-Address}', NULL, %{%{reply:WiMAX-FA-RK-Key}:-NULL}, %{%{reply:WiMAX-FA-RK-SPI}:-NULL}, %{%{reply:WiMAX-MN-hHA-MIP4-Key}:-%{%{reply:WiMAX-MN-hHA-MIP6-Key}:-NULL}}, %{%{reply:WiMAX-MN-hHA-MIP4-SPI}:-%{%{reply:WiMAX-MN-hHA-MIP6-SPI}:-NULL}}, '%{%{reply:WiMAX-hHA-IP-MIP4}:-%{reply:WiMAX-hHA-IP-MIP6}}', '%{%{reply:WiMAX-vHA-IP-MIP4}:-%{reply:WiMAX-vHA-IP-MIP6}}', '%S', '%{%{reply:Session-Timeout}:-86400}' )" Tue Jun 29 15:26:26 2010 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Attempting to connect to radius@172.17.0.150:/radius2 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlsession): starting 0 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Attempting to connect rlm_sql_mysql #0 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #0 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Connected new DB handle, #0 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlsession): starting 1 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Attempting to connect rlm_sql_mysql #1 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #1 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Connected new DB handle, #1 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlsession): starting 2 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Attempting to connect rlm_sql_mysql #2 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #2 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Connected new DB handle, #2 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlsession): starting 3 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Attempting to connect rlm_sql_mysql #3 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #3 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Connected new DB handle, #3 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlsession): starting 4 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Attempting to connect rlm_sql_mysql #4 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #4 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Connected new DB handle, #4 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlsession): starting 5 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Attempting to connect rlm_sql_mysql #5 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #5 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Connected new DB handle, #5 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlsession): starting 6 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Attempting to connect rlm_sql_mysql #6 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #6 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Connected new DB handle, #6 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlsession): starting 7 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Attempting to connect rlm_sql_mysql #7 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #7 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Connected new DB handle, #7 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlsession): starting 8 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Attempting to connect rlm_sql_mysql #8 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #8 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Connected new DB handle, #8 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlsession): starting 9 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Attempting to connect rlm_sql_mysql #9 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #9 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Connected new DB handle, #9 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlsession): starting 10 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Attempting to connect rlm_sql_mysql #10 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #10 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Connected new DB handle, #10 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlsession): starting 11 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Attempting to connect rlm_sql_mysql #11 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #11 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Connected new DB handle, #11 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlsession): starting 12 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Attempting to connect rlm_sql_mysql #12 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #12 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Connected new DB handle, #12 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlsession): starting 13 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Attempting to connect rlm_sql_mysql #13 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #13 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Connected new DB handle, #13 Tue Jun 29 15:26:26 2010 : Debug: rlm_sql (sqlsession): starting 14 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Attempting to connect rlm_sql_mysql #14 Tue Jun 29 15:26:26 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #14 Tue Jun 29 15:26:26 2010 : Info: rlm_sql (sqlsession): Connected new DB handle, #14 Tue Jun 29 15:26:26 2010 : Debug: (Loaded rlm_attr_filter, checking if it's valid) Tue Jun 29 15:26:26 2010 : Debug: Module: Linked to module rlm_attr_filter Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating attr_filter.accounting_response Tue Jun 29 15:26:26 2010 : Debug: attr_filter attr_filter.accounting_response { Tue Jun 29 15:26:26 2010 : Debug: attrsfile = "/etc/raddb/attrs.accounting_response" Tue Jun 29 15:26:26 2010 : Debug: key = "%{User-Name}" Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: Module: Checking session {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: Module: Checking post-proxy {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: Module: Checking post-auth {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: Module: Loading virtual module negotiate_ip_technology Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating handled Tue Jun 29 15:26:26 2010 : Debug: always handled { Tue Jun 29 15:26:26 2010 : Debug: rcode = "handled" Tue Jun 29 15:26:26 2010 : Debug: simulcount = 0 Tue Jun 29 15:26:26 2010 : Debug: mpp = no Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating attr_filter.access_reject Tue Jun 29 15:26:26 2010 : Debug: attr_filter attr_filter.access_reject { Tue Jun 29 15:26:26 2010 : Debug: attrsfile = "/etc/raddb/attrs.access_reject" Tue Jun 29 15:26:26 2010 : Debug: key = "%{User-Name}" Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: } # modules Tue Jun 29 15:26:26 2010 : Debug: } # server Tue Jun 29 15:26:26 2010 : Debug: server stress { Tue Jun 29 15:26:26 2010 : Debug: modules { Tue Jun 29 15:26:26 2010 : Debug: Module: Checking authenticate {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: Module: Checking authorize {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: Module: Checking post-auth {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: } # modules Tue Jun 29 15:26:26 2010 : Debug: } # server Tue Jun 29 15:26:26 2010 : Debug: server status { Tue Jun 29 15:26:26 2010 : Debug: modules { Tue Jun 29 15:26:26 2010 : Debug: Module: Checking authorize {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating ok Tue Jun 29 15:26:26 2010 : Debug: always ok { Tue Jun 29 15:26:26 2010 : Debug: rcode = "ok" Tue Jun 29 15:26:26 2010 : Debug: simulcount = 0 Tue Jun 29 15:26:26 2010 : Debug: mpp = no Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: } # modules Tue Jun 29 15:26:26 2010 : Debug: } # server Tue Jun 29 15:26:26 2010 : Debug: server originate-coa-wimax { Tue Jun 29 15:26:26 2010 : Debug: modules { Tue Jun 29 15:26:26 2010 : Debug: Module: Checking post-proxy {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating fail Tue Jun 29 15:26:26 2010 : Debug: always fail { Tue Jun 29 15:26:26 2010 : Debug: rcode = "fail" Tue Jun 29 15:26:26 2010 : Debug: simulcount = 0 Tue Jun 29 15:26:26 2010 : Debug: mpp = no Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: } # modules Tue Jun 29 15:26:26 2010 : Debug: } # server Tue Jun 29 15:26:26 2010 : Debug: server buffered-sql-wimax { Tue Jun 29 15:26:26 2010 : Debug: modules { Tue Jun 29 15:26:26 2010 : Debug: Module: Checking preacct {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: Module: Checking accounting {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: } # modules Tue Jun 29 15:26:26 2010 : Debug: } # server Tue Jun 29 15:26:26 2010 : Debug: server inner-tunnel { Tue Jun 29 15:26:26 2010 : Debug: modules { Tue Jun 29 15:26:26 2010 : Debug: Module: Checking authenticate {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: (Loaded rlm_pap, checking if it's valid) Tue Jun 29 15:26:26 2010 : Debug: Module: Linked to module rlm_pap Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating pap Tue Jun 29 15:26:26 2010 : Debug: pap { Tue Jun 29 15:26:26 2010 : Debug: encryption_scheme = "auto" Tue Jun 29 15:26:26 2010 : Debug: auto_header = no Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: (Loaded rlm_chap, checking if it's valid) Tue Jun 29 15:26:26 2010 : Debug: Module: Linked to module rlm_chap Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating chap Tue Jun 29 15:26:26 2010 : Debug: (Loaded rlm_mschap, checking if it's valid) Tue Jun 29 15:26:26 2010 : Debug: Module: Linked to module rlm_mschap Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating mschap Tue Jun 29 15:26:26 2010 : Debug: mschap { Tue Jun 29 15:26:26 2010 : Debug: use_mppe = yes Tue Jun 29 15:26:26 2010 : Debug: require_encryption = no Tue Jun 29 15:26:26 2010 : Debug: require_strong = no Tue Jun 29 15:26:26 2010 : Debug: with_ntdomain_hack = no Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: Module: Checking authorize {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: Module: Checking session {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: Module: Checking post-proxy {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: Module: Checking post-auth {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: } # modules Tue Jun 29 15:26:26 2010 : Debug: } # server Tue Jun 29 15:26:26 2010 : Debug: server { Tue Jun 29 15:26:26 2010 : Debug: modules { Tue Jun 29 15:26:26 2010 : Debug: Module: Checking authenticate {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: Module: Checking authorize {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: Module: Checking preacct {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: Module: Checking accounting {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: Module: Instantiating detail_wisper Tue Jun 29 15:26:26 2010 : Debug: detail detail_wisper { Tue Jun 29 15:26:26 2010 : Debug: detailfile = "/var/log/radius/radacct/wisper/detail-%Y%m%d" Tue Jun 29 15:26:26 2010 : Debug: header = "%t" Tue Jun 29 15:26:26 2010 : Debug: detailperm = 432 Tue Jun 29 15:26:26 2010 : Debug: dirperm = 493 Tue Jun 29 15:26:26 2010 : Debug: locking = no Tue Jun 29 15:26:26 2010 : Debug: log_packet_header = no Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: Module: Checking post-proxy {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: Module: Checking post-auth {...} for more modules to load Tue Jun 29 15:26:26 2010 : Debug: } # modules Tue Jun 29 15:26:26 2010 : Debug: } # server Tue Jun 29 15:26:26 2010 : Debug: radiusd: #### Opening IP addresses and Ports #### Tue Jun 29 15:26:26 2010 : Debug: listen { Tue Jun 29 15:26:26 2010 : Debug: type = "auth" Tue Jun 29 15:26:26 2010 : Debug: ipaddr = * Tue Jun 29 15:26:26 2010 : Debug: port = 0 Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: listen { Tue Jun 29 15:26:26 2010 : Debug: type = "acct" Tue Jun 29 15:26:26 2010 : Debug: ipaddr = * Tue Jun 29 15:26:26 2010 : Debug: port = 0 Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: listen { Tue Jun 29 15:26:26 2010 : Debug: type = "control" Tue Jun 29 15:26:26 2010 : Debug: listen { Tue Jun 29 15:26:26 2010 : Debug: socket = "/var/run/radiusd/radiusd.sock" Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: listen { Tue Jun 29 15:26:26 2010 : Debug: type = "detail" Tue Jun 29 15:26:26 2010 : Debug: listen { Tue Jun 29 15:26:26 2010 : Debug: filename = "/var/log/radius/radacct/wisper/detail-*" Tue Jun 29 15:26:26 2010 : Debug: load_factor = 10 Tue Jun 29 15:26:26 2010 : Debug: poll_interval = 10 Tue Jun 29 15:26:26 2010 : Debug: retry_interval = 30 Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: listen { Tue Jun 29 15:26:26 2010 : Debug: type = "status" Tue Jun 29 15:26:26 2010 : Debug: ipaddr = * Tue Jun 29 15:26:26 2010 : Debug: port = 18120 Tue Jun 29 15:26:26 2010 : Debug: client admin { Tue Jun 29 15:26:26 2010 : Debug: ipaddr = 127.0.0.1 Tue Jun 29 15:26:26 2010 : Debug: require_message_authenticator = no Tue Jun 29 15:26:26 2010 : Debug: secret = "blah" Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: client cacti { Tue Jun 29 15:26:26 2010 : Debug: ipaddr = 172.17.0.138 Tue Jun 29 15:26:26 2010 : Debug: require_message_authenticator = no Tue Jun 29 15:26:26 2010 : Debug: secret = "blah" Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: listen { Tue Jun 29 15:26:26 2010 : Debug: type = "detail" Tue Jun 29 15:26:26 2010 : Debug: listen { Tue Jun 29 15:26:26 2010 : Debug: filename = "/var/log/radius/radacct/wimax/detail-*" Tue Jun 29 15:26:26 2010 : Debug: load_factor = 10 Tue Jun 29 15:26:26 2010 : Debug: poll_interval = 20 Tue Jun 29 15:26:26 2010 : Debug: retry_interval = 30 Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: } Tue Jun 29 15:26:26 2010 : Debug: Listening on authentication address * port 1812 Tue Jun 29 15:26:26 2010 : Debug: Listening on accounting address * port 1813 Tue Jun 29 15:26:26 2010 : Debug: Listening on command file /var/run/radiusd/radiusd.sock Tue Jun 29 15:26:26 2010 : Debug: Listening on detail file /var/log/radius/radacct/wisper/detail-* as server buffered-sql-wisper Tue Jun 29 15:26:26 2010 : Debug: Detail listener /var/log/radius/radacct/wisper/detail-* state unopened signalled 0 waiting 10.000000 sec Tue Jun 29 15:26:26 2010 : Debug: Listening on status address * port 18120 as server status Tue Jun 29 15:26:26 2010 : Debug: Listening on detail file /var/log/radius/radacct/wimax/detail-* as server buffered-sql-wimax Tue Jun 29 15:26:26 2010 : Debug: Detail listener /var/log/radius/radacct/wimax/detail-* state unopened signalled 0 waiting 20.000000 sec Tue Jun 29 15:26:26 2010 : Debug: Listening on proxy address * port 1814 Tue Jun 29 15:26:26 2010 : Debug: Waking up in 9.9 seconds. Tue Jun 29 15:26:36 2010 : Debug: Polling for detail file /var/log/radius/radacct/wisper/detail-* Tue Jun 29 15:26:36 2010 : Debug: Detail listener /var/log/radius/radacct/wisper/detail-* state unopened signalled 0 waiting 10.176255 sec Tue Jun 29 15:26:36 2010 : Debug: Waking up in 9.9 seconds. Tue Jun 29 15:26:46 2010 : Debug: Polling for detail file /var/log/radius/radacct/wimax/detail-* Tue Jun 29 15:26:46 2010 : Debug: Detail listener /var/log/radius/radacct/wimax/detail-* state unopened signalled 0 waiting 19.786953 sec Tue Jun 29 15:26:46 2010 : Debug: Waking up in 0.1 seconds. Tue Jun 29 15:26:46 2010 : Debug: Polling for detail file /var/log/radius/radacct/wisper/detail-* Tue Jun 29 15:26:46 2010 : Debug: Detail listener /var/log/radius/radacct/wisper/detail-* state unopened signalled 0 waiting 9.933326 sec Tue Jun 29 15:26:46 2010 : Debug: Waking up in 9.9 seconds. Tue Jun 29 15:26:56 2010 : Debug: Polling for detail file /var/log/radius/radacct/wisper/detail-* Tue Jun 29 15:26:56 2010 : Debug: Detail listener /var/log/radius/radacct/wisper/detail-* state unopened signalled 0 waiting 9.832270 sec Tue Jun 29 15:26:56 2010 : Debug: Waking up in 9.6 seconds. Tue Jun 29 15:27:06 2010 : Debug: Polling for detail file /var/log/radius/radacct/wimax/detail-* Tue Jun 29 15:27:06 2010 : Debug: Detail listener /var/log/radius/radacct/wimax/detail-* state unopened signalled 0 waiting 20.068690 sec Tue Jun 29 15:27:06 2010 : Debug: Waking up in 0.1 seconds. Tue Jun 29 15:27:06 2010 : Debug: Polling for detail file /var/log/radius/radacct/wisper/detail-* Tue Jun 29 15:27:06 2010 : Debug: Detail listener /var/log/radius/radacct/wisper/detail-* state unopened signalled 0 waiting 9.778881 sec Tue Jun 29 15:27:06 2010 : Debug: Waking up in 9.7 seconds. rad_recv: Accounting-Request packet from host 172.17.2.20 port 6154, id=18, length=293 Acct-Status-Type = Interim-Update User-Name = "90E6A2CE0489B3FC32EBF73572CC92E6(a)test.wisper-wireless.com" NAS-IP-Address = 172.17.2.20 NAS-Port-Type = Wireless-802.16 NAS-Port = 5 NAS-Identifier = "melrose.asn-gw.wisper-wireless.com" WiMAX-NAP-Id = 0x575753 WiMAX-GMT-Timezone-offset = -18000 Calling-Station-Id = "\000&\202O\342\326" WiMAX-BS-Id = 0x000039fefe01 Event-Timestamp = "Aug 19 2009 22:33:29 CDT" Acct-Session-Id = "1A" Acct-Multi-Session-Id = "97be68067743d815f4ddd6d2c18b353a" Framed-IP-Address = 209.237.120.249 WiMAX-hHA-IP-MIP4 = 0.0.0.0 Acct-Session-Time = 240 WiMAX-Active-Time-Duration = 240 Acct-Input-Octets = 0 Acct-Output-Octets = 0 Acct-Input-Packets = 0 Acct-Output-Packets = 0 Tue Jun 29 15:27:09 2010 : Info: server wimax-asn { Tue Jun 29 15:27:09 2010 : Info: +- entering group preacct {...} Tue Jun 29 15:27:09 2010 : Info: ++[preprocess] returns ok Tue Jun 29 15:27:09 2010 : Info: [acct_unique] Hashing 'NAS-Port = 5,Client-IP-Address = 172.17.2.20,NAS-IP-Address = 172.17.2.20,Acct-Session-Id = "1A",User-Name = "90E6A2CE0489B3FC32EBF73572CC92E6(a)test.wisper-wireless.com"' Tue Jun 29 15:27:09 2010 : Info: [acct_unique] Acct-Unique-Session-ID = "deb71f7ac9251cc9". Tue Jun 29 15:27:09 2010 : Info: ++[acct_unique] returns ok Tue Jun 29 15:27:09 2010 : Debug: rlm_wimax: Fixing WiMAX binary Calling-Station-Id to 00-26-82-4f-e2-d6 Tue Jun 29 15:27:09 2010 : Info: ++[wimax] returns ok Tue Jun 29 15:27:09 2010 : Info: +- entering group accounting {...} Tue Jun 29 15:27:09 2010 : Info: [detail_wimax] expand: /var/log/radius/radacct/wimax/detail-%Y%m%d -> /var/log/radius/radacct/wimax/detail-20100629 Tue Jun 29 15:27:09 2010 : Info: [detail_wimax] /var/log/radius/radacct/wimax/detail-%Y%m%d expands to /var/log/radius/radacct/wimax/detail-20100629 Tue Jun 29 15:27:09 2010 : Info: [detail_wimax] expand: %t -> Tue Jun 29 15:27:09 2010 Tue Jun 29 15:27:09 2010 : Info: ++[detail_wimax] returns ok Tue Jun 29 15:27:09 2010 : Info: ++? if (Acct-Status-Type == Interim-Update) Tue Jun 29 15:27:09 2010 : Info: ? Evaluating (Acct-Status-Type == Interim-Update) -> TRUE Tue Jun 29 15:27:09 2010 : Info: ++? if (Acct-Status-Type == Interim-Update) -> TRUE Tue Jun 29 15:27:09 2010 : Info: ++- entering if (Acct-Status-Type == Interim-Update) {...} Tue Jun 29 15:27:09 2010 : Info: expand: %{User-Name} -> 90E6A2CE0489B3FC32EBF73572CC92E6(a)test.wisper-wireless.com Tue Jun 29 15:27:09 2010 : Info: expand: %{Calling-Station-Id} -> 00-26-82-4f-e2-d6 Tue Jun 29 15:27:09 2010 : Info: +++[disconnect] returns ok Tue Jun 29 15:27:09 2010 : Info: ++- if (Acct-Status-Type == Interim-Update) returns ok Tue Jun 29 15:27:09 2010 : Info: ++? if ((Acct-Status-Type == Stop) && (WiMAX-Session-Continue == False)) Tue Jun 29 15:27:09 2010 : Info: ?? Evaluating (Acct-Status-Type == Stop) -> FALSE Tue Jun 29 15:27:09 2010 : Info: ?? Skipping (WiMAX-Session-Continue == False) Tue Jun 29 15:27:09 2010 : Info: ++? if ((Acct-Status-Type == Stop) && (WiMAX-Session-Continue == False)) -> FALSE Tue Jun 29 15:27:09 2010 : Info: [attr_filter.accounting_response] expand: %{User-Name} -> 90E6A2CE0489B3FC32EBF73572CC92E6(a)test.wisper-wireless.com Tue Jun 29 15:27:09 2010 : Debug: attr_filter: Matched entry DEFAULT at line 12 Tue Jun 29 15:27:09 2010 : Info: ++[attr_filter.accounting_response] returns updated Tue Jun 29 15:27:09 2010 : Info: } # server wimax-asn Sending Accounting-Response of id 18 to 172.17.2.20 port 6154 Tue Jun 29 15:27:09 2010 : Info: server originate-coa-wimax { Tue Jun 29 15:27:09 2010 : Info: WARNING: Empty pre-proxy section. Using default return values. Tue Jun 29 15:27:09 2010 : Info: } Sending Disconnect-Request of id 203 to 172.17.2.20 port 3799 User-Name = "90E6A2CE0489B3FC32EBF73572CC92E6(a)test.wisper-wireless.com" Calling-Station-Id = "00-26-82-4f-e2-d6" WiMAX-AAA-Session-Id = 0x626c6168626c6168626c6168 WiMAX-DM-Action-Code = Deregister-MS Tue Jun 29 15:27:09 2010 : Info: Finished request 0. Tue Jun 29 15:27:09 2010 : Info: Cleaning up request 0 ID 18 with timestamp +43 Tue Jun 29 15:27:09 2010 : Debug: Going to the next request Tue Jun 29 15:27:09 2010 : Debug: Waking up in 2.2 seconds. rad_recv: Disconnect-NAK packet from host 172.17.2.20 port 3799, id=203, length=32 Event-Timestamp = "Aug 19 2009 22:33:29 CDT" Error-Cause = Session-Context-Not-Found Tue Jun 29 15:27:09 2010 : Info: server originate-coa-wimax { Tue Jun 29 15:27:09 2010 : Info: +- entering group post-proxy {...} Tue Jun 29 15:27:09 2010 : Info: expand: %{proxy-reply:Response-Packet-Type} -> Tue Jun 29 15:27:09 2010 : Info: expand: %{proxy-request:Response-Packet-Type} -> Tue Jun 29 15:27:09 2010 : Info: expand: %{request:Response-Packet-Type} -> Tue Jun 29 15:27:09 2010 : Info: expand: %{reply:Response-Packet-Type} -> Tue Jun 29 15:27:09 2010 : Info: expand: %{proxy-reply:Packet-Type} -> Disconnect-NAK Tue Jun 29 15:27:09 2010 : Info: expand: %{proxy-request:Packet-Type} -> Disconnect-Request Tue Jun 29 15:27:09 2010 : Info: expand: %{request:Packet-Type} -> Accounting-Request Tue Jun 29 15:27:09 2010 : Info: expand: %{reply:Packet-Type} -> Accounting-Response Tue Jun 29 15:27:09 2010 : Info: expand: %{Packet-Type} -> Accounting-Request Tue Jun 29 15:27:09 2010 : Info: ++[request] returns noop Tue Jun 29 15:27:09 2010 : Info: expand: %{proxy-reply:Packet-Type} -> Disconnect-NAK Tue Jun 29 15:27:09 2010 : Info: ++- entering switch %{proxy-reply:Packet-Type} {...} Tue Jun 29 15:27:09 2010 : Info: +++- entering case Disconnect-NAK {...} Tue Jun 29 15:27:09 2010 : Info: expand: %{proxy-reply:Error-Cause} -> Session-Context-Not-Found Tue Jun 29 15:27:09 2010 : Info: ++++[request] returns noop Tue Jun 29 15:27:09 2010 : Info: ++++[ok] returns ok Tue Jun 29 15:27:09 2010 : Info: +++- case Disconnect-NAK returns ok Tue Jun 29 15:27:09 2010 : Info: ++- switch %{proxy-reply:Packet-Type} returns ok Tue Jun 29 15:27:09 2010 : Info: } Tue Jun 29 15:27:09 2010 : Info: server wimax-asn { Tue Jun 29 15:27:09 2010 : Info: } # server wimax-asn Tue Jun 29 15:27:09 2010 : Info: Finished request 0. Tue Jun 29 15:27:09 2010 : Debug: Going to the next request Tue Jun 29 15:27:09 2010 : Debug: Waking up in 7.3 seconds. Ben

2 2

FreeRadius + AD + Realms
by Matthew P 30 Jun '10

30 Jun '10

Hello everyone! I'm new to FreeRadius, so please bear with me. :) Goal: Make FreeRadius look-up a user in ActiveDirectory if he has "mydomain.com" domain. Used method: EAP/TTLS (PAP in the tunnel) This is how I've done it, but it doesn't give the wanted results, so please explain a bit. :) (it doesn't seem to load the local_ad virtual server configuration, which is I placed in the sites-enabled directory, it seems to just carry on executing the default server) parts from proxy.conf: proxy server { default_fallback = no } home_server localhost_ad { type = auth virtual_server = local_ad } home_server_pool active_directory { type = fail-over virtual_server = local_ad home_server = localhost_ad } realm mydomain.com { auth_pool = active_directory } And the output: rad_recv: Access-Request packet from host 192.168.0.101 port 1812, id=8, length=138 NAS-IP-Address = 192.168.0.101 NAS-Port-Type = Async User-Name = "user(a)mydomain.com" Service-Type = Framed-User Framed-MTU = 1500 Calling-Station-Id = "00-11-22-33-44-55" EAP-Message = 0x0200001d016a73691d756e646363406c73732d6e65542e6c73732e6872 Message-Authenticator = 0x10017179767a5ab6718168e8399c8993 +- entering group authorize ++[preprocess] returns ok rlm_realm: Looking up realm "mydomain.com" for User-Name = "user(a)mydomain.com" rlm_realm: Found realm "mydomain.com" rlm_realm: Adding Stripped-User-Name = "user" rlm_realm: Adding Realm = "mydomain.com" rlm_realm: Proxying request from user user to realm mydomain.com rlm_realm: Preparing to proxy authentication request to realm "mydomain.com" ++[suffix] returns updated rlm_eap: Request is supposed to be proxied to Realm mydomain.com. Not doing EAP. ++[eap] returns noop ++[files] returns noop ++[expiration] returns noop ++[logintime] returns noop ++[pap] returns noop There was no response configured: rejecting request 0 Found Post-Auth-Type Reject +- entering group REJECT expand: %{User-Name} -> user(a)mydomain.com attr_filter: Matched entry DEFAULT at line 11 ++[attr_filter.access_reject] returns updated Delaying reject of request 0 for 1 seconds Going to the next request Thanks in advance! _________________________________________________________________ Hotmail: Trusted email with powerful SPAM protection. https://signup.live.com/signup.aspx?id=60969

2 1

Netmask HowTo
by loki 30 Jun '10

30 Jun '10

Greets, I have the following setup: freeradius 2.0.5 with sqlippool. Now my question: How can I setup radius to get it's netmask from sqlippool based on the pool name. For instance. I have two pools named pool1 and pool2 in mysql. Now on pool1 I want to have the netmask 255.255.255.128 and on pool2 I want to have netmask 255.255.255.0. How do I achieve that? I have tried the net and some trial and error runs, but got mostly errors. :-) THX in advance... __________ Information from ESET Mail Security, version of virus signature database 5238 (20100629) __________ The message was checked by ESET Mail Security. http://www.eset.com

1 0

Re: Expanding Suffix or Realm attributes
by Rob Turner 30 Jun '10

30 Jun '10

----- Original Message ----- > From: "Rob Turner" <rob(a)crosscut.org> > To: freeradius-users(a)lists.freeradius.org > Sent: Tuesday, June 29, 2010 9:55:57 PM > Subject: Expanding Suffix or Realm attributes > Problem: Cannot expand %{Realm} or %{Suffix} control attributes for > use unless realm is explicitly defined in proxy.conf > > I'm using freeradius2-2.1.7-7.el5 with ldap module. I would like to > perform an ldap dip to get the radiusProxyToRealm attribute for each > request based on Suffix as configured in modules/ldap: > > filter = "(radiusRealm=%{Suffix})" > > NOTE: If using <filter = "(radiusRealm=domain.com)"> in modules/ldap, > radiusProxyToRealm is returned successfully and things work as > expected. In this case the Proxy-To-Realm (which is mapped in > ldap.attrmap) is set in ldap to proxy.com and proxy.com is defined in > proxy.conf. > > Output from radiusd -X: > ... [suffix] Looking up realm "domain.com" for User-Name = > "test(a)domain.com" [suffix] No such realm "domain.com" > ++[suffix] returns noop > ++[files] returns noop > [ldap] performing user authorization for test(a)domain.com > [ldap] expand: (radiusRealm=%{Suffix}) -> (radiusRealm=) > ... > > After reading man unlang, I have also attempted (without success) to > expand using the following in ldap filter: > > %{control:Realm} > %{control:Suffix} %{suffix:User-Name} > %{realm:User-Name} > > Finally, after revisiting man rlm_realm, I read the following which is > of concern as I don't see any other way to utilize the > radiusProxyToRealm attribute in ldap: > > "In either case, a Realm attribute is created and added to the packet > on a match, which can be used by other modules." > > Is there currently anyway to always match (regardless if the realm is > defined in proxy.conf) in order to create a Stripped-User-Name and > Realm run-time variable with every request? > > Regards, > > Rob > > - > List info/subscribe/unsubscribe? See > http://www.freeradius.org/list/users.html Also, I've tried to use a regex realm such as realm "~.*\\.*\\.*$" { ignore_default = yes nostrip } Output from radiusd -X: ... [suffix] Looking up realm "domain.com" for User-Name = "test(a)domain.com" [suffix] Found realm "~.*\.*\.*$" [suffix] Adding Realm = "~.*\.*\.*$" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok ++[files] returns noop [ldap] performing user authorization for test(a)domain.com [ldap] expand: (radiusRealm=%{Realm}) -> (radiusRealm=~.\2a\5c.\2a\5c.\2a$) ... The regex realm would work if I could use the Suffix or Realm attribute from something like the check or control list rather than "~.\2a\5c.\2a\5c.\2a$" Thanks, Rob

2 1

Expanding Suffix or Realm attributes
by Rob Turner 30 Jun '10

30 Jun '10

Problem: Cannot expand %{Realm} or %{Suffix} control attributes for use unless realm is explicitly defined in proxy.conf I'm using freeradius2-2.1.7-7.el5 with ldap module. I would like to perform an ldap dip to get the radiusProxyToRealm attribute for each request based on Suffix as configured in modules/ldap: filter = "(radiusRealm=%{Suffix})" NOTE: If using <filter = "(radiusRealm=domain.com)"> in modules/ldap, radiusProxyToRealm is returned successfully and things work as expected. In this case the Proxy-To-Realm (which is mapped in ldap.attrmap) is set in ldap to proxy.com and proxy.com is defined in proxy.conf. Output from radiusd -X: ... [suffix] Looking up realm "domain.com" for User-Name = "test(a)domain.com" [suffix] No such realm "domain.com" ++[suffix] returns noop ++[files] returns noop [ldap] performing user authorization for test(a)domain.com [ldap] expand: (radiusRealm=%{Suffix}) -> (radiusRealm=) ... After reading man unlang, I have also attempted (without success) to expand using the following in ldap filter: %{control:Realm} %{control:Suffix} %{suffix:User-Name} %{realm:User-Name} Finally, after revisiting man rlm_realm, I read the following which is of concern as I don't see any other way to utilize the radiusProxyToRealm attribute in ldap: "In either case, a Realm attribute is created and added to the packet on a match, which can be used by other modules." Is there currently anyway to always match (regardless if the realm is defined in proxy.conf) in order to create a Stripped-User-Name and Realm run-time variable with every request? Regards, Rob

2 1

"Fast reconnect"
by Bob Franklin 29 Jun '10

29 Jun '10

Hello, I'm a bit hazy on "fast reconnect" -- from what I've ready in the list archives and found on various other sites, it uses cached information about the state of the TLS dialogue with the server terminating the EAP connection to reduce the number of messages which must be exchanged as a supplicant authenticates when moving (say) wireless access point. Looking at the FreeRADIUS changes, history it seems support for this was added in 2.1.1 for EAP-TLS (which I assume affects EAP-PEAP and EAP-TTLS, both of which we're using). Would I be right in thinking that, if the cached state is NOT found on the backend RADIUS server (there may be one or more proxies in the way, especially if the user is logging in over eduroam, but I assume that that doesn't matter, as they just proxy things through) that the device authenticating will just start the TLS negotiation from scratch and the user won't notice anything, except maybe a slightly longer time to roam between wireless access points (but, in practice, probably so quick, they won't)? This would also presumably be the case if the next authentication happened to take place against a different backend server at our eduroam 'home' site as there is no way to synchronise these caches. In other words, the only reason to untick the 'Fast reconnect' box on (for example) a Windows machine would be if there was a suspicion that this was either broken, or you wanted to force the full TLS negotiation to restart, as the user moved access points. [Does anyone know of a broken wireless NAS which complains if the full TLS conversation doesn't start from scratch, as you move around.] I'm just trying to see if there's a reason why anyone should NOT tick this box on a supplicant device. We're running FreeRADIUS >2.1.1. Thanks in advance, - Bob -- Bob Franklin <rcf34(a)cam.ac.uk> +44 1223 748479 Network Division, University of Cambridge Computing Service

2 1

FR 2.1.8 Issue - Unjustified(?) Access-Rejects.
by Palmer J.D.F. 29 Jun '10

29 Jun '10

Hi, We migrated to 2.1.8 (from 2.1.7) last week while things were quiet, as the users have re-appeared after the holiday we've started to receive a few reports from users stating that they have been getting lots of prompts for credentials. Two users in particular, both Ubuntu users, have been having big problems. I had a look at the radpostauth table and sure enough at least 50% of their auth attempts have resulted in access-rejects. I rolled back to 2.1.7 this afternoon and the problem has gone away. Should anyone be interested I have attached an radmin output for one of the users, it shows some accepts and lots of rejects. Is this likely to be a configuration error (no changes were made to the 2.1.7 config), or a bug? Thanks, Jezz Palmer.

7 16

How to use Freeradius with traffic limit?
by RaidenII 29 Jun '10

29 Jun '10

Hi, I'm running Freeradius 2.1+Postgresql 8.4.4+OpenVPN on Ubuntu 9.10 x86. It runs smoothly now, however, I want to know that if there is any way to limit per user's traffic, like 10G/month, and disconnect/reject their connection when the limitation has reached. It seems the the column AcctInputOctets and AcctOutputOctets is responsible for traffic calculation, how should I limit user's traffic by using these two? Thanks in advance. -- View this message in context: http://old.nabble.com/How-to-use-Freeradius-with-traffic-limit--tp28809968p… Sent from the FreeRadius - User mailing list archive at Nabble.com.

4 11

users rights seperations
by Ömer Tuğrul 29 Jun '10

29 Jun '10

Hi, my freeradius version is 2.1.4 I have network devices that I authenticate the network managers to console these devices with radius server based on users file. Now I need to use 802.1x authentication for wireless APs based on ldap authentication. My question is; How can I seperate network management authentication and internet access authentication rights? I mean, I don't want that some ldap users to console my network devices. I just want to allow them to authenticate internet access and some ldap users may console to devices. firstly, I heard that i could use clients.conf file with virtual-server parameter (and sites-enabled/virtual_server_ name...); but then I could only use the authenticator-device for one method if I got it right. I am confused there. I am sorry if i am not clear, please let me know...

2 1