I will be glad, if anyone can direct me to whare The log below is the part of the debug for the new test freeradius server 2.1.6 am testing with. However, the hotspotlogin,cgi is able to pass the param username to the radius but when the query is run against the database the "Tue Jun 9 14:59:48 2009 : Info: [sql] expand: %{User-Name} -> 0x32333435363738393031" the value of the username sent is changed. I have disabled the chap in the /usr/local/etc/raddb/sites-enabled/default. kindly advise on what to do. ################### my radcheck has the info below. mysql> select * from radcheck; +-----+------------+--------------------+----+------------+ | id | username | attribute | op | value | +-----+------------+--------------------+----+------------+ | 5 | 2345678901 | Auth-Type | := | Accept | | 201 | 1234567890 | Cleartext-Password | := | 1234567890 | +-----+------------+--------------------+----+------------+ 4 rows in set (0.00 sec) ######################radiusd -XX (part of the debug) rad_recv: Access-Request packet from host 127.0.0.1 port 44600, id=0, length=189 ChilliSpot-Max-Input-Octets = 0x32333435363738393031 ChilliSpot-Max-Output-Octets = 0 NAS-IP-Address = 127.0.0.1 Service-Type = Login-User Framed-IP-Address = 192.168.182.2 Calling-Station-Id = "00-1F-29-80-62-F3" Called-Station-Id = "00-50-DA-0C-C9-B0" NAS-Identifier = "nas01" Acct-Session-Id = "4a2e6a7700000000" NAS-Port-Type = Wireless-802.11 NAS-Port = 0 Message-Authenticator = 0xf2ee6add34820fb96dcceef08c07bbc5 WISPr-Logoff-URL = "http://192.168.182.1:3990/logoff" Tue Jun 9 14:59:48 2009 : Info: +- entering group authorize {...} Tue Jun 9 14:59:48 2009 : Info: ++[preprocess] returns ok Tue Jun 9 14:59:48 2009 : Info: ++[mschap] returns noop Tue Jun 9 14:59:48 2009 : Info: [suffix] No '@' in User-Name = "2345678901", looking up realm NULL Tue Jun 9 14:59:48 2009 : Info: [suffix] No such realm "NULL" Tue Jun 9 14:59:48 2009 : Info: ++[suffix] returns noop Tue Jun 9 14:59:48 2009 : Info: [eap] No EAP-Message, not doing EAP Tue Jun 9 14:59:48 2009 : Info: ++[eap] returns noop Tue Jun 9 14:59:48 2009 : Info: ++[unix] returns notfound Tue Jun 9 14:59:48 2009 : Info: ++[files] returns noop Tue Jun 9 14:59:48 2009 : Info: [sql] expand: %{User-Name} -> 0x32333435363738393031 Tue Jun 9 14:59:48 2009 : Info: [sql] sql_set_user escaped user --> '0x32333435363738393031' Tue Jun 9 14:59:48 2009 : Debug: rlm_sql (sql): Reserving sql socket id: 4 Tue Jun 9 14:59:48 2009 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = '0x32333435363738393031' ORDER BY id Tue Jun 9 14:59:48 2009 : Info: [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '0x32333435363738393031' ORDER BY priority Tue Jun 9 14:59:48 2009 : Debug: rlm_sql (sql): Released sql socket id: 4 Tue Jun 9 14:59:48 2009 : Info: [sql] User 0x32333435363738393031 not found Tue Jun 9 14:59:48 2009 : Info: ++[sql] returns notfound Tue Jun 9 14:59:48 2009 : Info: ++[expiration] returns noop Tue Jun 9 14:59:48 2009 : Info: ++[logintime] returns noop Tue Jun 9 14:59:48 2009 : Info: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. Tue Jun 9 14:59:48 2009 : Info: ++[pap] returns noop Tue Jun 9 14:59:48 2009 : Debug: rlm_sqlcounter: Entering module authorize code Tue Jun 9 14:59:48 2009 : Debug: rlm_sqlcounter: Could not find Check item value pair Tue Jun 9 14:59:48 2009 : Info: ++[validity] returns noop Tue Jun 9 14:59:48 2009 : Debug: rlm_sqlcounter: Entering module authorize code Tue Jun 9 14:59:48 2009 : Debug: rlm_sqlcounter: Could not find Check item value pair Tue Jun 9 14:59:48 2009 : Info: ++[noresetcounter] returns noop Tue Jun 9 14:59:48 2009 : Debug: rlm_sqlcounter: Entering module authorize code Tue Jun 9 14:59:48 2009 : Debug: rlm_sqlcounter: Could not find Check item value pair Tue Jun 9 14:59:48 2009 : Info: ++[hotspotcontrol] returns noop Tue Jun 9 14:59:48 2009 : Info: No authenticate method (Auth-Type) configuration found for the request: Rejecting the user Tue Jun 9 14:59:48 2009 : Info: Failed to authenticate the user. Tue Jun 9 14:59:48 2009 : Info: Using Post-Auth-Type Reject Tue Jun 9 14:59:48 2009 : Info: +- entering group REJECT {...} Tue Jun 9 14:59:48 2009 : Info: [attr_filter.access_reject] expand: %{User-Name} -> 0x32333435363738393031 Tue Jun 9 14:59:48 2009 : Debug: attr_filter: Matched entry DEFAULT at line 11 Tue Jun 9 14:59:48 2009 : Info: ++[attr_filter.access_reject] returns updated Tue Jun 9 14:59:48 2009 : Info: Delaying reject of request 0 for 1 seconds Tue Jun 9 14:59:48 2009 : Debug: Going to the next request Tue Jun 9 14:59:48 2009 : Debug: Waking up in 0.9 seconds. Tue Jun 9 14:59:49 2009 : Info: Sending delayed reject for request 0 Sending Access-Reject of id 0 to 127.0.0.1 port 44600 Tue Jun 9 14:59:49 2009 : Debug: Waking up in 4.9 seconds. Tue Jun 9 14:59:54 2009 : Info: Cleaning up request 0 ID 0 with timestamp +187 Tue Jun 9 14:59:54 2009 : Debug: Ready to process requests.
Goke Aruna wrote:
I will be glad, if anyone can direct me to whare The log below is the part of the debug for the new test freeradius server 2.1.6 am testing with.
However, the hotspotlogin,cgi is able to pass the param username to the radius
It's not in the debug log below.
rad_recv: Access-Request packet from host 127.0.0.1 port 44600, id=0, length=189
... there's no User-Name attribute. The packet violates the RADIUS specifications. Yet, somehow, magically:
Tue Jun 9 14:59:48 2009 : Info: [suffix] No '@' in User-Name = "2345678901", looking up realm NULL
There's a User-Name in the packet! How did that happen?
Tue Jun 9 14:59:48 2009 : Info: [sql] expand: %{User-Name} -> 0x32333435363738393031
And now the User-Name is different! You've managed to copy the Chillispot-Max-Input-Octets into the User-Name. Why? It looks like you've edited the dictionaries without knowing what you're doing. Don't do that. Alan DeKok.
Alan DeKok wrote:
Goke Aruna wrote:
I will be glad, if anyone can direct me to whare The log below is the part of the debug for the new test freeradius server 2.1.6 am testing with.
However, the hotspotlogin,cgi is able to pass the param username to the radius
It's not in the debug log below.
rad_recv: Access-Request packet from host 127.0.0.1 port 44600, id=0, length=189
... there's no User-Name attribute. The packet violates the RADIUS specifications. Yet, somehow, magically:
Tue Jun 9 14:59:48 2009 : Info: [suffix] No '@' in User-Name = "2345678901", looking up realm NULL
There's a User-Name in the packet! How did that happen?
Tue Jun 9 14:59:48 2009 : Info: [sql] expand: %{User-Name} -> 0x32333435363738393031
And now the User-Name is different!
You've managed to copy the Chillispot-Max-Input-Octets into the User-Name. Why?
It looks like you've edited the dictionaries without knowing what you're doing. Don't do that.
Alan DeKok.
Thanks Alan, The attached is the full debug, however, i have similar config done on 2.0.5 and its working. the parameter send by the UAM portal was actually the ${User-Name} not the Chillispot-Max-Input-Octets. bcos of that now I will unload the dictionary.chillispot to test again and revert. on the dictionary, I only added the attributes ==== # $INCLUDE /usr/local/share/freeradius/dictionary $INCLUDE /usr/local/etc/raddb/dictionary.chillispot # # Place additional attributes or $INCLUDEs here. They will # over-ride the definitions in the pre-defined dictionaries. # # See the 'man' page for 'dictionary' for information on # the format of the dictionary files. # # If you want to add entries to the dictionary file, # which are NOT going to be placed in a RADIUS packet, # add them here. The numbers you pick should be between # 3000 and 4000. # #ATTRIBUTE My-Local-String 3000 string #ATTRIBUTE My-Local-IPAddr 3001 ipaddr #ATTRIBUTE My-Local-Integer 3002 integer ATTRIBUTE Max-Secs-Usable 3000 integer ATTRIBUTE Max-Secs-Passed 3001 integer ======= Goksie {\rtf1\ansi\ansicpg1252\deff0\deflang1033{\fonttbl{\f0\fswiss\fcharset0 Arial;}} {\*\generator Msftedit 5.41.21.2508;}\viewkind4\uc1\pard\f0\fs20 [root@Etal raddb]# radiusd -XX\par Tue Jun 9 14:56:41 2009 : Info: FreeRADIUS Version 2.1.6, for host i686-pc-linux-gnu, built on May 22 2009 at 21:12:11\par Tue Jun 9 14:56:41 2009 : Info: Copyright (C) 1999-2009 The FreeRADIUS server project and contributors.\par Tue Jun 9 14:56:41 2009 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A\par Tue Jun 9 14:56:41 2009 : Info: PARTICULAR PURPOSE.\par Tue Jun 9 14:56:41 2009 : Info: You may redistribute copies of FreeRADIUS under the terms of the\par Tue Jun 9 14:56:41 2009 : Info: GNU General Public License v2.\par Tue Jun 9 14:56:41 2009 : Info: Starting - reading configuration files ...\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/radiusd.conf\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/proxy.conf\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/clients.conf\par Tue Jun 9 14:56:41 2009 : Debug: including files in directory /usr/local/etc/raddb/modules/\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/detail.example.com\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/pap\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/detail\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/files\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/preprocess\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/perl\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/inner-eap\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/expiration\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/expr\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/ldap\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/radutmp\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/smsotp\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/logintime\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/wimax\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/counter\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/sql/mysql/counter.conf\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/attr_filter\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/smbpasswd\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/mac2ip\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/realm\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/unix\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/exec\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/pam\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/etc_group\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/linelog\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/attr_rewrite\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/chap\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/passwd\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/krb5\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/ippool\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/always\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/digest\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/otp\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/mschap\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/acct_unique\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/policy\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/sql_log\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/sqlcounter_expire_on_login\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/detail.log\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/checkval\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/mac2vlan\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/echo\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/modules/sradutmp\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/eap.conf\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/sql.conf\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/sql/mysql/dialup.conf\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/policy.conf\par Tue Jun 9 14:56:41 2009 : Debug: including files in directory /usr/local/etc/raddb/sites-enabled/\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/inner-tunnel\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/default\par Tue Jun 9 14:56:41 2009 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/control-socket\par Tue Jun 9 14:56:41 2009 : Debug: including dictionary file /usr/local/etc/raddb/dictionary\par Tue Jun 9 14:56:41 2009 : Debug: main \{\par Tue Jun 9 14:56:41 2009 : Debug: prefix = "/usr/local"\par Tue Jun 9 14:56:41 2009 : Debug: localstatedir = "/usr/local/var"\par Tue Jun 9 14:56:41 2009 : Debug: logdir = "/usr/local/var/log/radius"\par Tue Jun 9 14:56:41 2009 : Debug: libdir = "/usr/local/lib"\par Tue Jun 9 14:56:41 2009 : Debug: radacctdir = "/usr/local/var/log/radius/radacct"\par Tue Jun 9 14:56:41 2009 : Debug: hostname_lookups = no\par Tue Jun 9 14:56:41 2009 : Debug: max_request_time = 30\par Tue Jun 9 14:56:41 2009 : Debug: cleanup_delay = 5\par Tue Jun 9 14:56:41 2009 : Debug: max_requests = 1024\par Tue Jun 9 14:56:41 2009 : Debug: allow_core_dumps = no\par Tue Jun 9 14:56:41 2009 : Debug: pidfile = "/usr/local/var/run/radiusd/radiusd.pid"\par Tue Jun 9 14:56:41 2009 : Debug: checkrad = "/usr/local/sbin/checkrad"\par Tue Jun 9 14:56:41 2009 : Debug: debug_level = 0\par Tue Jun 9 14:56:41 2009 : Debug: proxy_requests = yes\par Tue Jun 9 14:56:41 2009 : Debug: log \{\par Tue Jun 9 14:56:41 2009 : Debug: stripped_names = no\par Tue Jun 9 14:56:41 2009 : Debug: auth = no\par Tue Jun 9 14:56:41 2009 : Debug: auth_badpass = no\par Tue Jun 9 14:56:41 2009 : Debug: auth_goodpass = no\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: security \{\par Tue Jun 9 14:56:41 2009 : Debug: max_attributes = 200\par Tue Jun 9 14:56:41 2009 : Debug: reject_delay = 1\par Tue Jun 9 14:56:41 2009 : Debug: status_server = yes\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: radiusd: #### Loading Realms and Home Servers ####\par Tue Jun 9 14:56:41 2009 : Debug: proxy server \{\par Tue Jun 9 14:56:41 2009 : Debug: retry_delay = 5\par Tue Jun 9 14:56:41 2009 : Debug: retry_count = 3\par Tue Jun 9 14:56:41 2009 : Debug: default_fallback = no\par Tue Jun 9 14:56:41 2009 : Debug: dead_time = 120\par Tue Jun 9 14:56:41 2009 : Debug: wake_all_if_all_dead = no\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: home_server localhost \{\par Tue Jun 9 14:56:41 2009 : Debug: ipaddr = 127.0.0.1\par Tue Jun 9 14:56:41 2009 : Debug: port = 1812\par Tue Jun 9 14:56:41 2009 : Debug: type = "auth"\par Tue Jun 9 14:56:41 2009 : Debug: secret = "testing123"\par Tue Jun 9 14:56:41 2009 : Debug: response_window = 20\par Tue Jun 9 14:56:41 2009 : Debug: max_outstanding = 65536\par Tue Jun 9 14:56:41 2009 : Debug: require_message_authenticator = no\par Tue Jun 9 14:56:41 2009 : Debug: zombie_period = 40\par Tue Jun 9 14:56:41 2009 : Debug: status_check = "status-server"\par Tue Jun 9 14:56:41 2009 : Debug: ping_interval = 30\par Tue Jun 9 14:56:41 2009 : Debug: check_interval = 30\par Tue Jun 9 14:56:41 2009 : Debug: num_answers_to_alive = 3\par Tue Jun 9 14:56:41 2009 : Debug: num_pings_to_alive = 3\par Tue Jun 9 14:56:41 2009 : Debug: revive_interval = 120\par Tue Jun 9 14:56:41 2009 : Debug: status_check_timeout = 4\par Tue Jun 9 14:56:41 2009 : Debug: irt = 2\par Tue Jun 9 14:56:41 2009 : Debug: mrt = 16\par Tue Jun 9 14:56:41 2009 : Debug: mrc = 5\par Tue Jun 9 14:56:41 2009 : Debug: mrd = 30\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: home_server_pool my_auth_failover \{\par Tue Jun 9 14:56:41 2009 : Debug: type = fail-over\par Tue Jun 9 14:56:41 2009 : Debug: home_server = localhost\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: realm example.com \{\par Tue Jun 9 14:56:41 2009 : Debug: auth_pool = my_auth_failover\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: realm LOCAL \{\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: radiusd: #### Loading Clients ####\par Tue Jun 9 14:56:41 2009 : Debug: client localhost \{\par Tue Jun 9 14:56:41 2009 : Debug: ipaddr = 127.0.0.1\par Tue Jun 9 14:56:41 2009 : Debug: require_message_authenticator = no\par Tue Jun 9 14:56:41 2009 : Debug: secret = "testing123"\par Tue Jun 9 14:56:41 2009 : Debug: nastype = "other"\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: radiusd: #### Instantiating modules ####\par Tue Jun 9 14:56:41 2009 : Debug: instantiate \{\par Tue Jun 9 14:56:41 2009 : Debug: (Loaded rlm_exec, checking if it's valid)\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to module rlm_exec\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating exec\par Tue Jun 9 14:56:41 2009 : Debug: exec \{\par Tue Jun 9 14:56:41 2009 : Debug: wait = no\par Tue Jun 9 14:56:41 2009 : Debug: input_pairs = "request"\par Tue Jun 9 14:56:41 2009 : Debug: shell_escape = yes\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: (Loaded rlm_expr, checking if it's valid)\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to module rlm_expr\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating expr\par Tue Jun 9 14:56:41 2009 : Debug: (Loaded rlm_expiration, checking if it's valid)\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to module rlm_expiration\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating expiration\par Tue Jun 9 14:56:41 2009 : Debug: expiration \{\par Tue Jun 9 14:56:41 2009 : Debug: reply-message = "Password Has Expired "\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: (Loaded rlm_logintime, checking if it's valid)\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to module rlm_logintime\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating logintime\par Tue Jun 9 14:56:41 2009 : Debug: logintime \{\par Tue Jun 9 14:56:41 2009 : Debug: reply-message = "You are calling outside your allowed timespan "\par Tue Jun 9 14:56:41 2009 : Debug: minimum-timeout = 60\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: radiusd: #### Loading Virtual Servers ####\par Tue Jun 9 14:56:41 2009 : Debug: server inner-tunnel \{\par Tue Jun 9 14:56:41 2009 : Debug: modules \{\par Tue Jun 9 14:56:41 2009 : Debug: Module: Checking authenticate \{...\} for more modules to load\par Tue Jun 9 14:56:41 2009 : Debug: (Loaded rlm_pap, checking if it's valid)\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to module rlm_pap\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating pap\par Tue Jun 9 14:56:41 2009 : Debug: pap \{\par Tue Jun 9 14:56:41 2009 : Debug: encryption_scheme = "auto"\par Tue Jun 9 14:56:41 2009 : Debug: auto_header = no\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: (Loaded rlm_chap, checking if it's valid)\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to module rlm_chap\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating chap\par Tue Jun 9 14:56:41 2009 : Debug: (Loaded rlm_mschap, checking if it's valid)\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to module rlm_mschap\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating mschap\par Tue Jun 9 14:56:41 2009 : Debug: mschap \{\par Tue Jun 9 14:56:41 2009 : Debug: use_mppe = yes\par Tue Jun 9 14:56:41 2009 : Debug: require_encryption = no\par Tue Jun 9 14:56:41 2009 : Debug: require_strong = no\par Tue Jun 9 14:56:41 2009 : Debug: with_ntdomain_hack = no\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: (Loaded rlm_unix, checking if it's valid)\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to module rlm_unix\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating unix\par Tue Jun 9 14:56:41 2009 : Debug: unix \{\par Tue Jun 9 14:56:41 2009 : Debug: radwtmp = "/usr/local/var/log/radius/radwtmp"\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: (Loaded rlm_eap, checking if it's valid)\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to module rlm_eap\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating eap\par Tue Jun 9 14:56:41 2009 : Debug: eap \{\par Tue Jun 9 14:56:41 2009 : Debug: default_eap_type = "md5"\par Tue Jun 9 14:56:41 2009 : Debug: timer_expire = 60\par Tue Jun 9 14:56:41 2009 : Debug: ignore_unknown_eap_types = no\par Tue Jun 9 14:56:41 2009 : Debug: cisco_accounting_username_bug = no\par Tue Jun 9 14:56:41 2009 : Debug: max_sessions = 2048\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to sub-module rlm_eap_md5\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating eap-md5\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to sub-module rlm_eap_leap\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating eap-leap\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to sub-module rlm_eap_gtc\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating eap-gtc\par Tue Jun 9 14:56:41 2009 : Debug: gtc \{\par Tue Jun 9 14:56:41 2009 : Debug: challenge = "Password: "\par Tue Jun 9 14:56:41 2009 : Debug: auth_type = "PAP"\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to sub-module rlm_eap_tls\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating eap-tls\par Tue Jun 9 14:56:41 2009 : Debug: tls \{\par Tue Jun 9 14:56:41 2009 : Debug: rsa_key_exchange = no\par Tue Jun 9 14:56:41 2009 : Debug: dh_key_exchange = yes\par Tue Jun 9 14:56:41 2009 : Debug: rsa_key_length = 512\par Tue Jun 9 14:56:41 2009 : Debug: dh_key_length = 512\par Tue Jun 9 14:56:41 2009 : Debug: verify_depth = 0\par Tue Jun 9 14:56:41 2009 : Debug: pem_file_type = yes\par Tue Jun 9 14:56:41 2009 : Debug: private_key_file = "/usr/local/etc/raddb/certs/server.pem"\par Tue Jun 9 14:56:41 2009 : Debug: certificate_file = "/usr/local/etc/raddb/certs/server.pem"\par Tue Jun 9 14:56:41 2009 : Debug: CA_file = "/usr/local/etc/raddb/certs/ca.pem"\par Tue Jun 9 14:56:41 2009 : Debug: private_key_password = "whatever"\par Tue Jun 9 14:56:41 2009 : Debug: dh_file = "/usr/local/etc/raddb/certs/dh"\par Tue Jun 9 14:56:41 2009 : Debug: random_file = "/usr/local/etc/raddb/certs/random"\par Tue Jun 9 14:56:41 2009 : Debug: fragment_size = 1024\par Tue Jun 9 14:56:41 2009 : Debug: include_length = yes\par Tue Jun 9 14:56:41 2009 : Debug: check_crl = no\par Tue Jun 9 14:56:41 2009 : Debug: cipher_list = "DEFAULT"\par Tue Jun 9 14:56:41 2009 : Debug: make_cert_command = "/usr/local/etc/raddb/certs/bootstrap"\par Tue Jun 9 14:56:41 2009 : Debug: cache \{\par Tue Jun 9 14:56:41 2009 : Debug: enable = no\par Tue Jun 9 14:56:41 2009 : Debug: lifetime = 24\par Tue Jun 9 14:56:41 2009 : Debug: max_entries = 255\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to sub-module rlm_eap_ttls\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating eap-ttls\par Tue Jun 9 14:56:41 2009 : Debug: ttls \{\par Tue Jun 9 14:56:41 2009 : Debug: default_eap_type = "md5"\par Tue Jun 9 14:56:41 2009 : Debug: copy_request_to_tunnel = no\par Tue Jun 9 14:56:41 2009 : Debug: use_tunneled_reply = no\par Tue Jun 9 14:56:41 2009 : Debug: virtual_server = "inner-tunnel"\par Tue Jun 9 14:56:41 2009 : Debug: include_length = yes\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to sub-module rlm_eap_peap\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating eap-peap\par Tue Jun 9 14:56:41 2009 : Debug: peap \{\par Tue Jun 9 14:56:41 2009 : Debug: default_eap_type = "mschapv2"\par Tue Jun 9 14:56:41 2009 : Debug: copy_request_to_tunnel = no\par Tue Jun 9 14:56:41 2009 : Debug: use_tunneled_reply = no\par Tue Jun 9 14:56:41 2009 : Debug: proxy_tunneled_request_as_eap = yes\par Tue Jun 9 14:56:41 2009 : Debug: virtual_server = "inner-tunnel"\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to sub-module rlm_eap_mschapv2\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating eap-mschapv2\par Tue Jun 9 14:56:41 2009 : Debug: mschapv2 \{\par Tue Jun 9 14:56:41 2009 : Debug: with_ntdomain_hack = no\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: Module: Checking authorize \{...\} for more modules to load\par Tue Jun 9 14:56:41 2009 : Debug: (Loaded rlm_realm, checking if it's valid)\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to module rlm_realm\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating suffix\par Tue Jun 9 14:56:41 2009 : Debug: realm suffix \{\par Tue Jun 9 14:56:41 2009 : Debug: format = "suffix"\par Tue Jun 9 14:56:41 2009 : Debug: delimiter = "@"\par Tue Jun 9 14:56:41 2009 : Debug: ignore_default = no\par Tue Jun 9 14:56:41 2009 : Debug: ignore_null = no\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: (Loaded rlm_files, checking if it's valid)\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to module rlm_files\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating files\par Tue Jun 9 14:56:41 2009 : Debug: files \{\par Tue Jun 9 14:56:41 2009 : Debug: usersfile = "/usr/local/etc/raddb/users"\par Tue Jun 9 14:56:41 2009 : Debug: acctusersfile = "/usr/local/etc/raddb/acct_users"\par Tue Jun 9 14:56:41 2009 : Debug: preproxy_usersfile = "/usr/local/etc/raddb/preproxy_users"\par Tue Jun 9 14:56:41 2009 : Debug: compat = "no"\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: Module: Checking session \{...\} for more modules to load\par Tue Jun 9 14:56:41 2009 : Debug: (Loaded rlm_radutmp, checking if it's valid)\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to module rlm_radutmp\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating radutmp\par Tue Jun 9 14:56:41 2009 : Debug: radutmp \{\par Tue Jun 9 14:56:41 2009 : Debug: filename = "/usr/local/var/log/radius/radutmp"\par Tue Jun 9 14:56:41 2009 : Debug: username = "%\{User-Name\}"\par Tue Jun 9 14:56:41 2009 : Debug: case_sensitive = yes\par Tue Jun 9 14:56:41 2009 : Debug: check_with_nas = yes\par Tue Jun 9 14:56:41 2009 : Debug: perm = 384\par Tue Jun 9 14:56:41 2009 : Debug: callerid = yes\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: Module: Checking post-proxy \{...\} for more modules to load\par Tue Jun 9 14:56:41 2009 : Debug: Module: Checking post-auth \{...\} for more modules to load\par Tue Jun 9 14:56:41 2009 : Debug: (Loaded rlm_attr_filter, checking if it's valid)\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to module rlm_attr_filter\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating attr_filter.access_reject\par Tue Jun 9 14:56:41 2009 : Debug: attr_filter attr_filter.access_reject \{\par Tue Jun 9 14:56:41 2009 : Debug: attrsfile = "/usr/local/etc/raddb/attrs.access_reject"\par Tue Jun 9 14:56:41 2009 : Debug: key = "%\{User-Name\}"\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: \} # modules\par Tue Jun 9 14:56:41 2009 : Debug: \} # server\par Tue Jun 9 14:56:41 2009 : Debug: server \{\par Tue Jun 9 14:56:41 2009 : Debug: modules \{\par Tue Jun 9 14:56:41 2009 : Debug: Module: Checking authenticate \{...\} for more modules to load\par Tue Jun 9 14:56:41 2009 : Debug: Module: Checking authorize \{...\} for more modules to load\par Tue Jun 9 14:56:41 2009 : Debug: (Loaded rlm_preprocess, checking if it's valid)\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to module rlm_preprocess\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating preprocess\par Tue Jun 9 14:56:41 2009 : Debug: preprocess \{\par Tue Jun 9 14:56:41 2009 : Debug: huntgroups = "/usr/local/etc/raddb/huntgroups"\par Tue Jun 9 14:56:41 2009 : Debug: hints = "/usr/local/etc/raddb/hints"\par Tue Jun 9 14:56:41 2009 : Debug: with_ascend_hack = no\par Tue Jun 9 14:56:41 2009 : Debug: ascend_channels_per_line = 23\par Tue Jun 9 14:56:41 2009 : Debug: with_ntdomain_hack = no\par Tue Jun 9 14:56:41 2009 : Debug: with_specialix_jetstream_hack = no\par Tue Jun 9 14:56:41 2009 : Debug: with_cisco_vsa_hack = no\par Tue Jun 9 14:56:41 2009 : Debug: with_alvarion_vsa_hack = no\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: (Loaded rlm_sql, checking if it's valid)\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to module rlm_sql\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating sql\par Tue Jun 9 14:56:41 2009 : Debug: sql \{\par Tue Jun 9 14:56:41 2009 : Debug: driver = "rlm_sql_mysql"\par Tue Jun 9 14:56:41 2009 : Debug: server = "localhost"\par Tue Jun 9 14:56:41 2009 : Debug: port = ""\par Tue Jun 9 14:56:41 2009 : Debug: login = "root"\par Tue Jun 9 14:56:41 2009 : Debug: password = "Ch1ll1"\par Tue Jun 9 14:56:41 2009 : Debug: radius_db = "radiusd"\par Tue Jun 9 14:56:41 2009 : Debug: read_groups = yes\par Tue Jun 9 14:56:41 2009 : Debug: sqltrace = no\par Tue Jun 9 14:56:41 2009 : Debug: sqltracefile = "/usr/local/var/log/radius/sqltrace.sql"\par Tue Jun 9 14:56:41 2009 : Debug: readclients = no\par Tue Jun 9 14:56:41 2009 : Debug: deletestalesessions = yes\par Tue Jun 9 14:56:41 2009 : Debug: num_sql_socks = 5\par Tue Jun 9 14:56:41 2009 : Debug: lifetime = 0\par Tue Jun 9 14:56:41 2009 : Debug: max_queries = 0\par Tue Jun 9 14:56:41 2009 : Debug: sql_user_name = "%\{User-Name\}"\par Tue Jun 9 14:56:41 2009 : Debug: default_user_profile = ""\par Tue Jun 9 14:56:41 2009 : Debug: nas_query = "SELECT id, nasname, shortname, type, secret FROM nas"\par Tue Jun 9 14:56:41 2009 : Debug: authorize_check_query = "SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%\{SQL-User-Name\}' ORDER BY id"\par Tue Jun 9 14:56:41 2009 : Debug: authorize_reply_query = "SELECT id, username, attribute, value, op FROM radreply WHERE username = '%\{SQL-User-Name\}' ORDER BY id"\par Tue Jun 9 14:56:41 2009 : Debug: authorize_group_check_query = "SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%\{Sql-Group\}' ORDER BY id"\par Tue Jun 9 14:56:41 2009 : Debug: authorize_group_reply_query = "SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%\{Sql-Group\}' ORDER BY id"\par Tue Jun 9 14:56:41 2009 : 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'"\par Tue Jun 9 14:56:41 2009 : 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\}'"\par Tue Jun 9 14:56:41 2009 : 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\}')"\par Tue Jun 9 14:56:41 2009 : 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\}')"\par Tue Jun 9 14:56:41 2009 : 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\}'"\par Tue Jun 9 14:56:41 2009 : 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\}'"\par Tue Jun 9 14:56:41 2009 : 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\}')"\par Tue Jun 9 14:56:41 2009 : Debug: group_membership_query = "SELECT groupname FROM radusergroup WHERE username = '%\{SQL-User-Name\}' ORDER BY priority"\par Tue Jun 9 14:56:41 2009 : Debug: connect_failure_retry_delay = 60\par Tue Jun 9 14:56:41 2009 : Debug: simul_count_query = ""\par Tue Jun 9 14:56:41 2009 : Debug: simul_verify_query = "SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = '%\{SQL-User-Name\}' AND acctstoptime IS NULL"\par Tue Jun 9 14:56:41 2009 : Debug: postauth_query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%\{User-Name\}', '%\{%\{User-Password\}:-%\{Chap-Password\}\}', '%\{reply:Packet-Type\}', '%S')"\par Tue Jun 9 14:56:41 2009 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Info: rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked\par Tue Jun 9 14:56:41 2009 : Info: rlm_sql (sql): Attempting to connect to root@localhost:/radiusd\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sql (sql): starting 0\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sql (sql): Attempting to connect rlm_sql_mysql #0\par Tue Jun 9 14:56:41 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #0\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sql (sql): Connected new DB handle, #0\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sql (sql): starting 1\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sql (sql): Attempting to connect rlm_sql_mysql #1\par Tue Jun 9 14:56:41 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #1\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sql (sql): Connected new DB handle, #1\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sql (sql): starting 2\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sql (sql): Attempting to connect rlm_sql_mysql #2\par Tue Jun 9 14:56:41 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #2\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sql (sql): Connected new DB handle, #2\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sql (sql): starting 3\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sql (sql): Attempting to connect rlm_sql_mysql #3\par Tue Jun 9 14:56:41 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #3\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sql (sql): Connected new DB handle, #3\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sql (sql): starting 4\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sql (sql): Attempting to connect rlm_sql_mysql #4\par Tue Jun 9 14:56:41 2009 : Info: rlm_sql_mysql: Starting connect to MySQL server for #4\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sql (sql): Connected new DB handle, #4\par Tue Jun 9 14:56:41 2009 : Debug: (Loaded rlm_sqlcounter, checking if it's valid)\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to module rlm_sqlcounter\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating validity\par Tue Jun 9 14:56:41 2009 : Debug: sqlcounter validity \{\par Tue Jun 9 14:56:41 2009 : Debug: counter-name = "All-Secs-Usable"\par Tue Jun 9 14:56:41 2009 : Debug: check-name = "Max-Secs-Usable"\par Tue Jun 9 14:56:41 2009 : Debug: key = "User-Name"\par Tue Jun 9 14:56:41 2009 : Debug: sqlmod-inst = "sql"\par Tue Jun 9 14:56:41 2009 : Debug: query = "SELECT UNIX_TIMESTAMP() - UNIX_TIMESTAMP(AcctStartTime) secs_passed_since_start FROM radacct WHERE UserName = '%\{%k\}' LIMIT 1"\par Tue Jun 9 14:56:41 2009 : Debug: reset = "never"\par Tue Jun 9 14:56:41 2009 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sqlcounter: Reply attribute set to Session-Timeout.\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sqlcounter: Counter attribute All-Secs-Usable is number 11273\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sqlcounter: Check attribute Max-Secs-Usable is number 3000\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sqlcounter: Current Time: 1244555801 [2009-06-09 14:56:41], Next reset 0 [2009-06-09 14:00:00]\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sqlcounter: Current Time: 1244555801 [2009-06-09 14:56:41], Prev reset 0 [2009-06-09 14:00:00]\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating noresetcounter\par Tue Jun 9 14:56:41 2009 : Debug: sqlcounter noresetcounter \{\par Tue Jun 9 14:56:41 2009 : Debug: counter-name = "Max-All-Session-Time"\par Tue Jun 9 14:56:41 2009 : Debug: check-name = "Max-All-Session"\par Tue Jun 9 14:56:41 2009 : Debug: key = "User-Name"\par Tue Jun 9 14:56:41 2009 : Debug: sqlmod-inst = "sql"\par Tue Jun 9 14:56:41 2009 : Debug: query = "SELECT SUM(AcctSessionTime) FROM radacct WHERE UserName='%\{%k\}'"\par Tue Jun 9 14:56:41 2009 : Debug: reset = "never"\par Tue Jun 9 14:56:41 2009 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sqlcounter: Reply attribute set to Session-Timeout.\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sqlcounter: Counter attribute Max-All-Session-Time is number 11274\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sqlcounter: Check attribute Max-All-Session is number 11275\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sqlcounter: Current Time: 1244555801 [2009-06-09 14:56:41], Next reset 0 [2009-06-09 14:00:00]\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sqlcounter: Current Time: 1244555801 [2009-06-09 14:56:41], Prev reset 0 [2009-06-09 14:00:00]\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating hotspotcontrol\par Tue Jun 9 14:56:41 2009 : Debug: sqlcounter hotspotcontrol \{\par Tue Jun 9 14:56:41 2009 : Debug: counter-name = "All-Secs-Passed"\par Tue Jun 9 14:56:41 2009 : Debug: check-name = "Max-Secs-Passed"\par Tue Jun 9 14:56:41 2009 : Debug: reply-name = "Session-TimeOut"\par Tue Jun 9 14:56:41 2009 : Debug: key = "User-Name"\par Tue Jun 9 14:56:41 2009 : Debug: sqlmod-inst = "sql"\par Tue Jun 9 14:56:41 2009 : Debug: query = "SELECT IFNULL(SUM(AcctSessionTime),0) FROM radacct WHERE UserName='%\{%k\}'"\par Tue Jun 9 14:56:41 2009 : Debug: reset = "never"\par Tue Jun 9 14:56:41 2009 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sqlcounter: Reply attribute Session-TimeOut is number 27\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sqlcounter: Counter attribute All-Secs-Passed is number 11276\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sqlcounter: Check attribute Max-Secs-Passed is number 3001\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sqlcounter: Current Time: 1244555801 [2009-06-09 14:56:41], Next reset 0 [2009-06-09 14:00:00]\par Tue Jun 9 14:56:41 2009 : Debug: rlm_sqlcounter: Current Time: 1244555801 [2009-06-09 14:56:41], Prev reset 0 [2009-06-09 14:00:00]\par Tue Jun 9 14:56:41 2009 : Debug: Module: Checking preacct \{...\} for more modules to load\par Tue Jun 9 14:56:41 2009 : Debug: (Loaded rlm_acct_unique, checking if it's valid)\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to module rlm_acct_unique\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating acct_unique\par Tue Jun 9 14:56:41 2009 : Debug: acct_unique \{\par Tue Jun 9 14:56:41 2009 : Debug: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: Module: Checking accounting \{...\} for more modules to load\par Tue Jun 9 14:56:41 2009 : Debug: (Loaded rlm_detail, checking if it's valid)\par Tue Jun 9 14:56:41 2009 : Debug: Module: Linked to module rlm_detail\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating detail\par Tue Jun 9 14:56:41 2009 : Debug: detail \{\par Tue Jun 9 14:56:41 2009 : Debug: detailfile = "/usr/local/var/log/radius/radacct/%\{Client-IP-Address\}/detail-%Y%m%d"\par Tue Jun 9 14:56:41 2009 : Debug: header = "%t"\par Tue Jun 9 14:56:41 2009 : Debug: detailperm = 384\par Tue Jun 9 14:56:41 2009 : Debug: dirperm = 493\par Tue Jun 9 14:56:41 2009 : Debug: locking = no\par Tue Jun 9 14:56:41 2009 : Debug: log_packet_header = no\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: Module: Instantiating attr_filter.accounting_response\par Tue Jun 9 14:56:41 2009 : Debug: attr_filter attr_filter.accounting_response \{\par Tue Jun 9 14:56:41 2009 : Debug: attrsfile = "/usr/local/etc/raddb/attrs.accounting_response"\par Tue Jun 9 14:56:41 2009 : Debug: key = "%\{User-Name\}"\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: Module: Checking session \{...\} for more modules to load\par Tue Jun 9 14:56:41 2009 : Debug: Module: Checking post-proxy \{...\} for more modules to load\par Tue Jun 9 14:56:41 2009 : Debug: Module: Checking post-auth \{...\} for more modules to load\par Tue Jun 9 14:56:41 2009 : Debug: \} # modules\par Tue Jun 9 14:56:41 2009 : Debug: \} # server\par Tue Jun 9 14:56:41 2009 : Debug: radiusd: #### Opening IP addresses and Ports ####\par Tue Jun 9 14:56:41 2009 : Debug: listen \{\par Tue Jun 9 14:56:41 2009 : Debug: type = "auth"\par Tue Jun 9 14:56:41 2009 : Debug: ipaddr = *\par Tue Jun 9 14:56:41 2009 : Debug: port = 0\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: listen \{\par Tue Jun 9 14:56:41 2009 : Debug: type = "acct"\par Tue Jun 9 14:56:41 2009 : Debug: ipaddr = *\par Tue Jun 9 14:56:41 2009 : Debug: port = 0\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: listen \{\par Tue Jun 9 14:56:41 2009 : Debug: type = "control"\par Tue Jun 9 14:56:41 2009 : Debug: listen \{\par Tue Jun 9 14:56:41 2009 : Debug: socket = "/usr/local/var/run/radiusd/radiusd.sock"\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: \}\par Tue Jun 9 14:56:41 2009 : Debug: Listening on authentication address * port 1812\par Tue Jun 9 14:56:41 2009 : Debug: Listening on accounting address * port 1813\par Tue Jun 9 14:56:41 2009 : Debug: Listening on command file /usr/local/var/run/radiusd/radiusd.sock\par Tue Jun 9 14:56:41 2009 : Debug: Listening on proxy address * port 1814\par Tue Jun 9 14:56:41 2009 : Debug: Ready to process requests.\par rad_recv: Access-Request packet from host 127.0.0.1 port 44600, id=0, length=189\par ChilliSpot-Max-Input-Octets = 0x32333435363738393031\par ChilliSpot-Max-Output-Octets = 0\par NAS-IP-Address = 127.0.0.1\par Service-Type = Login-User\par Framed-IP-Address = 192.168.182.2\par Calling-Station-Id = "00-1F-29-80-62-F3"\par Called-Station-Id = "00-50-DA-0C-C9-B0"\par NAS-Identifier = "nas01"\par Acct-Session-Id = "4a2e6a7700000000"\par NAS-Port-Type = Wireless-802.11\par NAS-Port = 0\par Message-Authenticator = 0xf2ee6add34820fb96dcceef08c07bbc5\par WISPr-Logoff-URL = "http://192.168.182.1:3990/logoff"\par Tue Jun 9 14:59:48 2009 : Info: +- entering group authorize \{...\}\par Tue Jun 9 14:59:48 2009 : Info: ++[preprocess] returns ok\par Tue Jun 9 14:59:48 2009 : Info: ++[mschap] returns noop\par Tue Jun 9 14:59:48 2009 : Info: [suffix] No '@' in User-Name = "2345678901", looking up realm NULL\par Tue Jun 9 14:59:48 2009 : Info: [suffix] No such realm "NULL"\par Tue Jun 9 14:59:48 2009 : Info: ++[suffix] returns noop\par Tue Jun 9 14:59:48 2009 : Info: [eap] No EAP-Message, not doing EAP\par Tue Jun 9 14:59:48 2009 : Info: ++[eap] returns noop\par Tue Jun 9 14:59:48 2009 : Info: ++[unix] returns notfound\par Tue Jun 9 14:59:48 2009 : Info: ++[files] returns noop\par Tue Jun 9 14:59:48 2009 : Info: [sql] expand: %\{User-Name\} -> 0x32333435363738393031\par Tue Jun 9 14:59:48 2009 : Info: [sql] sql_set_user escaped user --> '0x32333435363738393031'\par Tue Jun 9 14:59:48 2009 : Debug: rlm_sql (sql): Reserving sql socket id: 4\par Tue Jun 9 14:59:48 2009 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%\{SQL-User-Name\}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = '0x32333435363738393031' ORDER BY id\par Tue Jun 9 14:59:48 2009 : Info: [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%\{SQL-User-Name\}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '0x32333435363738393031' ORDER BY priority\par Tue Jun 9 14:59:48 2009 : Debug: rlm_sql (sql): Released sql socket id: 4\par Tue Jun 9 14:59:48 2009 : Info: [sql] User 0x32333435363738393031 not found\par Tue Jun 9 14:59:48 2009 : Info: ++[sql] returns notfound\par Tue Jun 9 14:59:48 2009 : Info: ++[expiration] returns noop\par Tue Jun 9 14:59:48 2009 : Info: ++[logintime] returns noop\par Tue Jun 9 14:59:48 2009 : Info: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this.\par Tue Jun 9 14:59:48 2009 : Info: ++[pap] returns noop\par Tue Jun 9 14:59:48 2009 : Debug: rlm_sqlcounter: Entering module authorize code\par Tue Jun 9 14:59:48 2009 : Debug: rlm_sqlcounter: Could not find Check item value pair\par Tue Jun 9 14:59:48 2009 : Info: ++[validity] returns noop\par Tue Jun 9 14:59:48 2009 : Debug: rlm_sqlcounter: Entering module authorize code\par Tue Jun 9 14:59:48 2009 : Debug: rlm_sqlcounter: Could not find Check item value pair\par Tue Jun 9 14:59:48 2009 : Info: ++[noresetcounter] returns noop\par Tue Jun 9 14:59:48 2009 : Debug: rlm_sqlcounter: Entering module authorize code\par Tue Jun 9 14:59:48 2009 : Debug: rlm_sqlcounter: Could not find Check item value pair\par Tue Jun 9 14:59:48 2009 : Info: ++[hotspotcontrol] returns noop\par Tue Jun 9 14:59:48 2009 : Info: No authenticate method (Auth-Type) configuration found for the request: Rejecting the user\par Tue Jun 9 14:59:48 2009 : Info: Failed to authenticate the user.\par Tue Jun 9 14:59:48 2009 : Info: Using Post-Auth-Type Reject\par Tue Jun 9 14:59:48 2009 : Info: +- entering group REJECT \{...\}\par Tue Jun 9 14:59:48 2009 : Info: [attr_filter.access_reject] expand: %\{User-Name\} -> 0x32333435363738393031\par Tue Jun 9 14:59:48 2009 : Debug: attr_filter: Matched entry DEFAULT at line 11\par Tue Jun 9 14:59:48 2009 : Info: ++[attr_filter.access_reject] returns updated\par Tue Jun 9 14:59:48 2009 : Info: Delaying reject of request 0 for 1 seconds\par Tue Jun 9 14:59:48 2009 : Debug: Going to the next request\par Tue Jun 9 14:59:48 2009 : Debug: Waking up in 0.9 seconds.\par Tue Jun 9 14:59:49 2009 : Info: Sending delayed reject for request 0\par Sending Access-Reject of id 0 to 127.0.0.1 port 44600\par Tue Jun 9 14:59:49 2009 : Debug: Waking up in 4.9 seconds.\par Tue Jun 9 14:59:54 2009 : Info: Cleaning up request 0 ID 0 with timestamp +187\par Tue Jun 9 14:59:54 2009 : Debug: Ready to process requests.\par Tue Jun 9 14:59:54 2009 : Debug: Ready to process requests. rad_recv: Access-Request packet from host 127.0.0.1 port 33437, id=0, length=189 ChilliSpot-Max-Input-Octets = 0x31323334353637383930 ChilliSpot-Max-Output-Octets = 0 NAS-IP-Address = 127.0.0.1 Service-Type = Login-User Framed-IP-Address = 192.168.182.2 Calling-Station-Id = "00-1F-29-80-62-F3" Called-Station-Id = "00-50-DA-0C-C9-B0" NAS-Identifier = "nas01" Acct-Session-Id = "4a2e6a7700000000" NAS-Port-Type = Wireless-802.11 NAS-Port = 0 Message-Authenticator = 0xb96112f3b8a81ce98d1209ee0cc7a3cc WISPr-Logoff-URL = "http://192.168.182.1:3990/logoff" Tue Jun 9 15:00:26 2009 : Info: +- entering group authorize {...} Tue Jun 9 15:00:26 2009 : Info: ++[preprocess] returns ok Tue Jun 9 15:00:26 2009 : Info: ++[mschap] returns noop Tue Jun 9 15:00:26 2009 : Info: [suffix] No '@' in User-Name = "1234567890", looking up realm NULL Tue Jun 9 15:00:26 2009 : Info: [suffix] No such realm "NULL" Tue Jun 9 15:00:26 2009 : Info: ++[suffix] returns noop Tue Jun 9 15:00:26 2009 : Info: [eap] No EAP-Message, not doing EAP Tue Jun 9 15:00:26 2009 : Info: ++[eap] returns noop Tue Jun 9 15:00:26 2009 : Info: ++[unix] returns notfound Tue Jun 9 15:00:26 2009 : Info: ++[files] returns noop Tue Jun 9 15:00:26 2009 : Info: [sql] expand: %{User-Name} -> 0x31323334353637383930 Tue Jun 9 15:00:26 2009 : Info: [sql] sql_set_user escaped user --> '0x31323334353637383930' Tue Jun 9 15:00:26 2009 : Debug: rlm_sql (sql): Reserving sql socket id: 3 Tue Jun 9 15:00:26 2009 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = '0x31323334353637383930' ORDER BY id Tue Jun 9 15:00:26 2009 : Info: [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '0x31323334353637383930' ORDER BY priority Tue Jun 9 15:00:26 2009 : Debug: rlm_sql (sql): Released sql socket id: 3 Tue Jun 9 15:00:26 2009 : Info: [sql] User 0x31323334353637383930 not found Tue Jun 9 15:00:26 2009 : Info: ++[sql] returns notfound Tue Jun 9 15:00:26 2009 : Info: ++[expiration] returns noop Tue Jun 9 15:00:26 2009 : Info: ++[logintime] returns noop Tue Jun 9 15:00:26 2009 : Info: [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. Tue Jun 9 15:00:26 2009 : Info: ++[pap] returns noop Tue Jun 9 15:00:26 2009 : Debug: rlm_sqlcounter: Entering module authorize code Tue Jun 9 15:00:26 2009 : Debug: rlm_sqlcounter: Could not find Check item value pair Tue Jun 9 15:00:26 2009 : Info: ++[validity] returns noop Tue Jun 9 15:00:26 2009 : Debug: rlm_sqlcounter: Entering module authorize code Tue Jun 9 15:00:26 2009 : Debug: rlm_sqlcounter: Could not find Check item value pair Tue Jun 9 15:00:26 2009 : Info: ++[noresetcounter] returns noop Tue Jun 9 15:00:26 2009 : Debug: rlm_sqlcounter: Entering module authorize code Tue Jun 9 15:00:26 2009 : Debug: rlm_sqlcounter: Could not find Check item value pair Tue Jun 9 15:00:26 2009 : Info: ++[hotspotcontrol] returns noop Tue Jun 9 15:00:26 2009 : Info: No authenticate method (Auth-Type) configuration found for the request: Rejecting the user Tue Jun 9 15:00:26 2009 : Info: Failed to authenticate the user. Tue Jun 9 15:00:26 2009 : Info: Using Post-Auth-Type Reject Tue Jun 9 15:00:26 2009 : Info: +- entering group REJECT {...} Tue Jun 9 15:00:26 2009 : Info: [attr_filter.access_reject] expand: %{User-Name} -> 0x31323334353637383930 Tue Jun 9 15:00:26 2009 : Debug: attr_filter: Matched entry DEFAULT at line 11 Tue Jun 9 15:00:26 2009 : Info: ++[attr_filter.access_reject] returns updated Tue Jun 9 15:00:26 2009 : Info: Delaying reject of request 1 for 1 seconds Tue Jun 9 15:00:26 2009 : Debug: Going to the next request Tue Jun 9 15:00:26 2009 : Debug: Waking up in 0.9 seconds. Tue Jun 9 15:00:27 2009 : Info: Sending delayed reject for request 1 Sending Access-Reject of id 0 to 127.0.0.1 port 33437 Tue Jun 9 15:00:27 2009 : Debug: Waking up in 4.9 seconds. Tue Jun 9 15:00:32 2009 : Info: Cleaning up request 1 ID 0 with timestamp +225 Tue Jun 9 15:00:32 2009 : Debug: Ready to process requests. }
Alan DeKok wrote:
Goke Aruna wrote:
I will be glad, if anyone can direct me to whare The log below is the part of the debug for the new test freeradius server 2.1.6 am testing with.
However, the hotspotlogin,cgi is able to pass the param username to the radius
It's not in the debug log below.
rad_recv: Access-Request packet from host 127.0.0.1 port 44600, id=0, length=189
... there's no User-Name attribute. The packet violates the RADIUS specifications. Yet, somehow, magically:
Tue Jun 9 14:59:48 2009 : Info: [suffix] No '@' in User-Name = "2345678901", looking up realm NULL
There's a User-Name in the packet! How did that happen?
Tue Jun 9 14:59:48 2009 : Info: [sql] expand: %{User-Name} -> 0x32333435363738393031
And now the User-Name is different!
You've managed to copy the Chillispot-Max-Input-Octets into the User-Name. Why?
It looks like you've edited the dictionaries without knowing what you're doing. Don't do that.
Alan DeKok.
after commenting out the include directive for dictionary.chillispot from the radius dictionary file, i am able to login but my check-item which is attribute Max-Secs-Passed was not loaded. Thanks but I still need to do the billing based on the added attributes.
On Tue, Jun 9, 2009 at 5:10 PM, Goke Aruna <goksie@gmail.com> wrote:
Alan DeKok wrote:
Goke Aruna wrote:
I will be glad, if anyone can direct me to whare The log below is the part of the debug for the new test freeradius server 2.1.6 am testing with.
However, the hotspotlogin,cgi is able to pass the param username to the radius
It's not in the debug log below.
rad_recv: Access-Request packet from host 127.0.0.1 port 44600, id=0,
length=189
... there's no User-Name attribute. The packet violates the RADIUS specifications. Yet, somehow, magically:
Tue Jun 9 14:59:48 2009 : Info: [suffix] No '@' in User-Name =
"2345678901", looking up realm NULL
There's a User-Name in the packet! How did that happen?
Tue Jun 9 14:59:48 2009 : Info: [sql] expand: %{User-Name} ->
0x32333435363738393031
And now the User-Name is different!
You've managed to copy the Chillispot-Max-Input-Octets into the User-Name. Why?
It looks like you've edited the dictionaries without knowing what you're doing. Don't do that.
Alan DeKok.
after commenting out the include directive for dictionary.chillispot from the radius dictionary file, i am able to login but my check-item which is attribute Max-Secs-Passed was not loaded.
Thanks but I still need to do the billing based on the added attributes.
I still need your advice on how to go about adding my own attributes to the dictionary file and also what I have done wrong in including the dictionary.chillispot Thanks. goksie
participants (3)
-
Alan DeKok -
Goke Aruna -
Goke M Aruna