Hi,

I can't really see any errors in the debug output below (Sorry if it's long, I just copy and pasted from debug)



Mon Sep  1 15:54:20 2014 : Info: radiusd: FreeRADIUS Version 2.2.1, for host i686-pc-linux-gnu, built on Aug 13 2014 at 13:27:52
Mon Sep  1 15:54:20 2014 : Debug: Server was built with:
Mon Sep  1 15:54:20 2014 : Debug:   accounting
Mon Sep  1 15:54:20 2014 : Debug:   authentication
Mon Sep  1 15:54:20 2014 : Debug:  WITH_DHCP
Mon Sep  1 15:54:20 2014 : Debug:  WITH_VMPS
Mon Sep  1 15:54:20 2014 : Debug: Server core libs:
Mon Sep  1 15:54:20 2014 : Debug:   ssl: OpenSSL 1.0.1e-fips 11 Feb 2013
Mon Sep  1 15:54:20 2014 : Info: Copyright (C) 1999-2013 The FreeRADIUS server project and contributors.
Mon Sep  1 15:54:20 2014 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
Mon Sep  1 15:54:20 2014 : Info: PARTICULAR PURPOSE.
Mon Sep  1 15:54:20 2014 : Info: You may redistribute copies of FreeRADIUS under the terms of the
Mon Sep  1 15:54:20 2014 : Info: GNU General Public License.
Mon Sep  1 15:54:20 2014 : Info: For more information about these matters, see the file named COPYRIGHT.
Mon Sep  1 15:54:20 2014 : Info: Starting - reading configuration files ...
Mon Sep  1 15:54:20 2014 : Debug: including configuration file /etc/raddb/radiusd.conf
Mon Sep  1 15:54:20 2014 : Debug: including configuration file /etc/raddb/proxy.conf
Mon Sep  1 15:54:20 2014 : Debug: including configuration file /etc/raddb/clients.conf
Mon Sep  1 15:54:20 2014 : Debug: including configuration file /etc/raddb/snmp.conf
Mon Sep  1 15:54:20 2014 : Debug: including configuration file /etc/raddb/eap.conf
Mon Sep  1 15:54:20 2014 : Debug: including configuration file /etc/raddb/sql.conf
Mon Sep  1 15:54:20 2014 : Debug: main {
Mon Sep  1 15:54:20 2014 : Debug:       allow_core_dumps = no
Mon Sep  1 15:54:20 2014 : Debug: }
Mon Sep  1 15:54:20 2014 : Debug: including dictionary file /etc/raddb/dictionary
Mon Sep  1 15:54:20 2014 : Debug: main {
Mon Sep  1 15:54:20 2014 : Debug:       name = "radiusd"
Mon Sep  1 15:54:20 2014 : Debug:       prefix = "/usr"
Mon Sep  1 15:54:20 2014 : Debug:       localstatedir = "/var"
Mon Sep  1 15:54:20 2014 : Debug:       sbindir = "/usr/sbin"
Mon Sep  1 15:54:20 2014 : Debug:       logdir = "/var/log/radius"
Mon Sep  1 15:54:20 2014 : Debug:       run_dir = "/var/run/radiusd"
Mon Sep  1 15:54:20 2014 : Debug:       libdir = "/usr/lib"
Mon Sep  1 15:54:20 2014 : Debug:       radacctdir = "/var/log/radius/radacct"
Mon Sep  1 15:54:20 2014 : Debug:       hostname_lookups = no
Mon Sep  1 15:54:20 2014 : Debug:       max_request_time = 30
Mon Sep  1 15:54:20 2014 : Debug:       cleanup_delay = 5
Mon Sep  1 15:54:20 2014 : Debug:       max_requests = 1024
Mon Sep  1 15:54:20 2014 : Debug:       pidfile = "/var/run/radiusd/radiusd.pid"
Mon Sep  1 15:54:20 2014 : Debug:       checkrad = "/usr/sbin/checkrad"
Mon Sep  1 15:54:20 2014 : Debug:       debug_level = 0
Mon Sep  1 15:54:20 2014 : Debug:       proxy_requests = yes
Mon Sep  1 15:54:20 2014 : Debug:       log_auth = yes
Mon Sep  1 15:54:20 2014 : Debug:       log_auth_badpass = yes
Mon Sep  1 15:54:20 2014 : Debug:       log_auth_goodpass = no
Mon Sep  1 15:54:20 2014 : Debug:       log_stripped_names = yes
Mon Sep  1 15:54:20 2014 : Debug:  security {
Mon Sep  1 15:54:20 2014 : Debug:       max_attributes = 200
Mon Sep  1 15:54:20 2014 : Debug:       reject_delay = 1
Mon Sep  1 15:54:20 2014 : Debug:       status_server = no
Mon Sep  1 15:54:20 2014 : Debug:  }
Mon Sep  1 15:54:20 2014 : Debug: }
Mon Sep  1 15:54:20 2014 : Debug: radiusd: #### Loading Realms and Home Servers ####
Mon Sep  1 15:54:20 2014 : Debug:  proxy server {
Mon Sep  1 15:54:20 2014 : Debug:       retry_delay = 5
Mon Sep  1 15:54:20 2014 : Debug:       retry_count = 3
Mon Sep  1 15:54:20 2014 : Debug:       default_fallback = yes
Mon Sep  1 15:54:20 2014 : Debug:       dead_time = 120
Mon Sep  1 15:54:20 2014 : Debug:       wake_all_if_all_dead = no
Mon Sep  1 15:54:20 2014 : Debug:  }
Mon Sep  1 15:54:20 2014 : Debug:  home_server rad01 {
Mon Sep  1 15:54:20 2014 : Debug:       ipaddr = 192.168.25.126
Mon Sep  1 15:54:20 2014 : Debug:       port = 1813
Mon Sep  1 15:54:20 2014 : Debug:       type = "acct"
Mon Sep  1 15:54:20 2014 : Debug:       secret = "testing123"
Mon Sep  1 15:54:20 2014 : Debug:       response_window = 30
Mon Sep  1 15:54:20 2014 : Debug:       max_outstanding = 65536
Mon Sep  1 15:54:20 2014 : Debug:       require_message_authenticator = yes
Mon Sep  1 15:54:20 2014 : Debug:       zombie_period = 40
Mon Sep  1 15:54:20 2014 : Debug:       status_check = "none"
Mon Sep  1 15:54:20 2014 : Debug:       ping_interval = 30
Mon Sep  1 15:54:20 2014 : Debug:       check_interval = 30
Mon Sep  1 15:54:20 2014 : Debug:       num_answers_to_alive = 3
Mon Sep  1 15:54:20 2014 : Debug:       num_pings_to_alive = 3
Mon Sep  1 15:54:20 2014 : Debug:       revive_interval = 300
Mon Sep  1 15:54:20 2014 : Debug:       status_check_timeout = 4
Mon Sep  1 15:54:20 2014 : Debug:  }
Mon Sep  1 15:54:20 2014 : Debug:  realm LOCAL {
Mon Sep  1 15:54:20 2014 : Debug:       authhost = LOCAL
Mon Sep  1 15:54:20 2014 : Debug:       accthost = LOCAL
Mon Sep  1 15:54:20 2014 : Debug:  }
Mon Sep  1 15:54:20 2014 : Debug:  realm acc_realm {
Mon Sep  1 15:54:20 2014 : Debug:  }
Mon Sep  1 15:54:20 2014 : Debug:  home_server_pool acc1 {
Mon Sep  1 15:54:20 2014 : Debug:       home_server = rad01
Mon Sep  1 15:54:20 2014 : Debug:  }
Mon Sep  1 15:54:20 2014 : Debug: radiusd: #### Loading Clients ####
Mon Sep  1 15:54:20 2014 : Debug:  client 127.0.0.1 {
Mon Sep  1 15:54:20 2014 : Debug:       require_message_authenticator = no
Mon Sep  1 15:54:20 2014 : Debug:       secret = "testING123"
Mon Sep  1 15:54:20 2014 : Debug:       shortname = "localhost"
Mon Sep  1 15:54:20 2014 : Debug:       nastype = "other"
Mon Sep  1 15:54:20 2014 : Debug:  }
Mon Sep  1 15:54:20 2014 : Debug:  client 192.168.25.126 {
Mon Sep  1 15:54:20 2014 : Debug:       require_message_authenticator = no
Mon Sep  1 15:54:20 2014 : Debug:       secret = "testing123"
Mon Sep  1 15:54:20 2014 : Debug:       shortname = "backup"
Mon Sep  1 15:54:20 2014 : Debug:  }
Mon Sep  1 15:54:20 2014 : Debug: radiusd: #### Instantiating modules ####
Mon Sep  1 15:54:20 2014 : Debug:  instantiate {
Mon Sep  1 15:54:20 2014 : Debug:     (Loaded rlm_exec, checking if it's valid)
Mon Sep  1 15:54:20 2014 : Debug:  Module: Linked to module rlm_exec
Mon Sep  1 15:54:20 2014 : Debug:  Module: Instantiating module "exec" from file /etc/raddb/radiusd.conf
Mon Sep  1 15:54:20 2014 : Debug:   exec {
Mon Sep  1 15:54:20 2014 : Debug:       wait = yes
Mon Sep  1 15:54:20 2014 : Debug:       input_pairs = "request"
Mon Sep  1 15:54:20 2014 : Debug:       shell_escape = yes
Mon Sep  1 15:54:20 2014 : Debug:   }
Mon Sep  1 15:54:20 2014 : Debug:     (Loaded rlm_expr, checking if it's valid)
Mon Sep  1 15:54:20 2014 : Debug:  Module: Linked to module rlm_expr
Mon Sep  1 15:54:20 2014 : Debug:  Module: Instantiating module "expr" from file /etc/raddb/radiusd.conf
Mon Sep  1 15:54:20 2014 : Debug:  }
Mon Sep  1 15:54:20 2014 : Debug: radiusd: #### Loading Virtual Servers ####
Mon Sep  1 15:54:20 2014 : Debug: server { # from file /etc/raddb/radiusd.conf
Mon Sep  1 15:54:20 2014 : Debug:  modules {
Mon Sep  1 15:54:20 2014 : Debug:  Module: Checking authenticate {...} for more modules to load
Mon Sep  1 15:54:20 2014 : Debug:     (Loaded rlm_pap, checking if it's valid)
Mon Sep  1 15:54:20 2014 : Debug:  Module: Linked to module rlm_pap
Mon Sep  1 15:54:20 2014 : Debug:  Module: Instantiating module "pap" from file /etc/raddb/radiusd.conf
Mon Sep  1 15:54:20 2014 : Debug:   pap {
Mon Sep  1 15:54:20 2014 : Debug:       encryption_scheme = "auto"
Mon Sep  1 15:54:20 2014 : Debug:       auto_header = yes
Mon Sep  1 15:54:20 2014 : Debug:   }
Mon Sep  1 15:54:20 2014 : Debug:     (Loaded rlm_chap, checking if it's valid)
Mon Sep  1 15:54:20 2014 : Debug:  Module: Linked to module rlm_chap
Mon Sep  1 15:54:20 2014 : Debug:  Module: Instantiating module "chap" from file /etc/raddb/radiusd.conf
Mon Sep  1 15:54:20 2014 : Debug:     (Loaded rlm_mschap, checking if it's valid)
Mon Sep  1 15:54:20 2014 : Debug:  Module: Linked to module rlm_mschap
Mon Sep  1 15:54:20 2014 : Debug:  Module: Instantiating module "mschap" from file /etc/raddb/radiusd.conf
Mon Sep  1 15:54:20 2014 : Debug:   mschap {
Mon Sep  1 15:54:20 2014 : Debug:       use_mppe = yes
Mon Sep  1 15:54:20 2014 : Debug:       require_encryption = no
Mon Sep  1 15:54:20 2014 : Debug:       require_strong = no
Mon Sep  1 15:54:20 2014 : Debug:       with_ntdomain_hack = no
Mon Sep  1 15:54:20 2014 : Debug:       allow_retry = yes
Mon Sep  1 15:54:20 2014 : Debug:   }
Mon Sep  1 15:54:20 2014 : Debug:     (Loaded rlm_unix, checking if it's valid)
Mon Sep  1 15:54:20 2014 : Debug:  Module: Linked to module rlm_unix
Mon Sep  1 15:54:20 2014 : Debug:  Module: Instantiating module "unix" from file /etc/raddb/radiusd.conf
Mon Sep  1 15:54:20 2014 : Debug:   unix {
Mon Sep  1 15:54:20 2014 : Debug:       radwtmp = "/var/log/radius/radwtmp"
Mon Sep  1 15:54:20 2014 : Debug:   }
Mon Sep  1 15:54:20 2014 : Debug:     (Loaded rlm_eap, checking if it's valid)
Mon Sep  1 15:54:20 2014 : Debug:  Module: Linked to module rlm_eap
Mon Sep  1 15:54:20 2014 : Debug:  Module: Instantiating module "eap" from file /etc/raddb/eap.conf
Mon Sep  1 15:54:20 2014 : Debug:   eap {
Mon Sep  1 15:54:20 2014 : Debug:       default_eap_type = "md5"
Mon Sep  1 15:54:20 2014 : Debug:       timer_expire = 60
Mon Sep  1 15:54:20 2014 : Debug:       ignore_unknown_eap_types = no
Mon Sep  1 15:54:20 2014 : Debug:       cisco_accounting_username_bug = no
Mon Sep  1 15:54:20 2014 : Debug:       max_sessions = 2048
Mon Sep  1 15:54:20 2014 : Debug:   }
Mon Sep  1 15:54:20 2014 : Debug:  Module: Linked to sub-module rlm_eap_md5
Mon Sep  1 15:54:20 2014 : Debug:  Module: Instantiating eap-md5
Mon Sep  1 15:54:20 2014 : Debug:  Module: Linked to sub-module rlm_eap_leap
Mon Sep  1 15:54:20 2014 : Debug:  Module: Instantiating eap-leap
Mon Sep  1 15:54:20 2014 : Debug:  Module: Linked to sub-module rlm_eap_gtc
Mon Sep  1 15:54:20 2014 : Debug:  Module: Instantiating eap-gtc
Mon Sep  1 15:54:20 2014 : Debug:    gtc {
Mon Sep  1 15:54:20 2014 : Debug:       challenge = "Password: "
Mon Sep  1 15:54:20 2014 : Debug:       auth_type = "PAP"
Mon Sep  1 15:54:20 2014 : Debug:    }
Mon Sep  1 15:54:20 2014 : Debug:  Module: Linked to sub-module rlm_eap_mschapv2
Mon Sep  1 15:54:20 2014 : Debug:  Module: Instantiating eap-mschapv2
Mon Sep  1 15:54:20 2014 : Debug:    mschapv2 {
Mon Sep  1 15:54:20 2014 : Debug:       with_ntdomain_hack = no
Mon Sep  1 15:54:20 2014 : Debug:       send_error = no
Mon Sep  1 15:54:20 2014 : Debug:    }
Mon Sep  1 15:54:20 2014 : Debug:  Module: Checking authorize {...} for more modules to load
Mon Sep  1 15:54:20 2014 : Debug:     (Loaded rlm_preprocess, checking if it's valid)
Mon Sep  1 15:54:20 2014 : Debug:  Module: Linked to module rlm_preprocess
Mon Sep  1 15:54:20 2014 : Debug:  Module: Instantiating module "preprocess" from file /etc/raddb/radiusd.conf
Mon Sep  1 15:54:20 2014 : Debug:   preprocess {
Mon Sep  1 15:54:20 2014 : Debug:       huntgroups = "/etc/raddb/huntgroups"
Mon Sep  1 15:54:20 2014 : Debug:       hints = "/etc/raddb/hints"
Mon Sep  1 15:54:20 2014 : Debug:       with_ascend_hack = no
Mon Sep  1 15:54:20 2014 : Debug:       ascend_channels_per_line = 23
Mon Sep  1 15:54:20 2014 : Debug:       with_ntdomain_hack = no
Mon Sep  1 15:54:20 2014 : Debug:       with_specialix_jetstream_hack = no
Mon Sep  1 15:54:20 2014 : Debug:       with_cisco_vsa_hack = no
Mon Sep  1 15:54:20 2014 : Debug:       with_alvarion_vsa_hack = no
Mon Sep  1 15:54:20 2014 : Debug:   }
Mon Sep  1 15:54:20 2014 : Debug: reading pairlist file /etc/raddb/huntgroups
Mon Sep  1 15:54:20 2014 : Debug: reading pairlist file /etc/raddb/hints
Mon Sep  1 15:54:20 2014 : Debug:     (Loaded rlm_realm, checking if it's valid)
Mon Sep  1 15:54:20 2014 : Debug:  Module: Linked to module rlm_realm
Mon Sep  1 15:54:20 2014 : Debug:  Module: Instantiating module "suffix" from file /etc/raddb/radiusd.conf
Mon Sep  1 15:54:20 2014 : Debug:   realm suffix {
Mon Sep  1 15:54:20 2014 : Debug:       format = "suffix"
Mon Sep  1 15:54:20 2014 : Debug:       delimiter = "@"
Mon Sep  1 15:54:20 2014 : Debug:       ignore_default = no
Mon Sep  1 15:54:20 2014 : Debug:       ignore_null = no
Mon Sep  1 15:54:20 2014 : Debug:   }
Mon Sep  1 15:54:20 2014 : Debug:     (Loaded rlm_files, checking if it's valid)
Mon Sep  1 15:54:20 2014 : Debug:  Module: Linked to module rlm_files
Mon Sep  1 15:54:20 2014 : Debug:  Module: Instantiating module "files" from file /etc/raddb/radiusd.conf
Mon Sep  1 15:54:20 2014 : Debug:   files {
Mon Sep  1 15:54:20 2014 : Debug:       usersfile = "/etc/raddb/users"
Mon Sep  1 15:54:20 2014 : Debug:       acctusersfile = "/etc/raddb/acct_users"
Mon Sep  1 15:54:20 2014 : Debug:       preproxy_usersfile = "/etc/raddb/preproxy_users"
Mon Sep  1 15:54:20 2014 : Debug:       compat = "no"
Mon Sep  1 15:54:20 2014 : Debug:   }
Mon Sep  1 15:54:20 2014 : Debug: reading pairlist file /etc/raddb/users
Mon Sep  1 15:54:20 2014 : Debug: reading pairlist file /etc/raddb/acct_users
Mon Sep  1 15:54:20 2014 : Debug: reading pairlist file /etc/raddb/preproxy_users
Mon Sep  1 15:54:20 2014 : Debug:     (Loaded rlm_sql, checking if it's valid)
Mon Sep  1 15:54:20 2014 : Debug:  Module: Linked to module rlm_sql
Mon Sep  1 15:54:20 2014 : Debug:  Module: Instantiating module "sql" from file /etc/raddb/sql.conf
Mon Sep  1 15:54:20 2014 : Debug:   sql {
Mon Sep  1 15:54:20 2014 : Debug:       driver = "rlm_sql_mysql"
Mon Sep  1 15:54:20 2014 : Debug:       server = "localhost"
Mon Sep  1 15:54:20 2014 : Debug:       port = ""
Mon Sep  1 15:54:20 2014 : Debug:       login = "radius"
Mon Sep  1 15:54:20 2014 : Debug:       password = "XXXX"
Mon Sep  1 15:54:20 2014 : Debug:       radius_db = "radius"
Mon Sep  1 15:54:20 2014 : Debug:       read_groups = yes
Mon Sep  1 15:54:20 2014 : Debug:       sqltrace = no
Mon Sep  1 15:54:20 2014 : Debug:       sqltracefile = "/var/log/radius/sqltrace.sql"
Mon Sep  1 15:54:20 2014 : Debug:       readclients = no
Mon Sep  1 15:54:20 2014 : Debug:       deletestalesessions = yes
Mon Sep  1 15:54:20 2014 : Debug:       num_sql_socks = 25
Mon Sep  1 15:54:20 2014 : Debug:       lifetime = 0
Mon Sep  1 15:54:20 2014 : Debug:       max_queries = 0
Mon Sep  1 15:54:20 2014 : Debug:       sql_user_name = "%{User-Name}"
Mon Sep  1 15:54:20 2014 : Debug:       default_user_profile = ""
Mon Sep  1 15:54:20 2014 : Debug:       nas_query = "SELECT id,nasname,shortname,type,secret FROM nas" ...
...
Mon Sep  1 15:54:21 2014 : Debug: rlm_sql (sql): starting 24
Mon Sep  1 15:54:21 2014 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #24
Mon Sep  1 15:54:21 2014 : Info: rlm_sql_mysql: Starting connect to MySQL server for #24
Mon Sep  1 15:54:21 2014 : Info: rlm_sql (sql): Connected new DB handle, #24
Mon Sep  1 15:54:21 2014 : Debug:  Module: Checking preacct {...} for more modules to load
Mon Sep  1 15:54:21 2014 : Debug:     (Loaded rlm_acct_unique, checking if it's valid)
Mon Sep  1 15:54:21 2014 : Debug:  Module: Linked to module rlm_acct_unique
Mon Sep  1 15:54:21 2014 : Debug:  Module: Instantiating module "acct_unique" from file /etc/raddb/radiusd.conf
Mon Sep  1 15:54:21 2014 : Debug:   acct_unique {
Mon Sep  1 15:54:21 2014 : Debug:       key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
Mon Sep  1 15:54:21 2014 : Debug:   }
Mon Sep  1 15:54:21 2014 : Debug:  Module: Checking accounting {...} for more modules to load
Mon Sep  1 15:54:21 2014 : Debug:     (Loaded rlm_detail, checking if it's valid)
Mon Sep  1 15:54:21 2014 : Debug:  Module: Linked to module rlm_detail
Mon Sep  1 15:54:21 2014 : Debug:  Module: Instantiating module "detail" from file /etc/raddb/radiusd.conf
Mon Sep  1 15:54:21 2014 : Debug:   detail {
Mon Sep  1 15:54:21 2014 : Debug:       detailfile = "/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
Mon Sep  1 15:54:21 2014 : Debug:       header = "%t"
Mon Sep  1 15:54:21 2014 : Debug:       detailperm = 384
Mon Sep  1 15:54:21 2014 : Debug:       dirperm = 493
Mon Sep  1 15:54:21 2014 : Debug:       locking = no
Mon Sep  1 15:54:21 2014 : Debug:       log_packet_header = no
Mon Sep  1 15:54:21 2014 : Debug:   }
Mon Sep  1 15:54:21 2014 : Debug:     (Loaded rlm_radutmp, checking if it's valid)
Mon Sep  1 15:54:21 2014 : Debug:  Module: Linked to module rlm_radutmp
Mon Sep  1 15:54:21 2014 : Debug:  Module: Instantiating module "radutmp" from file /etc/raddb/radiusd.conf
Mon Sep  1 15:54:21 2014 : Debug:   radutmp {
Mon Sep  1 15:54:21 2014 : Debug:       filename = "/var/log/radius/radutmp"
Mon Sep  1 15:54:21 2014 : Debug:       username = "%{User-Name}"
Mon Sep  1 15:54:21 2014 : Debug:       case_sensitive = yes
Mon Sep  1 15:54:21 2014 : Debug:       check_with_nas = yes
Mon Sep  1 15:54:21 2014 : Debug:       perm = 384
Mon Sep  1 15:54:21 2014 : Debug:       callerid = yes
Mon Sep  1 15:54:21 2014 : Debug:   }
Mon Sep  1 15:54:21 2014 : Debug:  Module: Checking session {...} for more modules to load
Mon Sep  1 15:54:21 2014 : Debug:  Module: Checking post-proxy {...} for more modules to load
Mon Sep  1 15:54:21 2014 : Debug:  } # modules
Mon Sep  1 15:54:21 2014 : Debug: } # server
Mon Sep  1 15:54:21 2014 : Debug: radiusd: #### Opening IP addresses and Ports ####
Mon Sep  1 15:54:21 2014 : Debug:       bind_address = *
Mon Sep  1 15:54:21 2014 : Info: WARNING: The directive 'bind_address' is deprecated, and will be removed in future versions of FreeRADIUS. Please edit the configuration files to use the directive 'listen'.
Mon Sep  1 15:54:21 2014 : Debug:  ... adding new socket proxy address * port 36384
Mon Sep  1 15:54:21 2014 : Debug: Listening on authentication address * port 1812
Mon Sep  1 15:54:21 2014 : Debug: Listening on accounting address * port 1813
Mon Sep  1 15:54:21 2014 : Debug: Listening on proxy address * port 1814
Mon Sep  1 15:54:21 2014 : Info: Ready to process requests.
rad_recv: Accounting-Request packet from host 192.168.25.157 port 57086, id=161, length=258
        Service-Type = Framed-User
        Framed-Protocol = PPP
        NAS-Port = 8388670
        NAS-Port-Type = Ethernet
        User-Name = "wireless-test@ewireless.co.za"
        Calling-Station-Id = "60:A4:4C:01:EF:73"
        NAS-Port-Id = "ether2"
        MS-CHAP-Domain = "ewireless.co.za"
        Acct-Session-Id = "8100003e"
        Framed-IP-Address = 41.222.51.72
        Acct-Authentic = RADIUS
        Event-Timestamp = "Sep  1 2014 15:54:32 SAST"
        Acct-Session-Time = 707
        Acct-Input-Octets = 251662
        Acct-Input-Gigawords = 0
        Acct-Input-Packets = 3094
        Acct-Output-Octets = 114
        Acct-Output-Gigawords = 0
        Acct-Output-Packets = 9
        Acct-Status-Type = Stop
        Acct-Terminate-Cause = User-Request
        NAS-Identifier = "Btester-Client"
        Acct-Delay-Time = 0
        Mikrotik-Realm = "ewireless.co.za"
        NAS-IP-Address = 192.168.25.157
Mon Sep  1 15:54:32 2014 : Info: # Executing section preacct from file /etc/raddb/radiusd.conf
Mon Sep  1 15:54:32 2014 : Info: +group preacct {
Mon Sep  1 15:54:32 2014 : Info: ++[preprocess] = ok
Mon Sep  1 15:54:32 2014 : Info: [acct_unique] Hashing 'NAS-Port = 8388670,Client-IP-Address = 192.168.25.157,NAS-IP-Address = 192.168.25.157,Acct-Session-Id = "8100003e",User-Name = "wireless-test@ewireless.co.za"'
Mon Sep  1 15:54:32 2014 : Info: [acct_unique] Acct-Unique-Session-ID = "bda8cde3047e1119".
Mon Sep  1 15:54:32 2014 : Info: ++[acct_unique] = ok
Mon Sep  1 15:54:32 2014 : Info: [suffix] Looking up realm "ewireless.co.za" for User-Name = "wireless-test@ewireless.co.za"
Mon Sep  1 15:54:32 2014 : Info: [suffix] No such realm "ewireless.co.za"
Mon Sep  1 15:54:32 2014 : Info: ++[suffix] = noop
Mon Sep  1 15:54:32 2014 : Info: ++[files] = noop
Mon Sep  1 15:54:32 2014 : Info: +} # group preacct = noop
Mon Sep  1 15:54:32 2014 : Info: # Executing section accounting from file /etc/raddb/radiusd.conf
Mon Sep  1 15:54:32 2014 : Info: +group preacct {
Mon Sep  1 15:54:32 2014 : Info: ++[preprocess] = ok
Mon Sep  1 15:54:32 2014 : Info: [acct_unique] Hashing 'NAS-Port = 8388670,Client-IP-Address = 192.168.25.157,NAS-IP-Address = 192.168.25.157,Acct-Session-Id = "8100003e",User-Name = "wireless-test@ewireless.co.za"'
Mon Sep  1 15:54:32 2014 : Info: [acct_unique] Acct-Unique-Session-ID = "bda8cde3047e1119".
Mon Sep  1 15:54:32 2014 : Info: ++[acct_unique] = ok
Mon Sep  1 15:54:32 2014 : Info: [suffix] Looking up realm "ewireless.co.za" for User-Name = "wireless-test@ewireless.co.za"
Mon Sep  1 15:54:32 2014 : Info: [suffix] No such realm "ewireless.co.za"
Mon Sep  1 15:54:32 2014 : Info: ++[suffix] = noop
Mon Sep  1 15:54:32 2014 : Info: ++[files] = noop
Mon Sep  1 15:54:32 2014 : Info: +} # group preacct = noop
Mon Sep  1 15:54:32 2014 : Info: # Executing section accounting from file /etc/raddb/radiusd.conf
Mon Sep  1 15:54:32 2014 : Info: +group accounting {
Mon Sep  1 15:54:32 2014 : Info: [detail]       expand: /var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d -> /var/log/radius/radacct/192.168.25.157/detail-20140901
Mon Sep  1 15:54:32 2014 : Info: [detail] /var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/radius/radacct/192.168.25.157/detail-20140901
Mon Sep  1 15:54:32 2014 : Info: [detail]       expand: %t -> Mon Sep  1 15:54:32 2014
Mon Sep  1 15:54:32 2014 : Info: ++[detail] = ok
Mon Sep  1 15:54:32 2014 : Info: ++[unix] = ok
Mon Sep  1 15:54:32 2014 : Info: [radutmp]      expand: /var/log/radius/radutmp -> /var/log/radius/radutmp
Mon Sep  1 15:54:32 2014 : Info: [radutmp]      expand: %{User-Name} -> wireless-test@ewireless.co.za
Mon Sep  1 15:54:32 2014 : Info: ++[radutmp] = ok
Mon Sep  1 15:54:32 2014 : Info: [sql]  expand: %{User-Name} -> wireless-test@ewireless.co.za
Mon Sep  1 15:54:32 2014 : Info: [sql] sql_set_user escaped user --> 'wireless-test@ewireless.co.za'
Mon Sep  1 15:54:32 2014 : Info: [sql] WARNING: Deprecated conditional expansion ":-".  See "man unlang" for details
Mon Sep  1 15:54:32 2014 : Info: [sql] WARNING: Deprecated conditional expansion ":-".  See "man unlang" for details
Mon Sep  1 15:54:32 2014 : Info: [sql] WARNING: Deprecated conditional expansion ":-".  See "man unlang" for details
Mon Sep  1 15:54:32 2014 : Info: [sql] WARNING: Deprecated conditional expansion ":-".  See "man unlang" for details
Mon Sep  1 15:54:32 2014 : Info: [sql] WARNING: Deprecated conditional expansion ":-".  See "man unlang" for details
Mon Sep  1 15:54:32 2014 : Info: [sql]  expand:            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}',               _AcctTime         = NOW()           WHERE AcctSessionId   = '%{Acct-Session-Id}'           AND UserName          = '%{SQL-User-Name}'           AND NASIPAddress      = '%{NAS-IP-Address}' ->            UPDATE radacct SET              AcctStopTime       = '2014-09-01 15:54:32',              AcctSessionTime    = '707',              AcctInputOctets    = '0' << 32 |                                   '251662',              AcctO
Mon Sep  1 15:54:32 2014 : Debug: rlm_sql (sql): Reserving sql socket id: 24
Mon Sep  1 15:54:34 2014 : Debug: rlm_sql (sql): Released sql socket id: 24
Mon Sep  1 15:54:34 2014 : Info: ++[sql] = ok
Mon Sep  1 15:54:34 2014 : Info: +} # group accounting = ok
Sending Accounting-Response of id 161 to 192.168.25.157 port 57086
Mon Sep  1 15:54:34 2014 : Info: Finished request 0.
Mon Sep  1 15:54:34 2014 : Info: Cleaning up request 0 ID 161 with timestamp +11
Mon Sep  1 15:54:34 2014 : Debug: Going to the next request
Mon Sep  1 15:54:34 2014 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 192.168.25.157 port 50309, id=162, length=252
        Service-Type = Framed-User
        Framed-Protocol = PPP
        NAS-Port = 8388671
        NAS-Port-Type = Ethernet
        User-Name = "wireless-test@ewireless.co.za"
        Calling-Station-Id = "60:A4:4C:01:EF:73"
        NAS-Port-Id = "ether2"
        MS-CHAP-Domain = "ewireless.co.za"
        MS-CHAP-Challenge = 0x94ae72c572678c29987d8043f608ca91
        MS-CHAP2-Response = 0x0100f6f2494700414227dbb3b5337fc4612b00000000000000001bbd6a3bdee078c819b2116b2bc2fa8da2985ab43bc6b55e
        NAS-Identifier = "Btester-Client"
        Mikrotik-Realm = "ewireless.co.za"
        NAS-IP-Address = 192.168.25.157
Mon Sep  1 15:54:34 2014 : Info: # Executing section authorize from file /etc/raddb/radiusd.conf
Mon Sep  1 15:54:34 2014 : Info: +group authorize {
Mon Sep  1 15:54:34 2014 : Info: ++[preprocess] = ok
Mon Sep  1 15:54:34 2014 : Info: ++[chap] = noop
Mon Sep  1 15:54:34 2014 : Info: [mschap] Found MS-CHAP attributes.  Setting 'Auth-Type  = mschap'
Mon Sep  1 15:54:34 2014 : Info: ++[mschap] = ok
Mon Sep  1 15:54:34 2014 : Info: [suffix] Looking up realm "ewireless.co.za" for User-Name = "wireless-test@ewireless.co.za"
Mon Sep  1 15:54:34 2014 : Info: [suffix] No such realm "ewireless.co.za"
Mon Sep  1 15:54:34 2014 : Info: ++[suffix] = noop
Mon Sep  1 15:54:34 2014 : Info: [eap] No EAP-Message, not doing EAP
Mon Sep  1 15:54:34 2014 : Info: ++[eap] = noop
Mon Sep  1 15:54:34 2014 : Info: [files] users: Matched entry DEFAULT at line 172
Mon Sep  1 15:54:34 2014 : Info: [files] users: Matched entry DEFAULT at line 184
Mon Sep  1 15:54:34 2014 : Info: ++[files] = ok
Mon Sep  1 15:54:34 2014 : Info: [sql]  expand: %{User-Name} -> wireless-test@ewireless.co.za
Mon Sep  1 15:54:34 2014 : Info: [sql] sql_set_user escaped user --> 'wireless-test@ewireless.co.za'
Mon Sep  1 15:54:34 2014 : Debug: rlm_sql (sql): Reserving sql socket id: 23
Mon Sep  1 15:54:34 2014 : Info: [sql]  expand: SELECT Auth.id, Auth.UserName, Auth.Attribute, Auth.Value, Auth.op      FROM radcheck Auth      LEFT JOIN rt_users Users            ON Users.username = Auth.UserName   WHERE Auth.Username = '%{SQL-User-Name}'        AND (       Users.lock_number IS NULL        OR             LENGTH(Users.lock_number) = 0           OR      Users.lock_number = '%{Calling-Station-Id}'             )   ORDER BY Auth.id -> SELECT Auth.id, Auth.UserName, Auth.Attribute, Auth.Value, Auth.op  FROM radcheck Auth      LEFT JOIN rt_users Users            ON Users.username = Auth.UserName   WHERE Auth.Username = 'wireless-test@ewireless.co.za'   AND (       Users.lock_number IS NULL        OR             LENGTH(Users.lock_number) = 0           OR      Users.lock_number = '60:A4:4C:01:EF:73'         )   ORDER BY Auth.id
Mon Sep  1 15:54:34 2014 : Info: [sql] User found in radcheck table
Mon Sep  1 15:54:34 2014 : Info: [sql]  expand: SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, UserName, Attribute, Value, op           FROM radreply           WHERE Username = 'wireless-test@ewireless.co.za'           ORDER BY id
Mon Sep  1 15:54:34 2014 : Info: [sql]  expand: SELECT GroupName FROM usergroup WHERE UserName='%{SQL-User-Name}' -> SELECT GroupName FROM usergroup WHERE UserName='wireless-test@ewireless.c







On Mon, Sep 1, 2014 at 3:43 PM, Fajar A. Nugraha <work@fajar.net> wrote:
what does the debug mide say?


On Monday, September 1, 2014, Daren Hendricks <daren.hendricks@gmail.com> wrote:
Any other ideas? or what I'm missing?


On Mon, Sep 1, 2014 at 2:34 PM, Daren Hendricks <daren.hendricks@gmail.com> wrote:
Hi,

Yes I have called 'replicate' in accounting section and it is after the 'Replicate-To-Realm:= acc_realm' section.

Regards,


On Mon, Sep 1, 2014 at 12:11 PM, Fajar A. Nugraha <list@fajar.net> wrote:
On Mon, Sep 1, 2014 at 4:22 PM, Daren Hendricks <daren.hendricks@gmail.com> wrote:
Hi,

Thank you,I have looked into using rlm_replicate but I do not seem to be coming right. Below is what's in proxy.conf


home_server rad01 {
        type = acct
        ipaddr = 192.168.25.126
        port = 1813
        secret = testing123
}

home_server_pool otp0 {
        home_server = otp1
        home_server = rad01
}
home_server_pool acc1 {
        home_server = rad01
        
}
realm acc_realm {
        act_pool = acc1
}




... and did you call "replicate" on your accounting section?
Did you set Replicate-To-Realm before calling "replicate"?


-- 
Fajar

 

On Tue, Aug 26, 2014 at 11:53 AM, Fajar A. Nugraha <list@fajar.net> wrote:
On Tue, Aug 26, 2014 at 3:28 PM, Daren Hendricks <daren.hendricks@gmail.com> wrote:
Hi Everyone,

We have 2 radius servers (v2.2.1) a primary and secondary. Currently both use same mysql database that lives on the primary server. For HA sake we would like to have the following setup. The primary server will read/write to it's radius DB and that will be replicated using mysql replication to the secondary server. The secondary server will then read/write to the replicated db and forward/proxy it's accounting data to the primary server. 
Does this sound like a feasible solution?

No.

You should either:
- replicate the packets at radius level, and have each radius write (both packets that it received directly and the forward packets) to its own db. OR
- use active-active db replication (e.g. galera)

 
Also, what can we use to forward the accounting data to the primary server, would robust-proxy-accounting be something worth looking into?


Depends on your need. robust-proxy-accounting should work, but on some setup it might end up filling the disk (e.g. when bad home server rejects some packets).

Personally I prefer rlm_replicate, which is very fast but might lose some accounting packets due to it's send-and-forget menchanism (I'm fine with that).

-- 
Fajar

-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html


-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html


-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html



-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html