Thank you for reply I this example for WLAN_TEST group assigned Airespace-Wlan-Id 5. User cames with id 8 mysql> select * from radcheck where username = 'idtest'; +-----+----------+--------------------+----+-------+ | id | username | attribute | op | value | +-----+----------+--------------------+----+-------+ | 804 | idtest | Cleartext-Password | := | test | +-----+----------+--------------------+----+-------+ 1 row in set (0.00 sec) mysql> select * from radusergroup where username = 'idtest'; +----------+-----------+----------+ | username | groupname | priority | +----------+-----------+----------+ | idtest | WLAN_TEST | 0 | +----------+-----------+----------+ 1 row in set (0.00 sec) mysql> select * from radgroupcheck where groupname = 'WLAN_TEST'; +----+-----------+-------------------+----+-------+ | id | groupname | attribute | op | value | +----+-----------+-------------------+----+-------+ | 34 | WLAN_TEST | Airespace-Wlan-Id | == | 5 | +----+-----------+-------------------+----+-------+ 1 row in set (0.00 sec) root@NMS-RAD0301IQ ~# sudo freeradius -XX sudo: unable to resolve host NMS-RAD0301IQ Mon Apr 13 11:53:21 2015 : Info: FreeRADIUS Version 2.1.10, for host i486-pc-linux-gnu, built on Apr 24 2011 at 18:55:43 Mon Apr 13 11:53:21 2015 : Info: Copyright (C) 1999-2009 The FreeRADIUS server project and contributors. Mon Apr 13 11:53:21 2015 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A Mon Apr 13 11:53:21 2015 : Info: PARTICULAR PURPOSE. Mon Apr 13 11:53:21 2015 : Info: You may redistribute copies of FreeRADIUS under the terms of the Mon Apr 13 11:53:21 2015 : Info: GNU General Public License v2. Mon Apr 13 11:53:21 2015 : Info: Starting - reading configuration files ... Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/radiusd.conf Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/proxy.conf Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/clients.conf Mon Apr 13 11:53:21 2015 : Debug: including files in directory /etc/freeradius/modules/ Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/otp Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/perl Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/ldap Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/expr Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/ntlm_auth Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/realm Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/expiration Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/policy Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/sradutmp Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/detail.example.com Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/counter Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/acct_unique Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/pap Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/pam Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/digest Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/dynamic_clients Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/echo Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/smsotp Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/detail Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/mschap Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/detail.log Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/files Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/inner-eap Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/acct_unique.orig Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/logintime Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/smbpasswd Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/unix Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/cui Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/krb5 Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/attr_rewrite Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/attr_filter Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/passwd Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/mac2vlan Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/radutmp Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/wimax Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/preprocess Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/ippool Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/linelog Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/exec Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/etc_group Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/checkval Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/sqlcounter_expire_on_login Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/always Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/chap Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/sql_log Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/opendirectory Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/modules/mac2ip Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/eap.conf Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/sql.conf Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/sql/mysql/dialup.conf Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/sql/mysql/counter.conf Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/sqlippool.conf Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/sql/mysql/ippool.conf Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/policy.conf Mon Apr 13 11:53:21 2015 : Debug: including files in directory /etc/freeradius/sites-enabled/ Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/sites-enabled/default Mon Apr 13 11:53:21 2015 : Debug: including configuration file /etc/freeradius/sites-enabled/inner-tunnel Mon Apr 13 11:53:21 2015 : Debug: main { Mon Apr 13 11:53:21 2015 : Debug: user = "freerad" Mon Apr 13 11:53:21 2015 : Debug: group = "freerad" Mon Apr 13 11:53:21 2015 : Debug: allow_core_dumps = no Mon Apr 13 11:53:21 2015 : Debug: } Mon Apr 13 11:53:21 2015 : Debug: including dictionary file /etc/freeradius/dictionary Mon Apr 13 11:53:21 2015 : Debug: main { Mon Apr 13 11:53:21 2015 : Debug: prefix = "/usr" Mon Apr 13 11:53:21 2015 : Debug: localstatedir = "/var" Mon Apr 13 11:53:21 2015 : Debug: logdir = "/var/log/freeradius" Mon Apr 13 11:53:21 2015 : Debug: libdir = "/usr/lib/freeradius" Mon Apr 13 11:53:21 2015 : Debug: radacctdir = "/var/log/freeradius/radacct" Mon Apr 13 11:53:21 2015 : Debug: hostname_lookups = no Mon Apr 13 11:53:21 2015 : Debug: max_request_time = 30 Mon Apr 13 11:53:21 2015 : Debug: cleanup_delay = 5 Mon Apr 13 11:53:21 2015 : Debug: max_requests = 1024 Mon Apr 13 11:53:21 2015 : Debug: pidfile = "/var/run/freeradius/freeradius.pid" Mon Apr 13 11:53:21 2015 : Debug: checkrad = "/usr/sbin/checkrad" Mon Apr 13 11:53:21 2015 : Debug: debug_level = 0 Mon Apr 13 11:53:21 2015 : Debug: proxy_requests = yes Mon Apr 13 11:53:21 2015 : Debug: log { Mon Apr 13 11:53:21 2015 : Debug: stripped_names = no Mon Apr 13 11:53:21 2015 : Debug: auth = no Mon Apr 13 11:53:21 2015 : Debug: auth_badpass = no Mon Apr 13 11:53:21 2015 : Debug: auth_goodpass = no Mon Apr 13 11:53:21 2015 : Debug: } Mon Apr 13 11:53:21 2015 : Debug: security { Mon Apr 13 11:53:21 2015 : Debug: max_attributes = 200 Mon Apr 13 11:53:21 2015 : Debug: reject_delay = 1 Mon Apr 13 11:53:21 2015 : Debug: status_server = yes Mon Apr 13 11:53:21 2015 : Debug: } Mon Apr 13 11:53:21 2015 : Debug: } Mon Apr 13 11:53:21 2015 : Debug: radiusd: #### Loading Realms and Home Servers #### Mon Apr 13 11:53:21 2015 : Debug: proxy server { Mon Apr 13 11:53:21 2015 : Debug: retry_delay = 5 Mon Apr 13 11:53:21 2015 : Debug: retry_count = 3 Mon Apr 13 11:53:21 2015 : Debug: default_fallback = no Mon Apr 13 11:53:21 2015 : Debug: dead_time = 120 Mon Apr 13 11:53:21 2015 : Debug: wake_all_if_all_dead = no Mon Apr 13 11:53:21 2015 : Debug: } Mon Apr 13 11:53:21 2015 : Debug: home_server localhost { Mon Apr 13 11:53:21 2015 : Debug: ipaddr = 127.0.0.1 Mon Apr 13 11:53:21 2015 : Debug: port = 1812 Mon Apr 13 11:53:21 2015 : Debug: type = "auth" Mon Apr 13 11:53:21 2015 : Debug: secret = "testing123" Mon Apr 13 11:53:21 2015 : Debug: response_window = 20 Mon Apr 13 11:53:21 2015 : Debug: max_outstanding = 65536 Mon Apr 13 11:53:21 2015 : Debug: require_message_authenticator = yes Mon Apr 13 11:53:21 2015 : Debug: zombie_period = 40 Mon Apr 13 11:53:21 2015 : Debug: status_check = "status-server" Mon Apr 13 11:53:21 2015 : Debug: ping_interval = 30 Mon Apr 13 11:53:21 2015 : Debug: check_interval = 30 Mon Apr 13 11:53:21 2015 : Debug: num_answers_to_alive = 3 Mon Apr 13 11:53:21 2015 : Debug: num_pings_to_alive = 3 Mon Apr 13 11:53:21 2015 : Debug: revive_interval = 120 Mon Apr 13 11:53:21 2015 : Debug: status_check_timeout = 4 Mon Apr 13 11:53:21 2015 : Debug: irt = 2 Mon Apr 13 11:53:21 2015 : Debug: mrt = 16 Mon Apr 13 11:53:21 2015 : Debug: mrc = 5 Mon Apr 13 11:53:21 2015 : Debug: mrd = 30 Mon Apr 13 11:53:21 2015 : Debug: } Mon Apr 13 11:53:21 2015 : Debug: home_server_pool my_auth_failover { Mon Apr 13 11:53:21 2015 : Debug: type = fail-over Mon Apr 13 11:53:21 2015 : Debug: home_server = localhost Mon Apr 13 11:53:21 2015 : Debug: } Mon Apr 13 11:53:21 2015 : Debug: realm example.com { Mon Apr 13 11:53:21 2015 : Debug: auth_pool = my_auth_failover Mon Apr 13 11:53:21 2015 : Debug: } Mon Apr 13 11:53:21 2015 : Debug: realm LOCAL { Mon Apr 13 11:53:21 2015 : Debug: } Mon Apr 13 11:53:21 2015 : Debug: radiusd: #### Loading Clients #### Mon Apr 13 11:53:21 2015 : Debug: client localhost { Mon Apr 13 11:53:21 2015 : Debug: ipaddr = 127.0.0.1 Mon Apr 13 11:53:21 2015 : Debug: require_message_authenticator = no Mon Apr 13 11:53:21 2015 : Debug: secret = "testing123" Mon Apr 13 11:53:21 2015 : Debug: nastype = "other" Mon Apr 13 11:53:21 2015 : Debug: } Mon Apr 13 11:53:21 2015 : Debug: radiusd: #### Instantiating modules #### Mon Apr 13 11:53:21 2015 : Debug: instantiate { Mon Apr 13 11:53:21 2015 : Debug: (Loaded rlm_exec, checking if it's valid) Mon Apr 13 11:53:21 2015 : Debug: Module: Linked to module rlm_exec Mon Apr 13 11:53:21 2015 : Debug: Module: Instantiating module "exec" from file /etc/freeradius/modules/exec Mon Apr 13 11:53:21 2015 : Debug: exec { Mon Apr 13 11:53:21 2015 : Debug: wait = no Mon Apr 13 11:53:21 2015 : Debug: input_pairs = "request" Mon Apr 13 11:53:21 2015 : Debug: shell_escape = yes Mon Apr 13 11:53:21 2015 : Debug: } Mon Apr 13 11:53:21 2015 : Debug: (Loaded rlm_expr, checking if it's valid) Mon Apr 13 11:53:21 2015 : Debug: Module: Linked to module rlm_expr Mon Apr 13 11:53:21 2015 : Debug: Module: Instantiating module "expr" from file /etc/freeradius/modules/expr Mon Apr 13 11:53:21 2015 : Debug: (Loaded rlm_expiration, checking if it's valid) Mon Apr 13 11:53:21 2015 : Debug: Module: Linked to module rlm_expiration Mon Apr 13 11:53:21 2015 : Debug: Module: Instantiating module "expiration" from file /etc/freeradius/modules/expiration Mon Apr 13 11:53:21 2015 : Debug: expiration { Mon Apr 13 11:53:21 2015 : Debug: reply-message = "Password Has Expired " Mon Apr 13 11:53:21 2015 : Debug: } Mon Apr 13 11:53:21 2015 : Debug: (Loaded rlm_logintime, checking if it's valid) Mon Apr 13 11:53:21 2015 : Debug: Module: Linked to module rlm_logintime Mon Apr 13 11:53:21 2015 : Debug: Module: Instantiating module "logintime" from file /etc/freeradius/modules/logintime Mon Apr 13 11:53:21 2015 : Debug: logintime { Mon Apr 13 11:53:21 2015 : Debug: reply-message = "You are calling outside your allowed timespan " Mon Apr 13 11:53:21 2015 : Debug: minimum-timeout = 60 Mon Apr 13 11:53:21 2015 : Debug: } Mon Apr 13 11:53:21 2015 : Debug: } Mon Apr 13 11:53:21 2015 : Debug: radiusd: #### Loading Virtual Servers #### Mon Apr 13 11:53:21 2015 : Debug: server inner-tunnel { # from file /etc/freeradius/sites-enabled/inner-tunnel Mon Apr 13 11:53:21 2015 : Debug: modules { Mon Apr 13 11:53:21 2015 : Debug: Module: Checking authenticate {...} for more modules to load Mon Apr 13 11:53:21 2015 : Debug: (Loaded rlm_pap, checking if it's valid) Mon Apr 13 11:53:21 2015 : Debug: Module: Linked to module rlm_pap Mon Apr 13 11:53:21 2015 : Debug: Module: Instantiating module "pap" from file /etc/freeradius/modules/pap Mon Apr 13 11:53:21 2015 : Debug: pap { Mon Apr 13 11:53:21 2015 : Debug: encryption_scheme = "auto" Mon Apr 13 11:53:21 2015 : Debug: auto_header = no Mon Apr 13 11:53:21 2015 : Debug: } Mon Apr 13 11:53:21 2015 : Debug: (Loaded rlm_chap, checking if it's valid) Mon Apr 13 11:53:21 2015 : Debug: Module: Linked to module rlm_chap Mon Apr 13 11:53:21 2015 : Debug: Module: Instantiating module "chap" from file /etc/freeradius/modules/chap Mon Apr 13 11:53:21 2015 : Debug: (Loaded rlm_mschap, checking if it's valid) Mon Apr 13 11:53:21 2015 : Debug: Module: Linked to module rlm_mschap Mon Apr 13 11:53:21 2015 : Debug: Module: Instantiating module "mschap" from file /etc/freeradius/modules/mschap Mon Apr 13 11:53:21 2015 : Debug: mschap { Mon Apr 13 11:53:21 2015 : Debug: use_mppe = yes Mon Apr 13 11:53:21 2015 : Debug: require_encryption = no Mon Apr 13 11:53:21 2015 : Debug: require_strong = no Mon Apr 13 11:53:21 2015 : Debug: with_ntdomain_hack = no Mon Apr 13 11:53:21 2015 : Debug: } Mon Apr 13 11:53:21 2015 : Debug: (Loaded rlm_unix, checking if it's valid) Mon Apr 13 11:53:21 2015 : Debug: Module: Linked to module rlm_unix Mon Apr 13 11:53:21 2015 : Debug: Module: Instantiating module "unix" from file /etc/freeradius/modules/unix Mon Apr 13 11:53:21 2015 : Debug: unix { Mon Apr 13 11:53:21 2015 : Debug: radwtmp = "/var/log/freeradius/radwtmp" Mon Apr 13 11:53:21 2015 : Debug: } Mon Apr 13 11:53:21 2015 : Debug: (Loaded rlm_eap, checking if it's valid) Mon Apr 13 11:53:21 2015 : Debug: Module: Linked to module rlm_eap Mon Apr 13 11:53:21 2015 : Debug: Module: Instantiating module "eap" from file /etc/freeradius/eap.conf Mon Apr 13 11:53:21 2015 : Debug: eap { Mon Apr 13 11:53:21 2015 : Debug: default_eap_type = "md5" Mon Apr 13 11:53:21 2015 : Debug: timer_expire = 60 Mon Apr 13 11:53:21 2015 : Debug: ignore_unknown_eap_types = no Mon Apr 13 11:53:21 2015 : Debug: cisco_accounting_username_bug = no Mon Apr 13 11:53:21 2015 : Debug: max_sessions = 4096 Mon Apr 13 11:53:21 2015 : Debug: } Mon Apr 13 11:53:21 2015 : Debug: Module: Linked to sub-module rlm_eap_md5 Mon Apr 13 11:53:21 2015 : Debug: Module: Instantiating eap-md5 Mon Apr 13 11:53:21 2015 : Debug: Module: Linked to sub-module rlm_eap_leap Mon Apr 13 11:53:21 2015 : Debug: Module: Instantiating eap-leap Mon Apr 13 11:53:21 2015 : Debug: Module: Linked to sub-module rlm_eap_gtc Mon Apr 13 11:53:21 2015 : Debug: Module: Instantiating eap-gtc Mon Apr 13 11:53:21 2015 : Debug: gtc { Mon Apr 13 11:53:21 2015 : Debug: challenge = "Password: " Mon Apr 13 11:53:21 2015 : Debug: auth_type = "PAP" Mon Apr 13 11:53:21 2015 : Debug: } Mon Apr 13 11:53:21 2015 : Debug: Module: Linked to sub-module rlm_eap_tls Mon Apr 13 11:53:21 2015 : Debug: Module: Instantiating eap-tls Mon Apr 13 11:53:21 2015 : Debug: tls { Mon Apr 13 11:53:21 2015 : Debug: rsa_key_exchange = no Mon Apr 13 11:53:21 2015 : Debug: dh_key_exchange = yes Mon Apr 13 11:53:21 2015 : Debug: rsa_key_length = 512 Mon Apr 13 11:53:21 2015 : Debug: dh_key_length = 512 Mon Apr 13 11:53:21 2015 : Debug: verify_depth = 0 Mon Apr 13 11:53:21 2015 : Debug: CA_path = "/etc/freeradius/certs" Mon Apr 13 11:53:21 2015 : Debug: pem_file_type = yes Mon Apr 13 11:53:21 2015 : Debug: private_key_file = "/etc/freeradius/certs/server.key" Mon Apr 13 11:53:21 2015 : Debug: certificate_file = "/etc/freeradius/certs/server.pem" Mon Apr 13 11:53:21 2015 : Debug: CA_file = "/etc/freeradius/certs/ca.pem" Mon Apr 13 11:53:21 2015 : Debug: private_key_password = "whatever" Mon Apr 13 11:53:21 2015 : Debug: dh_file = "/etc/freeradius/certs/dh" Mon Apr 13 11:53:21 2015 : Debug: random_file = "/etc/freeradius/certs/random" Mon Apr 13 11:53:21 2015 : Debug: fragment_size = 1024 Mon Apr 13 11:53:21 2015 : Debug: include_length = yes Mon Apr 13 11:53:21 2015 : Debug: check_crl = no Mon Apr 13 11:53:21 2015 : Debug: cipher_list = "DEFAULT" Mon Apr 13 11:53:21 2015 : Debug: make_cert_command = "/etc/freeradius/certs/bootstrap" Mon Apr 13 11:53:21 2015 : Debug: cache { Mon Apr 13 11:53:21 2015 : Debug: enable = no Mon Apr 13 11:53:21 2015 : Debug: lifetime = 24 Mon Apr 13 11:53:21 2015 : Debug: max_entries = 255 Mon Apr 13 11:53:21 2015 : Debug: } Mon Apr 13 11:53:21 2015 : Debug: verify { Mon Apr 13 11:53:21 2015 : Debug: } Mon Apr 13 11:53:21 2015 : Debug: } Mon Apr 13 11:53:22 2015 : Debug: Module: Linked to sub-module rlm_eap_ttls Mon Apr 13 11:53:22 2015 : Debug: Module: Instantiating eap-ttls Mon Apr 13 11:53:22 2015 : Debug: ttls { Mon Apr 13 11:53:22 2015 : Debug: default_eap_type = "md5" Mon Apr 13 11:53:22 2015 : Debug: copy_request_to_tunnel = no Mon Apr 13 11:53:22 2015 : Debug: use_tunneled_reply = no Mon Apr 13 11:53:22 2015 : Debug: virtual_server = "inner-tunnel" Mon Apr 13 11:53:22 2015 : Debug: include_length = yes Mon Apr 13 11:53:22 2015 : Debug: } Mon Apr 13 11:53:22 2015 : Debug: Module: Linked to sub-module rlm_eap_peap Mon Apr 13 11:53:22 2015 : Debug: Module: Instantiating eap-peap Mon Apr 13 11:53:22 2015 : Debug: peap { Mon Apr 13 11:53:22 2015 : Debug: default_eap_type = "mschapv2" Mon Apr 13 11:53:22 2015 : Debug: copy_request_to_tunnel = no Mon Apr 13 11:53:22 2015 : Debug: use_tunneled_reply = no Mon Apr 13 11:53:22 2015 : Debug: proxy_tunneled_request_as_eap = yes Mon Apr 13 11:53:22 2015 : Debug: virtual_server = "inner-tunnel" Mon Apr 13 11:53:22 2015 : Debug: } Mon Apr 13 11:53:22 2015 : Debug: Module: Linked to sub-module rlm_eap_mschapv2 Mon Apr 13 11:53:22 2015 : Debug: Module: Instantiating eap-mschapv2 Mon Apr 13 11:53:22 2015 : Debug: mschapv2 { Mon Apr 13 11:53:22 2015 : Debug: with_ntdomain_hack = no Mon Apr 13 11:53:22 2015 : Debug: } Mon Apr 13 11:53:22 2015 : Debug: Module: Checking authorize {...} for more modules to load Mon Apr 13 11:53:22 2015 : Debug: (Loaded rlm_realm, checking if it's valid) Mon Apr 13 11:53:22 2015 : Debug: Module: Linked to module rlm_realm Mon Apr 13 11:53:22 2015 : Debug: Module: Instantiating module "suffix" from file /etc/freeradius/modules/realm Mon Apr 13 11:53:22 2015 : Debug: realm suffix { Mon Apr 13 11:53:22 2015 : Debug: format = "suffix" Mon Apr 13 11:53:22 2015 : Debug: delimiter = "@" Mon Apr 13 11:53:22 2015 : Debug: ignore_default = no Mon Apr 13 11:53:22 2015 : Debug: ignore_null = no Mon Apr 13 11:53:22 2015 : Debug: } Mon Apr 13 11:53:22 2015 : Debug: (Loaded rlm_files, checking if it's valid) Mon Apr 13 11:53:22 2015 : Debug: Module: Linked to module rlm_files Mon Apr 13 11:53:22 2015 : Debug: Module: Instantiating module "files" from file /etc/freeradius/modules/files Mon Apr 13 11:53:22 2015 : Debug: files { Mon Apr 13 11:53:22 2015 : Debug: usersfile = "/etc/freeradius/users" Mon Apr 13 11:53:22 2015 : Debug: acctusersfile = "/etc/freeradius/acct_users" Mon Apr 13 11:53:22 2015 : Debug: preproxy_usersfile = "/etc/freeradius/preproxy_users" Mon Apr 13 11:53:22 2015 : Debug: compat = "no" Mon Apr 13 11:53:22 2015 : Debug: } Mon Apr 13 11:53:22 2015 : Debug: (Loaded rlm_sql, checking if it's valid) Mon Apr 13 11:53:22 2015 : Debug: Module: Linked to module rlm_sql Mon Apr 13 11:53:22 2015 : Debug: Module: Instantiating module "sql" from file /etc/freeradius/sql.conf Mon Apr 13 11:53:22 2015 : Debug: sql { Mon Apr 13 11:53:22 2015 : Debug: driver = "rlm_sql_mysql" Mon Apr 13 11:53:22 2015 : Debug: server = "localhost" Mon Apr 13 11:53:22 2015 : Debug: port = "" Mon Apr 13 11:53:22 2015 : Debug: login = "radius" Mon Apr 13 11:53:22 2015 : Debug: password = "radius" Mon Apr 13 11:53:22 2015 : Debug: radius_db = "radius" Mon Apr 13 11:53:22 2015 : Debug: read_groups = yes Mon Apr 13 11:53:22 2015 : Debug: sqltrace = no Mon Apr 13 11:53:22 2015 : Debug: sqltracefile = "/var/log/freeradius/sqltrace.sql" Mon Apr 13 11:53:22 2015 : Debug: readclients = yes Mon Apr 13 11:53:22 2015 : Debug: deletestalesessions = yes Mon Apr 13 11:53:22 2015 : Debug: num_sql_socks = 5 Mon Apr 13 11:53:22 2015 : Debug: lifetime = 0 Mon Apr 13 11:53:22 2015 : Debug: max_queries = 0 Mon Apr 13 11:53:22 2015 : Debug: sql_user_name = "%{User-Name}" Mon Apr 13 11:53:22 2015 : Debug: default_user_profile = "" Mon Apr 13 11:53:22 2015 : Debug: nas_query = "SELECT id, nasname, shortname, type, secret, server FROM nas" Mon Apr 13 11:53:22 2015 : Debug: authorize_check_query = "SELECT id, username, attribute, value, op FROM radcheck WHERE username = BINARY '%{SQL-User-Name}' ORDER BY id" Mon Apr 13 11:53:22 2015 : Debug: authorize_reply_query = "SELECT id, username, attribute, value, op FROM radreply WHERE username = BINARY '%{SQL-User-Name}' ORDER BY id" Mon Apr 13 11:53:22 2015 : Debug: authorize_group_check_query = "SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id" Mon Apr 13 11:53:22 2015 : Debug: authorize_group_reply_query = "SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id" Mon Apr 13 11:53:22 2015 : 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'" Mon Apr 13 11:53:22 2015 : 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}', acctstoptime = NULL WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" Mon Apr 13 11:53:22 2015 : 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}')" Mon Apr 13 11:53:22 2015 : 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}')" Mon Apr 13 11:53:22 2015 : 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}'" Mon Apr 13 11:53:22 2015 : 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}'" Mon Apr 13 11:53:22 2015 : 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}')" Mon Apr 13 11:53:22 2015 : Debug: group_membership_query = "SELECT groupname FROM radusergroup WHERE username = BINARY '%{SQL-User-Name}' ORDER BY priority" Mon Apr 13 11:53:22 2015 : Debug: connect_failure_retry_delay = 60 Mon Apr 13 11:53:22 2015 : Debug: simul_count_query = "SELECT COUNT(*) FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL" Mon Apr 13 11:53:22 2015 : Debug: simul_verify_query = "SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL" Mon Apr 13 11:53:22 2015 : Debug: postauth_query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')" Mon Apr 13 11:53:22 2015 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" Mon Apr 13 11:53:22 2015 : Debug: } Mon Apr 13 11:53:22 2015 : Info: rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked Mon Apr 13 11:53:22 2015 : Info: rlm_sql (sql): Attempting to connect to radius@localhost:/radius Mon Apr 13 11:53:22 2015 : Debug: rlm_sql (sql): starting 0 Mon Apr 13 11:53:22 2015 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #0 Mon Apr 13 11:53:22 2015 : Info: rlm_sql_mysql: Starting connect to MySQL server for #0 Mon Apr 13 11:53:22 2015 : Info: rlm_sql (sql): Connected new DB handle, #0 Mon Apr 13 11:53:22 2015 : Debug: rlm_sql (sql): starting 1 Mon Apr 13 11:53:22 2015 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #1 Mon Apr 13 11:53:22 2015 : Info: rlm_sql_mysql: Starting connect to MySQL server for #1 Mon Apr 13 11:53:22 2015 : Info: rlm_sql (sql): Connected new DB handle, #1 Mon Apr 13 11:53:22 2015 : Debug: rlm_sql (sql): starting 2 Mon Apr 13 11:53:22 2015 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #2 Mon Apr 13 11:53:22 2015 : Info: rlm_sql_mysql: Starting connect to MySQL server for #2 Mon Apr 13 11:53:22 2015 : Info: rlm_sql (sql): Connected new DB handle, #2 Mon Apr 13 11:53:22 2015 : Debug: rlm_sql (sql): starting 3 Mon Apr 13 11:53:22 2015 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #3 Mon Apr 13 11:53:22 2015 : Info: rlm_sql_mysql: Starting connect to MySQL server for #3 Mon Apr 13 11:53:22 2015 : Info: rlm_sql (sql): Connected new DB handle, #3 Mon Apr 13 11:53:22 2015 : Debug: rlm_sql (sql): starting 4 Mon Apr 13 11:53:22 2015 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #4 Mon Apr 13 11:53:22 2015 : Info: rlm_sql_mysql: Starting connect to MySQL server for #4 Mon Apr 13 11:53:22 2015 : Info: rlm_sql (sql): Connected new DB handle, #4 Mon Apr 13 11:53:22 2015 : Debug: rlm_sql (sql): Processing generate_sql_clients Mon Apr 13 11:53:22 2015 : Debug: rlm_sql (sql) in generate_sql_clients: query is SELECT id, nasname, shortname, type, secret, server FROM nas Mon Apr 13 11:53:22 2015 : Debug: rlm_sql (sql): Reserving sql socket id: 4 Mon Apr 13 11:53:22 2015 : Debug: rlm_sql (sql): Read entry nasname=localhost,shortname=localhost,secret=testing123 Mon Apr 13 11:53:22 2015 : Debug: rlm_sql (sql): Adding client 127.0.0.1 (localhost, server=<none>) to clients list Mon Apr 13 11:53:22 2015 : Debug: WARNING: Ignoring duplicate client 127.0.0.1 Mon Apr 13 11:53:22 2015 : Debug: rlm_sql (sql): Read entry nasname=10.127.3.221,shortname=IQ-PC-WLC,secret=#WQ2r@dW!f1 Mon Apr 13 11:53:22 2015 : Debug: rlm_sql (sql): Adding client 10.127.3.221 (IQ-PC-WLC, server=<none>) to clients list Mon Apr 13 11:53:22 2015 : Debug: rlm_sql (sql): Read entry nasname=10.127.200.253,shortname=Solarwinds,secret=nms Mon Apr 13 11:53:22 2015 : Debug: rlm_sql (sql): Adding client 10.127.200.253 (Solarwinds, server=<none>) to clients list Mon Apr 13 11:53:22 2015 : Debug: rlm_sql (sql): Read entry nasname=10.126.35.2,shortname=DPGWLC,secret=dpg Mon Apr 13 11:53:22 2015 : Debug: rlm_sql (sql): Adding client 10.126.35.2 (DPGWLC, server=<none>) to clients list Mon Apr 13 11:53:22 2015 : Debug: rlm_sql (sql): Released sql socket id: 4 Mon Apr 13 11:53:22 2015 : Debug: Module: Checking session {...} for more modules to load Mon Apr 13 11:53:22 2015 : Debug: Module: Checking post-proxy {...} for more modules to load Mon Apr 13 11:53:22 2015 : Debug: Module: Checking post-auth {...} for more modules to load Mon Apr 13 11:53:22 2015 : Debug: (Loaded rlm_attr_filter, checking if it's valid) Mon Apr 13 11:53:22 2015 : Debug: Module: Linked to module rlm_attr_filter Mon Apr 13 11:53:22 2015 : Debug: Module: Instantiating module "attr_filter.access_reject" from file /etc/freeradius/modules/attr_filter Mon Apr 13 11:53:22 2015 : Debug: attr_filter attr_filter.access_reject { Mon Apr 13 11:53:22 2015 : Debug: attrsfile = "/etc/freeradius/attrs.access_reject" Mon Apr 13 11:53:22 2015 : Debug: key = "%{User-Name}" Mon Apr 13 11:53:22 2015 : Debug: } Mon Apr 13 11:53:22 2015 : Debug: } # modules Mon Apr 13 11:53:22 2015 : Debug: } # server Mon Apr 13 11:53:22 2015 : Debug: server { # from file /etc/freeradius/radiusd.conf Mon Apr 13 11:53:22 2015 : Debug: modules { Mon Apr 13 11:53:22 2015 : Debug: Module: Checking authenticate {...} for more modules to load Mon Apr 13 11:53:22 2015 : Debug: Module: Checking authorize {...} for more modules to load Mon Apr 13 11:53:22 2015 : Debug: (Loaded rlm_preprocess, checking if it's valid) Mon Apr 13 11:53:22 2015 : Debug: Module: Linked to module rlm_preprocess Mon Apr 13 11:53:22 2015 : Debug: Module: Instantiating module "preprocess" from file /etc/freeradius/modules/preprocess Mon Apr 13 11:53:22 2015 : Debug: preprocess { Mon Apr 13 11:53:22 2015 : Debug: huntgroups = "/etc/freeradius/huntgroups" Mon Apr 13 11:53:22 2015 : Debug: hints = "/etc/freeradius/hints" Mon Apr 13 11:53:22 2015 : Debug: with_ascend_hack = no Mon Apr 13 11:53:22 2015 : Debug: ascend_channels_per_line = 23 Mon Apr 13 11:53:22 2015 : Debug: with_ntdomain_hack = no Mon Apr 13 11:53:22 2015 : Debug: with_specialix_jetstream_hack = no Mon Apr 13 11:53:22 2015 : Debug: with_cisco_vsa_hack = no Mon Apr 13 11:53:22 2015 : Debug: with_alvarion_vsa_hack = no Mon Apr 13 11:53:22 2015 : Debug: } Mon Apr 13 11:53:22 2015 : Debug: (Loaded rlm_sqlcounter, checking if it's valid) Mon Apr 13 11:53:22 2015 : Debug: Module: Linked to module rlm_sqlcounter Mon Apr 13 11:53:22 2015 : Debug: Module: Instantiating module "dailycounter" from file /etc/freeradius/sql/mysql/counter.conf Mon Apr 13 11:53:22 2015 : Debug: sqlcounter dailycounter { Mon Apr 13 11:53:22 2015 : Debug: counter-name = "Daily-Session-Time" Mon Apr 13 11:53:22 2015 : Debug: check-name = "Max-Daily-Session" Mon Apr 13 11:53:22 2015 : Debug: reply-name = "Session-Timeout" Mon Apr 13 11:53:22 2015 : Debug: key = "User-Name" Mon Apr 13 11:53:22 2015 : Debug: sqlmod-inst = "sql" Mon Apr 13 11:53:22 2015 : Debug: query = "SELECT IFNULL(SUM(acctsessiontime - GREATEST((%b - UNIX_TIMESTAMP(acctstarttime)), 0)),0) FROM radacct WHERE username = '%{%k}' AND UNIX_TIMESTAMP(acctstarttime) + acctsessiontime > '%b'" Mon Apr 13 11:53:22 2015 : Debug: reset = "daily" Mon Apr 13 11:53:22 2015 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" Mon Apr 13 11:53:22 2015 : Debug: } Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Reply attribute Session-Timeout is number 27 Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Counter attribute Daily-Session-Time is number 11273 Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Check attribute Max-Daily-Session is number 11274 Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Current Time: 1428915202 [2015-04-13 11:53:22], Next reset 1428958800 [2015-04-14 00:00:00] Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Current Time: 1428915202 [2015-04-13 11:53:22], Prev reset 1428872400 [2015-04-13 00:00:00] Mon Apr 13 11:53:22 2015 : Debug: Module: Instantiating module "monthlycounter" from file /etc/freeradius/sql/mysql/counter.conf Mon Apr 13 11:53:22 2015 : Debug: sqlcounter monthlycounter { Mon Apr 13 11:53:22 2015 : Debug: counter-name = "Monthly-Session-Time" Mon Apr 13 11:53:22 2015 : Debug: check-name = "Max-Monthly-Session" Mon Apr 13 11:53:22 2015 : Debug: reply-name = "Session-Timeout" Mon Apr 13 11:53:22 2015 : Debug: key = "User-Name" Mon Apr 13 11:53:22 2015 : Debug: sqlmod-inst = "sql" Mon Apr 13 11:53:22 2015 : Debug: query = "SELECT IFNULL(SUM(acctsessiontime - GREATEST((%b - UNIX_TIMESTAMP(acctstarttime)), 0)),0) FROM radacct WHERE username='%{%k}' AND UNIX_TIMESTAMP(acctstarttime) + acctsessiontime > '%b'" Mon Apr 13 11:53:22 2015 : Debug: reset = "monthly" Mon Apr 13 11:53:22 2015 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" Mon Apr 13 11:53:22 2015 : Debug: } Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Reply attribute Session-Timeout is number 27 Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Counter attribute Monthly-Session-Time is number 11275 Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Check attribute Max-Monthly-Session is number 11276 Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Current Time: 1428915202 [2015-04-13 11:53:22], Next reset 1430427600 [2015-05-01 00:00:00] Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Current Time: 1428915202 [2015-04-13 11:53:22], Prev reset 1427835600 [2015-04-01 00:00:00] Mon Apr 13 11:53:22 2015 : Debug: Module: Instantiating module "weeklycounter" from file /etc/freeradius/sql/mysql/counter.conf Mon Apr 13 11:53:22 2015 : Debug: sqlcounter weeklycounter { Mon Apr 13 11:53:22 2015 : Debug: counter-name = "Weekly-Session-Time" Mon Apr 13 11:53:22 2015 : Debug: check-name = "Max-Weekly-Session" Mon Apr 13 11:53:22 2015 : Debug: key = "User-Name" Mon Apr 13 11:53:22 2015 : Debug: sqlmod-inst = "sql" Mon Apr 13 11:53:22 2015 : Debug: query = "SELECT IFNULL(SUM(AcctSessionTime),0) FROM radacct WHERE UserName='%{%k}'" Mon Apr 13 11:53:22 2015 : Debug: reset = "weekly" Mon Apr 13 11:53:22 2015 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" Mon Apr 13 11:53:22 2015 : Debug: } Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Reply attribute set to Session-Timeout. Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Counter attribute Weekly-Session-Time is number 11277 Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Check attribute Max-Weekly-Session is number 11278 Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Current Time: 1428915202 [2015-04-13 11:53:22], Next reset 1429390800 [2015-04-19 00:00:00] Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Current Time: 1428915202 [2015-04-13 11:53:22], Prev reset 1428354000 [2015-04-07 00:00:00] Mon Apr 13 11:53:22 2015 : Debug: Module: Instantiating module "quaterlycounter" from file /etc/freeradius/sql/mysql/counter.conf Mon Apr 13 11:53:22 2015 : Debug: sqlcounter quaterlycounter { Mon Apr 13 11:53:22 2015 : Debug: counter-name = "Quaterly-Session-Time" Mon Apr 13 11:53:22 2015 : Debug: check-name = "Max-Quaterly-Session" Mon Apr 13 11:53:22 2015 : Debug: key = "User-Name" Mon Apr 13 11:53:22 2015 : Debug: sqlmod-inst = "sql" Mon Apr 13 11:53:22 2015 : Debug: query = "SELECT IFNULL(SUM(AcctSessionTime),0) FROM radacct WHERE UserName='%{%k}'" Mon Apr 13 11:53:22 2015 : Debug: reset = "3m" Mon Apr 13 11:53:22 2015 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" Mon Apr 13 11:53:22 2015 : Debug: } Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Reply attribute set to Session-Timeout. Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Counter attribute Quaterly-Session-Time is number 11279 Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Check attribute Max-Quaterly-Session is number 11280 Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: num=3, last=m Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Current Time: 1428915202 [2015-04-13 11:53:22], Next reset 1435698000 [2015-07-01 00:00:00] Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: num=3, last=m Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Current Time: 1428915202 [2015-04-13 11:53:22], Prev reset 1422738000 [2015-02-01 00:00:00] Mon Apr 13 11:53:22 2015 : Debug: Module: Instantiating module "yearlycounter" from file /etc/freeradius/sql/mysql/counter.conf Mon Apr 13 11:53:22 2015 : Debug: sqlcounter yearlycounter { Mon Apr 13 11:53:22 2015 : Debug: counter-name = "Yearly-Session-Time" Mon Apr 13 11:53:22 2015 : Debug: check-name = "Max-Yearly-Session" Mon Apr 13 11:53:22 2015 : Debug: key = "User-Name" Mon Apr 13 11:53:22 2015 : Debug: sqlmod-inst = "sql" Mon Apr 13 11:53:22 2015 : Debug: query = "SELECT IFNULL(SUM(AcctSessionTime),0) FROM radacct WHERE UserName='%{%k}'" Mon Apr 13 11:53:22 2015 : Debug: reset = "12m" Mon Apr 13 11:53:22 2015 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" Mon Apr 13 11:53:22 2015 : Debug: } Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Reply attribute set to Session-Timeout. Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Counter attribute Yearly-Session-Time is number 11281 Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Check attribute Max-Yearly-Session is number 11282 Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: num=12, last=m Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Current Time: 1428915202 [2015-04-13 11:53:22], Next reset 1459458000 [2016-04-01 00:00:00] Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: num=12, last=m Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Current Time: 1428915202 [2015-04-13 11:53:22], Prev reset 1398891600 [2014-05-01 00:00:00] Mon Apr 13 11:53:22 2015 : Debug: Module: Instantiating module "noresetcounter" from file /etc/freeradius/sql/mysql/counter.conf Mon Apr 13 11:53:22 2015 : Debug: sqlcounter noresetcounter { Mon Apr 13 11:53:22 2015 : Debug: counter-name = "Max-All-Session-Time" Mon Apr 13 11:53:22 2015 : Debug: check-name = "Max-All-Session" Mon Apr 13 11:53:22 2015 : Debug: key = "User-Name" Mon Apr 13 11:53:22 2015 : Debug: sqlmod-inst = "sql" Mon Apr 13 11:53:22 2015 : Debug: query = "SELECT IFNULL(SUM(AcctSessionTime),0) FROM radacct WHERE UserName='%{%k}'" Mon Apr 13 11:53:22 2015 : Debug: reset = "never" Mon Apr 13 11:53:22 2015 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" Mon Apr 13 11:53:22 2015 : Debug: } Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Reply attribute set to Session-Timeout. Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Counter attribute Max-All-Session-Time is number 11283 Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Check attribute Max-All-Session is number 11284 Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Current Time: 1428915202 [2015-04-13 11:53:22], Next reset 0 [2015-04-13 11:00:00] Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Current Time: 1428915202 [2015-04-13 11:53:22], Prev reset 0 [2015-04-13 11:00:00] Mon Apr 13 11:53:22 2015 : Debug: Module: Instantiating module "accessperiod" from file /etc/freeradius/sql/mysql/counter.conf Mon Apr 13 11:53:22 2015 : Debug: sqlcounter accessperiod { Mon Apr 13 11:53:22 2015 : Debug: counter-name = "Max-Access-Period-Never" Mon Apr 13 11:53:22 2015 : Debug: check-name = "Access-Period" Mon Apr 13 11:53:22 2015 : Debug: key = "User-Name" Mon Apr 13 11:53:22 2015 : Debug: sqlmod-inst = "sql" Mon Apr 13 11:53:22 2015 : Debug: query = "SELECT IF(COUNT(radacctid>=1),(UNIX_TIMESTAMP() - IFNULL(UNIX_TIMESTAMP(AcctStartTime),0)),0) FROM radacct WHERE UserName = '%{%k}' AND AcctSessionTime >= 1 ORDER BY AcctStartTime LIMIT 1" Mon Apr 13 11:53:22 2015 : Debug: reset = "never" Mon Apr 13 11:53:22 2015 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" Mon Apr 13 11:53:22 2015 : Debug: } Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Reply attribute set to Session-Timeout. Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Counter attribute Max-Access-Period-Never is number 11285 Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Check attribute Access-Period is number 11286 Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Current Time: 1428915202 [2015-04-13 11:53:22], Next reset 0 [2015-04-13 11:00:00] Mon Apr 13 11:53:22 2015 : Debug: rlm_sqlcounter: Current Time: 1428915202 [2015-04-13 11:53:22], Prev reset 0 [2015-04-13 11:00:00] Mon Apr 13 11:53:22 2015 : Debug: Module: Checking preacct {...} for more modules to load Mon Apr 13 11:53:22 2015 : Debug: (Loaded rlm_acct_unique, checking if it's valid) Mon Apr 13 11:53:22 2015 : Debug: Module: Linked to module rlm_acct_unique Mon Apr 13 11:53:22 2015 : Debug: Module: Instantiating module "acct_unique" from file /etc/freeradius/modules/acct_unique Mon Apr 13 11:53:22 2015 : Debug: acct_unique { Mon Apr 13 11:53:22 2015 : Debug: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address" Mon Apr 13 11:53:22 2015 : Debug: } Mon Apr 13 11:53:22 2015 : Debug: Module: Checking accounting {...} for more modules to load Mon Apr 13 11:53:22 2015 : Debug: (Loaded rlm_detail, checking if it's valid) Mon Apr 13 11:53:22 2015 : Debug: Module: Linked to module rlm_detail Mon Apr 13 11:53:22 2015 : Debug: Module: Instantiating module "detail" from file /etc/freeradius/modules/detail Mon Apr 13 11:53:22 2015 : Debug: detail { Mon Apr 13 11:53:22 2015 : Debug: detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d" Mon Apr 13 11:53:22 2015 : Debug: header = "%t" Mon Apr 13 11:53:22 2015 : Debug: detailperm = 384 Mon Apr 13 11:53:22 2015 : Debug: dirperm = 493 Mon Apr 13 11:53:22 2015 : Debug: locking = no Mon Apr 13 11:53:22 2015 : Debug: log_packet_header = no Mon Apr 13 11:53:22 2015 : Debug: } Mon Apr 13 11:53:22 2015 : Debug: Module: Instantiating module "attr_filter.accounting_response" from file /etc/freeradius/modules/attr_filter Mon Apr 13 11:53:22 2015 : Debug: attr_filter attr_filter.accounting_response { Mon Apr 13 11:53:22 2015 : Debug: attrsfile = "/etc/freeradius/attrs.accounting_response" Mon Apr 13 11:53:22 2015 : Debug: key = "%{User-Name}" Mon Apr 13 11:53:22 2015 : Debug: } Mon Apr 13 11:53:22 2015 : Debug: Module: Checking session {...} for more modules to load Mon Apr 13 11:53:22 2015 : Debug: Module: Checking post-proxy {...} for more modules to load Mon Apr 13 11:53:22 2015 : Debug: Module: Checking post-auth {...} for more modules to load Mon Apr 13 11:53:22 2015 : Debug: } # modules Mon Apr 13 11:53:22 2015 : Debug: } # server Mon Apr 13 11:53:22 2015 : Debug: radiusd: #### Opening IP addresses and Ports #### Mon Apr 13 11:53:22 2015 : Debug: listen { Mon Apr 13 11:53:22 2015 : Debug: type = "auth" Mon Apr 13 11:53:22 2015 : Debug: ipaddr = * Mon Apr 13 11:53:22 2015 : Debug: port = 0 Mon Apr 13 11:53:22 2015 : Debug: } Mon Apr 13 11:53:22 2015 : Debug: listen { Mon Apr 13 11:53:22 2015 : Debug: type = "acct" Mon Apr 13 11:53:22 2015 : Debug: ipaddr = * Mon Apr 13 11:53:22 2015 : Debug: port = 0 Mon Apr 13 11:53:22 2015 : Debug: } Mon Apr 13 11:53:22 2015 : Debug: listen { Mon Apr 13 11:53:22 2015 : Debug: type = "auth" Mon Apr 13 11:53:22 2015 : Debug: ipaddr = 127.0.0.1 Mon Apr 13 11:53:22 2015 : Debug: port = 18120 Mon Apr 13 11:53:22 2015 : Debug: } Mon Apr 13 11:53:22 2015 : Debug: Listening on authentication address * port 1812 Mon Apr 13 11:53:22 2015 : Debug: Listening on accounting address * port 1813 Mon Apr 13 11:53:22 2015 : Debug: Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel Mon Apr 13 11:53:22 2015 : Debug: Listening on proxy address * port 1814 Mon Apr 13 11:53:23 2015 : Info: Ready to process requests. rad_recv: Access-Request packet from host 10.126.35.2 port 32769, id=48, length=216 User-Name = "idtest" User-Password = "test" Service-Type = Login-User NAS-IP-Address = 10.126.35.2 NAS-Port = 13 Cisco-AVPair = "audit-session-id=0a7e2302002bdd02552b82f6" Framed-IP-Address = 192.168.19.27 NAS-Identifier = "DPG_WLC5508Prime" NAS-Port-Type = Wireless-802.11 Airespace-Wlan-Id = 8 Calling-Station-Id = "cc-c3-ea-17-b6-25" Called-Station-Id = "08-cc-68-90-81-b0:TEST" Message-Authenticator = 0xe4314432eee48107bf9ba656b2ef3df7 Mon Apr 13 11:53:45 2015 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Mon Apr 13 11:53:45 2015 : Info: +- entering group authorize {...} Mon Apr 13 11:53:45 2015 : Info: ++[preprocess] returns ok Mon Apr 13 11:53:45 2015 : Info: sql_xlat Mon Apr 13 11:53:45 2015 : Info: expand: %{User-Name} -> idtest Mon Apr 13 11:53:45 2015 : Info: sql_set_user escaped user --> 'idtest' Mon Apr 13 11:53:45 2015 : Info: expand: select groupname from radhuntgroup where nasipaddress="%{NAS-IP-Address}" -> select groupname from radhuntgroup where nasipaddress="10.126.35.2" Mon Apr 13 11:53:45 2015 : Debug: rlm_sql (sql): Reserving sql socket id: 1 Mon Apr 13 11:53:45 2015 : Info: SQL query did not return any results Mon Apr 13 11:53:45 2015 : Debug: rlm_sql (sql): Released sql socket id: 1 Mon Apr 13 11:53:45 2015 : Info: expand: %{sql:select groupname from radhuntgroup where nasipaddress="%{NAS-IP-Address}"} -> Mon Apr 13 11:53:45 2015 : Info: ++[request] returns ok Mon Apr 13 11:53:45 2015 : Info: ++[chap] returns noop Mon Apr 13 11:53:45 2015 : Info: ++[mschap] returns noop Mon Apr 13 11:53:45 2015 : Info: [suffix] No '@' in User-Name = "idtest", looking up realm NULL Mon Apr 13 11:53:45 2015 : Info: [suffix] No such realm "NULL" Mon Apr 13 11:53:45 2015 : Info: ++[suffix] returns noop Mon Apr 13 11:53:45 2015 : Info: [eap] No EAP-Message, not doing EAP Mon Apr 13 11:53:45 2015 : Info: ++[eap] returns noop Mon Apr 13 11:53:45 2015 : Info: ++[unix] returns notfound Mon Apr 13 11:53:45 2015 : Info: ++[files] returns noop Mon Apr 13 11:53:45 2015 : Info: [sql] expand: %{User-Name} -> idtest Mon Apr 13 11:53:45 2015 : Info: [sql] sql_set_user escaped user --> 'idtest' Mon Apr 13 11:53:45 2015 : Debug: rlm_sql (sql): Reserving sql socket id: 0 Mon Apr 13 11:53:45 2015 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = BINARY '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = BINARY 'idtest' ORDER BY id Mon Apr 13 11:53:45 2015 : Info: [sql] User found in radcheck table Mon Apr 13 11:53:45 2015 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = BINARY '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = BINARY 'idtest' ORDER BY id Mon Apr 13 11:53:45 2015 : Info: [sql] expand: SELECT groupname FROM radusergroup WHERE username = BINARY '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = BINARY 'idtest' ORDER BY priority Mon Apr 13 11:53:45 2015 : Info: [sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'WLAN_TEST' ORDER BY id Mon Apr 13 11:53:45 2015 : Debug: rlm_sql (sql): Released sql socket id: 0 Mon Apr 13 11:53:45 2015 : Info: ++[sql] returns ok Mon Apr 13 11:53:45 2015 : Debug: rlm_sqlcounter: Entering module authorize code Mon Apr 13 11:53:45 2015 : Debug: rlm_sqlcounter: Could not find Check item value pair Mon Apr 13 11:53:45 2015 : Info: ++[dailycounter] returns noop Mon Apr 13 11:53:45 2015 : Debug: rlm_sqlcounter: Entering module authorize code Mon Apr 13 11:53:45 2015 : Debug: rlm_sqlcounter: Could not find Check item value pair Mon Apr 13 11:53:45 2015 : Info: ++[monthlycounter] returns noop Mon Apr 13 11:53:45 2015 : Debug: rlm_sqlcounter: Entering module authorize code Mon Apr 13 11:53:45 2015 : Debug: rlm_sqlcounter: Could not find Check item value pair Mon Apr 13 11:53:45 2015 : Info: ++[weeklycounter] returns noop Mon Apr 13 11:53:45 2015 : Debug: rlm_sqlcounter: Entering module authorize code Mon Apr 13 11:53:45 2015 : Debug: rlm_sqlcounter: Could not find Check item value pair Mon Apr 13 11:53:45 2015 : Info: ++[quaterlycounter] returns noop Mon Apr 13 11:53:45 2015 : Debug: rlm_sqlcounter: Entering module authorize code Mon Apr 13 11:53:45 2015 : Debug: rlm_sqlcounter: Could not find Check item value pair Mon Apr 13 11:53:45 2015 : Info: ++[yearlycounter] returns noop Mon Apr 13 11:53:45 2015 : Debug: rlm_sqlcounter: Entering module authorize code Mon Apr 13 11:53:45 2015 : Debug: rlm_sqlcounter: Could not find Check item value pair Mon Apr 13 11:53:45 2015 : Info: ++[noresetcounter] returns noop Mon Apr 13 11:53:45 2015 : Debug: rlm_sqlcounter: Entering module authorize code Mon Apr 13 11:53:45 2015 : Debug: rlm_sqlcounter: Could not find Check item value pair Mon Apr 13 11:53:45 2015 : Info: ++[accessperiod] returns noop Mon Apr 13 11:53:45 2015 : Info: ++[expiration] returns noop Mon Apr 13 11:53:45 2015 : Info: ++[logintime] returns noop Mon Apr 13 11:53:45 2015 : Info: ++[pap] returns updated Mon Apr 13 11:53:45 2015 : Info: Found Auth-Type = PAP Mon Apr 13 11:53:45 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default Mon Apr 13 11:53:45 2015 : Info: +- entering group PAP {...} Mon Apr 13 11:53:45 2015 : Info: [pap] login attempt with password "test" Mon Apr 13 11:53:45 2015 : Info: [pap] Using clear text password "test" Mon Apr 13 11:53:45 2015 : Info: [pap] User authenticated successfully Mon Apr 13 11:53:45 2015 : Info: ++[pap] returns ok Mon Apr 13 11:53:45 2015 : Info: # Executing section post-auth from file /etc/freeradius/sites-enabled/default Mon Apr 13 11:53:45 2015 : Info: +- entering group post-auth {...} Mon Apr 13 11:53:45 2015 : Info: [sql] expand: %{User-Name} -> idtest Mon Apr 13 11:53:45 2015 : Info: [sql] sql_set_user escaped user --> 'idtest' Mon Apr 13 11:53:45 2015 : Info: [sql] expand: %{User-Password} -> test Mon Apr 13 11:53:45 2015 : Info: [sql] expand: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'idtest', 'test', 'Access-Accept', '2015-04-13 11:53:45') Mon Apr 13 11:53:45 2015 : Debug: rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'idtest', 'test', 'Access-Accept', '2015-04-13 11:53:45') Mon Apr 13 11:53:45 2015 : Debug: rlm_sql (sql): Reserving sql socket id: 4 Mon Apr 13 11:53:45 2015 : Debug: rlm_sql (sql): Released sql socket id: 4 Mon Apr 13 11:53:45 2015 : Info: ++[sql] returns ok Mon Apr 13 11:53:45 2015 : Info: ++[exec] returns noop Sending Access-Accept of id 48 to 10.126.35.2 port 32769 Mon Apr 13 11:53:45 2015 : Info: Finished request 2. Mon Apr 13 11:53:45 2015 : Debug: Going to the next request Mon Apr 13 11:53:45 2015 : Debug: Waking up in 4.9 seconds. rad_recv: Accounting-Request packet from host 10.126.35.2 port 32769, id=45, length=248 User-Name = "idtest" NAS-Port = 13 NAS-IP-Address = 10.126.35.2 Framed-IP-Address = 192.168.19.27 Framed-IPv6-Prefix = fe80::/64 NAS-Identifier = "DPG_WLC5508Prime" Airespace-Wlan-Id = 8 Acct-Session-Id = "552b8310/cc:c3:ea:17:b6:25/11808" NAS-Port-Type = Wireless-802.11 Cisco-AVPair = "audit-session-id=0a7e2302002bdd02552b82f6" Acct-Authentic = RADIUS Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "318" Event-Timestamp = "Apr 13 2015 11:49:20 AST" Acct-Status-Type = Start Calling-Station-Id = "192.168.19.27" Called-Station-Id = "10.126.35.2" Mon Apr 13 11:53:45 2015 : Info: # Executing section preacct from file /etc/freeradius/sites-enabled/default Mon Apr 13 11:53:45 2015 : Info: +- entering group preacct {...} Mon Apr 13 11:53:45 2015 : Info: ++[preprocess] returns ok Mon Apr 13 11:53:45 2015 : Info: [acct_unique] Hashing 'Client-IP-Address = 10.126.35.2,NAS-IP-Address = 10.126.35.2,Acct-Session-Id = "552b8310/cc:c3:ea:17:b6:25/11808",User-Name = "idtest"' Mon Apr 13 11:53:45 2015 : Info: [acct_unique] Acct-Unique-Session-ID = "a427a01270b006a8". Mon Apr 13 11:53:45 2015 : Info: ++[acct_unique] returns ok Mon Apr 13 11:53:45 2015 : Info: [suffix] No '@' in User-Name = "idtest", looking up realm NULL Mon Apr 13 11:53:45 2015 : Info: [suffix] No such realm "NULL" Mon Apr 13 11:53:45 2015 : Info: ++[suffix] returns noop Mon Apr 13 11:53:45 2015 : Info: ++[files] returns noop Mon Apr 13 11:53:45 2015 : Info: # Executing section accounting from file /etc/freeradius/sites-enabled/default Mon Apr 13 11:53:45 2015 : Info: +- entering group accounting {...} Mon Apr 13 11:53:45 2015 : Info: [detail] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d -> /var/log/freeradius/radacct/10.126.35.2/detail-20150413 Mon Apr 13 11:53:45 2015 : Info: [detail] /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/freeradius/radacct/10.126.35.2/detail-20150413 Mon Apr 13 11:53:45 2015 : Info: [detail] expand: %t -> Mon Apr 13 11:53:45 2015 Mon Apr 13 11:53:45 2015 : Info: ++[detail] returns ok Mon Apr 13 11:53:45 2015 : Info: ++[unix] returns ok Mon Apr 13 11:53:45 2015 : Info: [sql] expand: %{User-Name} -> idtest Mon Apr 13 11:53:45 2015 : Info: [sql] sql_set_user escaped user --> 'idtest' Mon Apr 13 11:53:45 2015 : Info: [sql] expand: %{Acct-Delay-Time} -> Mon Apr 13 11:53:45 2015 : Info: [sql] ... expanding second conditional Mon Apr 13 11:53:45 2015 : Info: [sql] expand: 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}', Mon Apr 13 11:53:45 2015 : Debug: rlm_sql (sql): Reserving sql socket id: 3 Mon Apr 13 11:53:45 2015 : Debug: rlm_sql (sql): Released sql socket id: 3 Mon Apr 13 11:53:45 2015 : Info: ++[sql] returns ok Mon Apr 13 11:53:45 2015 : Info: ++[exec] returns noop Mon Apr 13 11:53:45 2015 : Info: [attr_filter.accounting_response] expand: %{User-Name} -> idtest Mon Apr 13 11:53:45 2015 : Debug: attr_filter: Matched entry DEFAULT at line 12 Mon Apr 13 11:53:45 2015 : Info: ++[attr_filter.accounting_response] returns updated Sending Accounting-Response of id 45 to 10.126.35.2 port 32769 Mon Apr 13 11:53:45 2015 : Info: Finished request 3. Mon Apr 13 11:53:45 2015 : Info: Cleaning up request 3 ID 45 with timestamp +23 Mon Apr 13 11:53:45 2015 : Debug: Going to the next request Mon Apr 13 11:53:45 2015 : Debug: Waking up in 4.8 seconds. Mon Apr 13 11:53:50 2015 : Info: Cleaning up request 2 ID 48 with timestamp +23 Mon Apr 13 11:53:50 2015 : Info: Ready to process requests. ^C