Re[2]: Group membership

Олег Кобелев na_krul at mail.ru
Mon Apr 13 10:56:16 CEST 2015


 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 at 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 at 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 at 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


More information about the Freeradius-Users mailing list