Freeradius-Users
Threads by month
- ----- 2026 -----
- July
- June
- May
- April
- March
- February
- January
- ----- 2025 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2024 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2023 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2022 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2021 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2020 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2019 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2018 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2017 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2016 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2015 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2014 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2013 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2012 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2011 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2010 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2009 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2008 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2007 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2006 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2005 -----
- December
- November
- October
- September
- August
- July
- June
- May
June 2016
- 75 participants
- 90 discussions
Hello,
I was using freeradius 2.1 for a while, and at some point I had to make
robust proxy accounting solution.
While testing I ran into problem with multiplying Proxy-State, described
here: http://permalink.gmane.org/gmane.comp.freeradius.devel/6276
Hence I decided to move to 3.0.4 (installed from networkradius.com repo)
I discarded all old configs I had and making setup from scratch, at first
stage trying to make minimum changes in examples.
Now I'm trying to make work/understand following scenario:
- start freeradius with only one upstream servers alive (home1 is alive,
home2 initially dead)
- auth with client (pptp + radiusclient)
- stop alive upstream server (home1 dies, so no server will respond to
Interim-Update)
acct data starts to get logged into detail.examle.com/ folder
- then I bring up home1, it's clear from logs that radius server marks it
"alive"
but detail polling never goes on, i.e detail files remain on disk
if I restart freeradius it polls detail files immediately and send to
upstream
I spent a while trying to debug/understand what's going on, but at this
point I'm stuck, thus asking for help.
configs and log are too long to include in mail, so created gists:
debug log:
https://gist.github.com/dzinevich/56b3259246b62a36d2ed62836b181fac
configs: https://gist.github.com/dzinevich/cd7d8510093293f4b9fab49f60535918
--
Denis
2
2
Hello,
I am trying to access http://bugs.freeradius.org/ and it is coming up
with a '500 Internal Server Error'.
John.
--
John Horne Tel: +44 (0)1752 587287
Plymouth University, UK
3
2
On a Alix (32bit HW) with a Voyage V0.10 (Debian derevative) I am
following this guide:
http://wiki.freeradius.org/building/Build
tar zxvf freeradius-<version>.tar.gz
./configure
make
su - root
make install
(It misses you have to change dir, but I can figure that out :)
When i (as root) type make, I end up with this message:
checking for _talloc in -ltalloc in /usr/local/lib... no
checking for _talloc in -ltalloc in /opt/lib... no
configure: WARNING: talloc library not found. Use
--with-talloc-lib-dir=<path>.
configure: error: FreeRADIUS requires libtalloc
So I try to install libtalloc
# apt-get install libtalloc
Reading package lists... Done
Building dependency tree
Reading state information... Done
E: Unable to locate package libtalloc
Same thing happens when I try: # apt-get install libtallocl
Can anybode tell my what the lib is called so I can install it.
(Presuming the problem is that simple)
--
-------------------------------------------
Med venlig hilsen / Yours Sincerly
Henrik Kressner
kressner(a)synkro.dk
3
3
Hello, everyone.
I try to change the username attribute in the request by the result of
sql select query:
if ("%{sql_main:select count(id) from vbmacs where mac='%{User-Name}'}"
> "0") {
update request {
User-Name = "%{sql_main:select phone from vbmacs where
mac='%{User-Name}'}"
}
}
else {
reject
}
This code is placed in authorize section after module preprocess.
But in debug I see "update request = noop" after successful expanding of
sql query result.
Can you help me with this issue?
root@debian:/etc/freeradius/sql/mysql# freeradius -XXX
Wed Jun 29 19:01:07 2016 : Info: freeradius: FreeRADIUS Version 2.2.5,
for host x86_64-pc-linux-gnu, built on Oct 28 2014 at 16:27:11
Wed Jun 29 19:01:07 2016 : Debug: Server was built with:
Wed Jun 29 19:01:07 2016 : Debug: accounting
Wed Jun 29 19:01:07 2016 : Debug: authentication
Wed Jun 29 19:01:07 2016 : Debug: WITH_DHCP
Wed Jun 29 19:01:07 2016 : Debug: WITH_VMPS
Wed Jun 29 19:01:07 2016 : Debug: Server core libs:
Wed Jun 29 19:01:07 2016 : Debug: ssl: OpenSSL 1.0.1e 11 Feb 2013
Wed Jun 29 19:01:07 2016 : Info: Copyright (C) 1999-2013 The FreeRADIUS
server project and contributors.
Wed Jun 29 19:01:07 2016 : Info: There is NO warranty; not even for
MERCHANTABILITY or FITNESS FOR A
Wed Jun 29 19:01:07 2016 : Info: PARTICULAR PURPOSE.
Wed Jun 29 19:01:07 2016 : Info: You may redistribute copies of
FreeRADIUS under the terms of the
Wed Jun 29 19:01:07 2016 : Info: GNU General Public License.
Wed Jun 29 19:01:07 2016 : Info: For more information about these
matters, see the file named COPYRIGHT.
Wed Jun 29 19:01:07 2016 : Info: Starting - reading configuration files
...
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/radiusd.conf
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/proxy.conf
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/clients.conf
Wed Jun 29 19:01:07 2016 : Debug: including files in directory
/etc/freeradius/modules/
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/detail
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/rediswho
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/linelog
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/mac2ip
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/ippool
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/perl
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/echo
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/replicate
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/sql_log
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/realm
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/attr_filter
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/counter
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/detail.example.com
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/always
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/smsotp
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/wimax
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/pam
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/dhcp_sqlippool
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/soh
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/etc_group
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/detail.log
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/attr_rewrite
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/mac2vlan
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/cui
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/ldap
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/redis
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/dynamic_clients
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/digest
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/checkval
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/expiration
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/passwd
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/pap
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/policy
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/unix
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/preprocess
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/cache
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/sqlcounter_expire_on_login
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/chap
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/radutmp
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/logintime
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/otp
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/expr
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/radrelay
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/mschap
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/acct_unique
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/smbpasswd
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/sradutmp
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/opendirectory
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/exec
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/ntlm_auth
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/krb5
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/inner-eap
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/modules/files
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/eap.conf
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/sql.conf
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/sql/mysql/dialup.conf
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/sql/mysql/mac-filter-sql.conf
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/policy.conf
Wed Jun 29 19:01:07 2016 : Debug: including files in directory
/etc/freeradius/sites-enabled/
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/sites-enabled/default
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/sql/mysql/mac-filter.conf
Wed Jun 29 19:01:07 2016 : Debug: including configuration file
/etc/freeradius/sites-enabled/inner-tunnel
Wed Jun 29 19:01:07 2016 : Debug: main {
Wed Jun 29 19:01:07 2016 : Debug: user = "freerad"
Wed Jun 29 19:01:07 2016 : Debug: group = "freerad"
Wed Jun 29 19:01:07 2016 : Debug: allow_core_dumps = no
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: including dictionary file
/etc/freeradius/dictionary
Wed Jun 29 19:01:07 2016 : Debug: main {
Wed Jun 29 19:01:07 2016 : Debug: name = "freeradius"
Wed Jun 29 19:01:07 2016 : Debug: prefix = "/usr"
Wed Jun 29 19:01:07 2016 : Debug: localstatedir = "/var"
Wed Jun 29 19:01:07 2016 : Debug: sbindir = "/usr/sbin"
Wed Jun 29 19:01:07 2016 : Debug: logdir = "/var/log/freeradius"
Wed Jun 29 19:01:07 2016 : Debug: run_dir = "/var/run/freeradius"
Wed Jun 29 19:01:07 2016 : Debug: libdir = "/usr/lib/freeradius"
Wed Jun 29 19:01:07 2016 : Debug: radacctdir =
"/var/log/freeradius/radacct"
Wed Jun 29 19:01:07 2016 : Debug: hostname_lookups = no
Wed Jun 29 19:01:07 2016 : Debug: max_request_time = 30
Wed Jun 29 19:01:07 2016 : Debug: cleanup_delay = 5
Wed Jun 29 19:01:07 2016 : Debug: max_requests = 1024
Wed Jun 29 19:01:07 2016 : Debug: pidfile =
"/var/run/freeradius/freeradius.pid"
Wed Jun 29 19:01:07 2016 : Debug: checkrad = "/usr/sbin/checkrad"
Wed Jun 29 19:01:07 2016 : Debug: debug_level = 0
Wed Jun 29 19:01:07 2016 : Debug: proxy_requests = no
Wed Jun 29 19:01:07 2016 : Debug: log {
Wed Jun 29 19:01:07 2016 : Debug: stripped_names = no
Wed Jun 29 19:01:07 2016 : Debug: auth = no
Wed Jun 29 19:01:07 2016 : Debug: auth_badpass = no
Wed Jun 29 19:01:07 2016 : Debug: auth_goodpass = no
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: security {
Wed Jun 29 19:01:07 2016 : Debug: max_attributes = 200
Wed Jun 29 19:01:07 2016 : Debug: reject_delay = 0
Wed Jun 29 19:01:07 2016 : Debug: status_server = yes
Wed Jun 29 19:01:07 2016 : Debug: allow_vulnerable_openssl = yes
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: radiusd: #### Loading Realms and Home
Servers ####
Wed Jun 29 19:01:07 2016 : Debug: proxy server {
Wed Jun 29 19:01:07 2016 : Debug: retry_delay = 5
Wed Jun 29 19:01:07 2016 : Debug: retry_count = 3
Wed Jun 29 19:01:07 2016 : Debug: default_fallback = no
Wed Jun 29 19:01:07 2016 : Debug: dead_time = 120
Wed Jun 29 19:01:07 2016 : Debug: wake_all_if_all_dead = no
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: home_server localhost {
Wed Jun 29 19:01:07 2016 : Debug: ipaddr = 127.0.0.1
Wed Jun 29 19:01:07 2016 : Debug: port = 1812
Wed Jun 29 19:01:07 2016 : Debug: type = "auth"
Wed Jun 29 19:01:07 2016 : Debug: secret = "testing123"
Wed Jun 29 19:01:07 2016 : Debug: response_window = 20
Wed Jun 29 19:01:07 2016 : Debug: max_outstanding = 65536
Wed Jun 29 19:01:07 2016 : Debug: require_message_authenticator =
yes
Wed Jun 29 19:01:07 2016 : Debug: zombie_period = 40
Wed Jun 29 19:01:07 2016 : Debug: status_check = "status-server"
Wed Jun 29 19:01:07 2016 : Debug: ping_interval = 30
Wed Jun 29 19:01:07 2016 : Debug: check_interval = 30
Wed Jun 29 19:01:07 2016 : Debug: num_answers_to_alive = 3
Wed Jun 29 19:01:07 2016 : Debug: num_pings_to_alive = 3
Wed Jun 29 19:01:07 2016 : Debug: revive_interval = 120
Wed Jun 29 19:01:07 2016 : Debug: status_check_timeout = 4
Wed Jun 29 19:01:07 2016 : Debug: coa {
Wed Jun 29 19:01:07 2016 : Debug: irt = 2
Wed Jun 29 19:01:07 2016 : Debug: mrt = 16
Wed Jun 29 19:01:07 2016 : Debug: mrc = 5
Wed Jun 29 19:01:07 2016 : Debug: mrd = 30
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: home_server_pool my_auth_failover {
Wed Jun 29 19:01:07 2016 : Debug: type = fail-over
Wed Jun 29 19:01:07 2016 : Debug: home_server = localhost
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: realm example.com {
Wed Jun 29 19:01:07 2016 : Debug: auth_pool = my_auth_failover
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: realm LOCAL {
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: radiusd: #### Loading Clients ####
Wed Jun 29 19:01:07 2016 : Debug: client localhost {
Wed Jun 29 19:01:07 2016 : Debug: ipaddr = 127.0.0.1
Wed Jun 29 19:01:07 2016 : Debug: require_message_authenticator =
no
Wed Jun 29 19:01:07 2016 : Debug: secret = "testing123"
Wed Jun 29 19:01:07 2016 : Debug: nastype = "other"
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: radiusd: #### Instantiating modules
####
Wed Jun 29 19:01:07 2016 : Debug: instantiate {
Wed Jun 29 19:01:07 2016 : Debug: (Loaded rlm_exec, checking if it's
valid)
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to module rlm_exec
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating module "exec"
from file /etc/freeradius/modules/exec
Wed Jun 29 19:01:07 2016 : Debug: exec {
Wed Jun 29 19:01:07 2016 : Debug: wait = no
Wed Jun 29 19:01:07 2016 : Debug: input_pairs = "request"
Wed Jun 29 19:01:07 2016 : Debug: shell_escape = yes
Wed Jun 29 19:01:07 2016 : Debug: timeout = 10
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: (Loaded rlm_expr, checking if it's
valid)
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to module rlm_expr
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating module "expr"
from file /etc/freeradius/modules/expr
Wed Jun 29 19:01:07 2016 : Debug: (Loaded rlm_expiration, checking
if it's valid)
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to module
rlm_expiration
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating module
"expiration" from file /etc/freeradius/modules/expiration
Wed Jun 29 19:01:07 2016 : Debug: expiration {
Wed Jun 29 19:01:07 2016 : Debug: reply-message = "Password Has
Expired "
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: (Loaded rlm_logintime, checking if
it's valid)
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to module
rlm_logintime
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating module
"logintime" from file /etc/freeradius/modules/logintime
Wed Jun 29 19:01:07 2016 : Debug: logintime {
Wed Jun 29 19:01:07 2016 : Debug: reply-message = "You are calling
outside your allowed timespan "
Wed Jun 29 19:01:07 2016 : Debug: minimum-timeout = 60
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: radiusd: #### Loading Virtual Servers
####
Wed Jun 29 19:01:07 2016 : Debug: server { # from file ▒▒▒?
Wed Jun 29 19:01:07 2016 : Debug: modules {
Wed Jun 29 19:01:07 2016 : Debug: Module: Creating Auth-Type = digest
Wed Jun 29 19:01:07 2016 : Debug: Module: Creating Post-Auth-Type =
REJECT
Wed Jun 29 19:01:07 2016 : Debug: Module: Checking authenticate {...}
for more modules to load
Wed Jun 29 19:01:07 2016 : Debug: (Loaded rlm_pap, checking if it's
valid)
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to module rlm_pap
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating module "pap"
from file /etc/freeradius/modules/pap
Wed Jun 29 19:01:07 2016 : Debug: pap {
Wed Jun 29 19:01:07 2016 : Debug: encryption_scheme = "auto"
Wed Jun 29 19:01:07 2016 : Debug: auto_header = no
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: (Loaded rlm_chap, checking if it's
valid)
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to module rlm_chap
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating module "chap"
from file /etc/freeradius/modules/chap
Wed Jun 29 19:01:07 2016 : Debug: (Loaded rlm_mschap, checking if
it's valid)
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to module rlm_mschap
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating module "mschap"
from file /etc/freeradius/modules/mschap
Wed Jun 29 19:01:07 2016 : Debug: mschap {
Wed Jun 29 19:01:07 2016 : Debug: use_mppe = yes
Wed Jun 29 19:01:07 2016 : Debug: require_encryption = no
Wed Jun 29 19:01:07 2016 : Debug: require_strong = no
Wed Jun 29 19:01:07 2016 : Debug: with_ntdomain_hack = no
Wed Jun 29 19:01:07 2016 : Debug: allow_retry = yes
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: (Loaded rlm_digest, checking if
it's valid)
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to module rlm_digest
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating module "digest"
from file /etc/freeradius/modules/digest
Wed Jun 29 19:01:07 2016 : Debug: (Loaded rlm_unix, checking if it's
valid)
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to module rlm_unix
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating module "unix"
from file /etc/freeradius/modules/unix
Wed Jun 29 19:01:07 2016 : Debug: unix {
Wed Jun 29 19:01:07 2016 : Debug: radwtmp =
"/var/log/freeradius/radwtmp"
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: (Loaded rlm_eap, checking if it's
valid)
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to module rlm_eap
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating module "eap"
from file /etc/freeradius/eap.conf
Wed Jun 29 19:01:07 2016 : Debug: eap {
Wed Jun 29 19:01:07 2016 : Debug: default_eap_type = "md5"
Wed Jun 29 19:01:07 2016 : Debug: timer_expire = 60
Wed Jun 29 19:01:07 2016 : Debug: ignore_unknown_eap_types = no
Wed Jun 29 19:01:07 2016 : Debug: cisco_accounting_username_bug =
no
Wed Jun 29 19:01:07 2016 : Debug: max_sessions = 1024
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to sub-module
rlm_eap_md5
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating eap-md5
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to sub-module
rlm_eap_leap
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating eap-leap
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to sub-module
rlm_eap_gtc
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating eap-gtc
Wed Jun 29 19:01:07 2016 : Debug: gtc {
Wed Jun 29 19:01:07 2016 : Debug: challenge = "Password: "
Wed Jun 29 19:01:07 2016 : Debug: auth_type = "PAP"
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to sub-module
rlm_eap_tls
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating eap-tls
Wed Jun 29 19:01:07 2016 : Debug: tls {
Wed Jun 29 19:01:07 2016 : Debug: rsa_key_exchange = no
Wed Jun 29 19:01:07 2016 : Debug: dh_key_exchange = yes
Wed Jun 29 19:01:07 2016 : Debug: rsa_key_length = 512
Wed Jun 29 19:01:07 2016 : Debug: dh_key_length = 512
Wed Jun 29 19:01:07 2016 : Debug: verify_depth = 0
Wed Jun 29 19:01:07 2016 : Debug: CA_path =
"/etc/freeradius/certs"
Wed Jun 29 19:01:07 2016 : Debug: pem_file_type = yes
Wed Jun 29 19:01:07 2016 : Debug: private_key_file =
"/etc/freeradius/certs/server.key"
Wed Jun 29 19:01:07 2016 : Debug: certificate_file =
"/etc/freeradius/certs/server.pem"
Wed Jun 29 19:01:07 2016 : Debug: CA_file =
"/etc/freeradius/certs/ca.pem"
Wed Jun 29 19:01:07 2016 : Debug: private_key_password =
"whatever"
Wed Jun 29 19:01:07 2016 : Debug: dh_file =
"/etc/freeradius/certs/dh"
Wed Jun 29 19:01:07 2016 : Debug: random_file = "/dev/urandom"
Wed Jun 29 19:01:07 2016 : Debug: fragment_size = 1024
Wed Jun 29 19:01:07 2016 : Debug: include_length = yes
Wed Jun 29 19:01:07 2016 : Debug: check_crl = no
Wed Jun 29 19:01:07 2016 : Debug: cipher_list = "DEFAULT"
Wed Jun 29 19:01:07 2016 : Debug: make_cert_command =
"/etc/freeradius/certs/bootstrap"
Wed Jun 29 19:01:07 2016 : Debug: ecdh_curve = "prime256v1"
Wed Jun 29 19:01:07 2016 : Debug: cache {
Wed Jun 29 19:01:07 2016 : Debug: enable = no
Wed Jun 29 19:01:07 2016 : Debug: lifetime = 24
Wed Jun 29 19:01:07 2016 : Debug: max_entries = 255
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: verify {
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: ocsp {
Wed Jun 29 19:01:07 2016 : Debug: enable = no
Wed Jun 29 19:01:07 2016 : Debug: override_cert_url = yes
Wed Jun 29 19:01:07 2016 : Debug: url = "http://127.0.0.1/ocsp/"
Wed Jun 29 19:01:07 2016 : Debug: use_nonce = yes
Wed Jun 29 19:01:07 2016 : Debug: timeout = 0
Wed Jun 29 19:01:07 2016 : Debug: softfail = no
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to sub-module
rlm_eap_ttls
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating eap-ttls
Wed Jun 29 19:01:07 2016 : Debug: ttls {
Wed Jun 29 19:01:07 2016 : Debug: default_eap_type = "md5"
Wed Jun 29 19:01:07 2016 : Debug: copy_request_to_tunnel = no
Wed Jun 29 19:01:07 2016 : Debug: use_tunneled_reply = no
Wed Jun 29 19:01:07 2016 : Debug: virtual_server = "inner-tunnel"
Wed Jun 29 19:01:07 2016 : Debug: include_length = yes
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to sub-module
rlm_eap_peap
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating eap-peap
Wed Jun 29 19:01:07 2016 : Debug: peap {
Wed Jun 29 19:01:07 2016 : Debug: default_eap_type = "mschapv2"
Wed Jun 29 19:01:07 2016 : Debug: copy_request_to_tunnel = no
Wed Jun 29 19:01:07 2016 : Debug: use_tunneled_reply = no
Wed Jun 29 19:01:07 2016 : Debug: proxy_tunneled_request_as_eap =
yes
Wed Jun 29 19:01:07 2016 : Debug: virtual_server = "inner-tunnel"
Wed Jun 29 19:01:07 2016 : Debug: soh = no
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to sub-module
rlm_eap_mschapv2
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating eap-mschapv2
Wed Jun 29 19:01:07 2016 : Debug: mschapv2 {
Wed Jun 29 19:01:07 2016 : Debug: with_ntdomain_hack = no
Wed Jun 29 19:01:07 2016 : Debug: send_error = no
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: Module: Checking authorize {...} for
more modules to load
Wed Jun 29 19:01:07 2016 : Debug: (Loaded rlm_preprocess, checking
if it's valid)
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to module
rlm_preprocess
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating module
"preprocess" from file /etc/freeradius/modules/preprocess
Wed Jun 29 19:01:07 2016 : Debug: preprocess {
Wed Jun 29 19:01:07 2016 : Debug: huntgroups =
"/etc/freeradius/huntgroups"
Wed Jun 29 19:01:07 2016 : Debug: hints = "/etc/freeradius/hints"
Wed Jun 29 19:01:07 2016 : Debug: with_ascend_hack = no
Wed Jun 29 19:01:07 2016 : Debug: ascend_channels_per_line = 23
Wed Jun 29 19:01:07 2016 : Debug: with_ntdomain_hack = no
Wed Jun 29 19:01:07 2016 : Debug: with_specialix_jetstream_hack =
no
Wed Jun 29 19:01:07 2016 : Debug: with_cisco_vsa_hack = no
Wed Jun 29 19:01:07 2016 : Debug: with_alvarion_vsa_hack = no
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: reading pairlist file
/etc/freeradius/huntgroups
Wed Jun 29 19:01:07 2016 : Debug: reading pairlist file
/etc/freeradius/hints
Wed Jun 29 19:01:07 2016 : Debug: (Loaded rlm_always, checking if
it's valid)
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to module rlm_always
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating module "reject"
from file /etc/freeradius/modules/always
Wed Jun 29 19:01:07 2016 : Debug: always reject {
Wed Jun 29 19:01:07 2016 : Debug: rcode = "reject"
Wed Jun 29 19:01:07 2016 : Debug: simulcount = 0
Wed Jun 29 19:01:07 2016 : Debug: mpp = no
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: (Loaded rlm_realm, checking if
it's valid)
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to module rlm_realm
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating module "suffix"
from file /etc/freeradius/modules/realm
Wed Jun 29 19:01:07 2016 : Debug: realm suffix {
Wed Jun 29 19:01:07 2016 : Debug: format = "suffix"
Wed Jun 29 19:01:07 2016 : Debug: delimiter = "@"
Wed Jun 29 19:01:07 2016 : Debug: ignore_default = no
Wed Jun 29 19:01:07 2016 : Debug: ignore_null = no
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: (Loaded rlm_files, checking if
it's valid)
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to module rlm_files
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating module "files"
from file /etc/freeradius/modules/files
Wed Jun 29 19:01:07 2016 : Debug: files {
Wed Jun 29 19:01:07 2016 : Debug: usersfile =
"/etc/freeradius/users"
Wed Jun 29 19:01:07 2016 : Debug: acctusersfile =
"/etc/freeradius/acct_users"
Wed Jun 29 19:01:07 2016 : Debug: preproxy_usersfile =
"/etc/freeradius/preproxy_users"
Wed Jun 29 19:01:07 2016 : Debug: compat = "no"
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: reading pairlist file
/etc/freeradius/users
Wed Jun 29 19:01:07 2016 : Debug: reading pairlist file
/etc/freeradius/acct_users
Wed Jun 29 19:01:07 2016 : Debug: reading pairlist file
/etc/freeradius/preproxy_users
Wed Jun 29 19:01:07 2016 : Debug: (Loaded rlm_sql, checking if it's
valid)
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to module rlm_sql
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating module
"sql_main" from file /etc/freeradius/sql.conf
Wed Jun 29 19:01:07 2016 : Debug: sql sql_main {
Wed Jun 29 19:01:07 2016 : Debug: driver = "rlm_sql_mysql"
Wed Jun 29 19:01:07 2016 : Debug: server = "localhost"
Wed Jun 29 19:01:07 2016 : Debug: port = ""
Wed Jun 29 19:01:07 2016 : Debug: login = "radius"
Wed Jun 29 19:01:07 2016 : Debug: password = "vEdf84JEXdPAuUHv"
Wed Jun 29 19:01:07 2016 : Debug: radius_db = "radius-test"
Wed Jun 29 19:01:07 2016 : Debug: read_groups = yes
Wed Jun 29 19:01:07 2016 : Debug: sqltrace = no
Wed Jun 29 19:01:07 2016 : Debug: sqltracefile =
"/var/log/freeradius/sqltrace.sql"
Wed Jun 29 19:01:07 2016 : Debug: readclients = yes
Wed Jun 29 19:01:07 2016 : Debug: deletestalesessions = yes
Wed Jun 29 19:01:07 2016 : Debug: num_sql_socks = 32
Wed Jun 29 19:01:07 2016 : Debug: lifetime = 0
Wed Jun 29 19:01:07 2016 : Debug: max_queries = 0
Wed Jun 29 19:01:07 2016 : Debug: sql_user_name = "%{User-Name}"
Wed Jun 29 19:01:07 2016 : Debug: default_user_profile = ""
Wed Jun 29 19:01:07 2016 : Debug: nas_query = "SELECT id, nasname,
shortname, type, secret, server FROM nas"
Wed Jun 29 19:01:07 2016 : Debug: authorize_check_query = "SELECT
id, username, attribute, value, op FROM radcheck
WHERE username = '%{SQL-User-Name}' ORDER BY id"
Wed Jun 29 19:01:07 2016 : Debug: authorize_reply_query = "SELECT
id, username, attribute, value, op FROM radreply
WHERE username = '%{SQL-User-Name}' ORDER BY id"
Wed Jun 29 19:01:07 2016 : Debug: authorize_group_check_query =
"SELECT id, groupname, attribute, Value, op FROM
radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER
BY id"
Wed Jun 29 19:01:07 2016 : Debug: authorize_group_reply_query =
"SELECT id, groupname, attribute, value, op FROM
radgroupreply WHERE groupname = '%{Sql-Group}' ORDER
BY id"
Wed Jun 29 19:01:07 2016 : 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'"
Wed Jun 29 19:01:07 2016 : Debug: accounting_update_query = "
UPDATE radacct SET framedipaddress =
'%{Framed-IP-Address}', acctsessiontime =
'%{Acct-Session-Time}', acctinputoctets =
'%{%{Acct-Input-Gigawords}:-0}' << 32 |
'%{%{Acct-Input-Octets}:-0}', acctoutputoctets =
'%{%{Acct-Output-Gigawords}:-0}' << 32 |
'%{%{Acct-Output-Octets}:-0}' WHERE acctsessionid =
'%{Acct-Session-Id}' AND username = '%{SQL-User-Name}'
AND nasipaddress = '%{NAS-IP-Address}'"
Wed Jun 29 19:01:07 2016 : 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}')"
Wed Jun 29 19:01:07 2016 : 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}')"
Wed Jun 29 19:01:07 2016 : 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}'"
Wed Jun 29 19:01:07 2016 : 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}'"
Wed Jun 29 19:01:07 2016 : 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}')"
Wed Jun 29 19:01:07 2016 : Debug: group_membership_query = "SELECT
groupname FROM radusergroup WHERE username =
'%{SQL-User-Name}' ORDER BY priority"
Wed Jun 29 19:01:07 2016 : Debug: connect_failure_retry_delay = 60
Wed Jun 29 19:01:07 2016 : Debug: simul_count_query = "SELECT
COUNT(*) FROM radacct
WHERE username = '%{SQL-User-Name}'
AND acctstoptime IS NULL"
Wed Jun 29 19:01:07 2016 : Debug: simul_verify_query = "SELECT
radacctid, acctsessionid, username,
nasipaddress, nasportid, framedipaddress,
callingstationid, framedprotocol FROM
radacct WHERE username =
'%{SQL-User-Name}' AND acctstoptime IS
NULL"
Wed Jun 29 19:01:07 2016 : Debug: postauth_query = "INSERT INTO
radpostauth (username, pass, reply, authdate)
VALUES (
'%{User-Name}',
'%{%{User-Password}:-%{Chap-Password}}',
'%{reply:Packet-Type}', '%S')"
Wed Jun 29 19:01:07 2016 : Debug: safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql Creating new attribute
sql_main-SQL-Group
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql: Registering sql_groupcmp for
sql_main-SQL-Group
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Driver
rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect to radius@localhost:/radius-test
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 0
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #0
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #0
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #0
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 1
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #1
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #1
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #1
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 2
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #2
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #2
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #2
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 3
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #3
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #3
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #3
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 4
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #4
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #4
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #4
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 5
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #5
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #5
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #5
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 6
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #6
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #6
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #6
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 7
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #7
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #7
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #7
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 8
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #8
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #8
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #8
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 9
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #9
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #9
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #9
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 10
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #10
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #10
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #10
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 11
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #11
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #11
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #11
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 12
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #12
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #12
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #12
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 13
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #13
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #13
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #13
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 14
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #14
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #14
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #14
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 15
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #15
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #15
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #15
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 16
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #16
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #16
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #16
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 17
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #17
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #17
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #17
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 18
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #18
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #18
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #18
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 19
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #19
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #19
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #19
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 20
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #20
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #20
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #20
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 21
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #21
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #21
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #21
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 22
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #22
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #22
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #22
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 23
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #23
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #23
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #23
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 24
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #24
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #24
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #24
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 25
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #25
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #25
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #25
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 26
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #26
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #26
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #26
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 27
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #27
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #27
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #27
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 28
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #28
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #28
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #28
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 29
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #29
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #29
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #29
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 30
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #30
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #30
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #30
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): starting 31
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Attempting to
connect rlm_sql_mysql #31
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #31
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_main): Connected new DB
handle, #31
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Processing
generate_sql_clients
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main) in
generate_sql_clients: query is SELECT id, nasname, shortname, type,
secret, server FROM nas
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Reserving sql
socket id: 31
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Read entry
nasname=10.4.17.2,shortname=wlc-omc,secret=wlcradius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Adding client
10.4.17.2 (wlc-omc, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Read entry
nasname=10.7.17.2,shortname=wlc-priut-2,secret=wlcradius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Adding client
10.7.17.2 (wlc-priut-2, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Read entry
nasname=10.10.17.2,shortname=wlc-1389,secret=wlcradius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Adding client
10.10.17.2 (wlc-1389, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Read entry
nasname=10.25.17.2,shortname=wlc-okc,secret=wlcradius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Adding client
10.25.17.2 (wlc-okc, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Read entry
nasname=10.25.17.5,shortname=wlc-okc-2,secret=wlcradius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Adding client
10.25.17.5 (wlc-okc-2, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Read entry
nasname=10.25.17.4,shortname=wlc-okc_rezerv,secret=wlcradius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Adding client
10.25.17.4 (wlc-okc_rezerv, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Read entry
nasname=10.201.133.2,shortname=wlc-alpika,secret=wlcradius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Adding client
10.201.133.2 (wlc-alpika, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Read entry
nasname=172.31.17.251,shortname=wlc-peak,secret=wlcradius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Adding client
172.31.17.251 (wlc-peak, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Read entry
nasname=10.20.101.251,shortname=asr-okc,secret=keisgradyius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Adding client
10.20.101.251 (asr-okc, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Read entry
nasname=10.20.101.252,shortname=asr-gk1389,secret=keisgradyius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Adding client
10.20.101.252 (asr-gk1389, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Read entry
nasname=10.20.101.253,shortname=asr-omc,secret=keisgradyius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Adding client
10.20.101.253 (asr-omc, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Read entry
nasname=10.20.101.13,shortname=2951-1200,secret=hg39fJ93Onf1Y
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Adding client
10.20.101.13 (2951-1200, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Read entry
nasname=10.25.17.1,shortname=wlc-okc-omc,secret=wlcradius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Adding client
10.25.17.1 (wlc-okc-omc, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_main): Released sql
socket id: 31
Wed Jun 29 19:01:07 2016 : Debug: (Loaded rlm_sqlcounter, checking
if it's valid)
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to module
rlm_sqlcounter
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating module
"expire_on_login" from file
/etc/freeradius/modules/sqlcounter_expire_on_login
Wed Jun 29 19:01:07 2016 : Debug: sqlcounter expire_on_login {
Wed Jun 29 19:01:07 2016 : Debug: counter-name =
"Expire-After-Initial-Login"
Wed Jun 29 19:01:07 2016 : Debug: check-name = "Expire-After"
Wed Jun 29 19:01:07 2016 : Debug: reply-name = "Session-Timeout"
Wed Jun 29 19:01:07 2016 : Debug: key = "User-Name"
Wed Jun 29 19:01:07 2016 : Debug: sqlmod-inst = "sql"
Wed Jun 29 19:01:07 2016 : Debug: query = "SELECT
TIME_TO_SEC(TIMEDIFF(NOW(), acctstarttime)) FROM radacct
WHERE UserName='%{User-Name}' ORDER BY
acctstarttime LIMIT 1;"
Wed Jun 29 19:01:07 2016 : Debug: reset = "never"
Wed Jun 29 19:01:07 2016 : Debug: safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: rlm_sqlcounter: Check attribute
Expire-After is number 12001
Wed Jun 29 19:01:07 2016 : Debug: rlm_sqlcounter: Current Time:
1467216067 [2016-06-29 19:01:07], Next reset 0 [2016-06-29 19:00:00]
Wed Jun 29 19:01:07 2016 : Debug: rlm_sqlcounter: Current Time:
1467216067 [2016-06-29 19:01:07], Prev reset 0 [2016-06-29 19:00:00]
Wed Jun 29 19:01:07 2016 : Debug: Module: Checking preacct {...} for
more modules to load
Wed Jun 29 19:01:07 2016 : Debug: (Loaded rlm_acct_unique, checking
if it's valid)
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to module
rlm_acct_unique
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating module
"acct_unique" from file /etc/freeradius/modules/acct_unique
Wed Jun 29 19:01:07 2016 : Debug: acct_unique {
Wed Jun 29 19:01:07 2016 : Debug: key = "User-Name,
Acct-Session-Id, NAS-IP-Address, NAS-Identifier, NAS-Port"
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: Module: Checking accounting {...} for
more modules to load
Wed Jun 29 19:01:07 2016 : Debug: (Loaded rlm_detail, checking if
it's valid)
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to module rlm_detail
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating module "detail"
from file /etc/freeradius/modules/detail
Wed Jun 29 19:01:07 2016 : Debug: detail {
Wed Jun 29 19:01:07 2016 : Debug: detailfile =
"/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d"
Wed Jun 29 19:01:07 2016 : Debug: header = "%t"
Wed Jun 29 19:01:07 2016 : Debug: detailperm = 384
Wed Jun 29 19:01:07 2016 : Debug: dirperm = 493
Wed Jun 29 19:01:07 2016 : Debug: locking = no
Wed Jun 29 19:01:07 2016 : Debug: log_packet_header = no
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating module
"sql_mac-filter" from file /etc/freeradius/sql.conf
Wed Jun 29 19:01:07 2016 : Debug: sql sql_mac-filter {
Wed Jun 29 19:01:07 2016 : Debug: driver = "rlm_sql_mysql"
Wed Jun 29 19:01:07 2016 : Debug: server = "localhost"
Wed Jun 29 19:01:07 2016 : Debug: port = ""
Wed Jun 29 19:01:07 2016 : Debug: login = "radius"
Wed Jun 29 19:01:07 2016 : Debug: password = "vEdf84JEXdPAuUHv"
Wed Jun 29 19:01:07 2016 : Debug: radius_db = "radius-test"
Wed Jun 29 19:01:07 2016 : Debug: read_groups = yes
Wed Jun 29 19:01:07 2016 : Debug: sqltrace = no
Wed Jun 29 19:01:07 2016 : Debug: sqltracefile =
"/var/log/freeradius/sqltrace.sql"
Wed Jun 29 19:01:07 2016 : Debug: readclients = yes
Wed Jun 29 19:01:07 2016 : Debug: deletestalesessions = yes
Wed Jun 29 19:01:07 2016 : Debug: num_sql_socks = 32
Wed Jun 29 19:01:07 2016 : Debug: lifetime = 0
Wed Jun 29 19:01:07 2016 : Debug: max_queries = 0
Wed Jun 29 19:01:07 2016 : Debug: sql_user_name = "%{User-Name}"
Wed Jun 29 19:01:07 2016 : Debug: default_user_profile = ""
Wed Jun 29 19:01:07 2016 : Debug: nas_query = "SELECT id, nasname,
shortname, type, secret, server FROM nas"
Wed Jun 29 19:01:07 2016 : Debug: authorize_check_query = "SELECT
id, username, attribute, value, op FROM radcheck
WHERE username = '%{SQL-User-Name}' ORDER BY id"
Wed Jun 29 19:01:07 2016 : Debug: authorize_reply_query = "SELECT
id, username, attribute, value, op FROM radreply
WHERE username = '%{SQL-User-Name}' ORDER BY id"
Wed Jun 29 19:01:07 2016 : Debug: authorize_group_check_query =
"SELECT id, groupname, attribute, Value, op FROM
radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER
BY id"
Wed Jun 29 19:01:07 2016 : Debug: authorize_group_reply_query =
"SELECT id, groupname, attribute, value, op FROM
radgroupreply WHERE groupname = '%{Sql-Group}' ORDER
BY id"
Wed Jun 29 19:01:07 2016 : 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'"
Wed Jun 29 19:01:07 2016 : Debug: accounting_update_query = "
UPDATE radacct SET framedipaddress =
'%{Framed-IP-Address}', acctsessiontime =
'%{Acct-Session-Time}', acctinputoctets =
'%{%{Acct-Input-Gigawords}:-0}' << 32 |
'%{%{Acct-Input-Octets}:-0}', acctoutputoctets =
'%{%{Acct-Output-Gigawords}:-0}' << 32 |
'%{%{Acct-Output-Octets}:-0}' WHERE acctsessionid =
'%{Acct-Session-Id}' AND username = '%{SQL-User-Name}'
AND nasipaddress = '%{NAS-IP-Address}'"
Wed Jun 29 19:01:07 2016 : 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}')"
Wed Jun 29 19:01:07 2016 : 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}')"
Wed Jun 29 19:01:07 2016 : 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}'"
Wed Jun 29 19:01:07 2016 : 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}'"
Wed Jun 29 19:01:07 2016 : 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}')"
Wed Jun 29 19:01:07 2016 : Debug: group_membership_query = "SELECT
groupname FROM radusergroup WHERE username =
'%{SQL-User-Name}' ORDER BY priority"
Wed Jun 29 19:01:07 2016 : Debug: connect_failure_retry_delay = 60
Wed Jun 29 19:01:07 2016 : Debug: simul_count_query = "SELECT
COUNT(*) FROM radacct
WHERE username = '%{SQL-User-Name}'
AND acctstoptime IS NULL"
Wed Jun 29 19:01:07 2016 : Debug: simul_verify_query = "SELECT
radacctid, acctsessionid, username,
nasipaddress, nasportid, framedipaddress,
callingstationid, framedprotocol FROM
radacct WHERE username =
'%{SQL-User-Name}' AND acctstoptime IS
NULL"
Wed Jun 29 19:01:07 2016 : Debug: postauth_query = "INSERT INTO
radpostauth (username, pass, reply, authdate)
VALUES (
'%{User-Name}',
'%{%{User-Password}:-%{Chap-Password}}',
'%{reply:Packet-Type}', '%S')"
Wed Jun 29 19:01:07 2016 : Debug: safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql Creating new attribute
sql_mac-filter-SQL-Group
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql: Registering sql_groupcmp for
sql_mac-filter-SQL-Group
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Driver
rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect to radius@localhost:/radius-test
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 0
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #0
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #0
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #0
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 1
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #1
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #1
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #1
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 2
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #2
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #2
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #2
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 3
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #3
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #3
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #3
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 4
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #4
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #4
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #4
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 5
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #5
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #5
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #5
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 6
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #6
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #6
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #6
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 7
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #7
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #7
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #7
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 8
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #8
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #8
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #8
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 9
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #9
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #9
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #9
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 10
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #10
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #10
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #10
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 11
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #11
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #11
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #11
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 12
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #12
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #12
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #12
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 13
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #13
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #13
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #13
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 14
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #14
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #14
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #14
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 15
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #15
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #15
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #15
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 16
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #16
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #16
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #16
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 17
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #17
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #17
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #17
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 18
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #18
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #18
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #18
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 19
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #19
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #19
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #19
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 20
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #20
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #20
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #20
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 21
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #21
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #21
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #21
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 22
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #22
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #22
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #22
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 23
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #23
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #23
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #23
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 24
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #24
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #24
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #24
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 25
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #25
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #25
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #25
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 26
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #26
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #26
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #26
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 27
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #27
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #27
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #27
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 28
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #28
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #28
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #28
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 29
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #29
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #29
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #29
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 30
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #30
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #30
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #30
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): starting 31
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Attempting to
connect rlm_sql_mysql #31
Wed Jun 29 19:01:07 2016 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #31
Wed Jun 29 19:01:07 2016 : Info: rlm_sql (sql_mac-filter): Connected new
DB handle, #31
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Processing
generate_sql_clients
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter) in
generate_sql_clients: query is SELECT id, nasname, shortname, type,
secret, server FROM nas
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Reserving
sql socket id: 31
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Read entry
nasname=10.4.17.2,shortname=wlc-omc,secret=wlcradius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Adding
client 10.4.17.2 (wlc-omc, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: WARNING: Ignoring duplicate client
10.4.17.2
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Read entry
nasname=10.7.17.2,shortname=wlc-priut-2,secret=wlcradius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Adding
client 10.7.17.2 (wlc-priut-2, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: WARNING: Ignoring duplicate client
10.7.17.2
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Read entry
nasname=10.10.17.2,shortname=wlc-1389,secret=wlcradius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Adding
client 10.10.17.2 (wlc-1389, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: WARNING: Ignoring duplicate client
10.10.17.2
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Read entry
nasname=10.25.17.2,shortname=wlc-okc,secret=wlcradius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Adding
client 10.25.17.2 (wlc-okc, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: WARNING: Ignoring duplicate client
10.25.17.2
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Read entry
nasname=10.25.17.5,shortname=wlc-okc-2,secret=wlcradius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Adding
client 10.25.17.5 (wlc-okc-2, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: WARNING: Ignoring duplicate client
10.25.17.5
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Read entry
nasname=10.25.17.4,shortname=wlc-okc_rezerv,secret=wlcradius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Adding
client 10.25.17.4 (wlc-okc_rezerv, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: WARNING: Ignoring duplicate client
10.25.17.4
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Read entry
nasname=10.201.133.2,shortname=wlc-alpika,secret=wlcradius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Adding
client 10.201.133.2 (wlc-alpika, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: WARNING: Ignoring duplicate client
10.201.133.2
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Read entry
nasname=172.31.17.251,shortname=wlc-peak,secret=wlcradius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Adding
client 172.31.17.251 (wlc-peak, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: WARNING: Ignoring duplicate client
172.31.17.251
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Read entry
nasname=10.20.101.251,shortname=asr-okc,secret=keisgradyius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Adding
client 10.20.101.251 (asr-okc, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: WARNING: Ignoring duplicate client
10.20.101.251
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Read entry
nasname=10.20.101.252,shortname=asr-gk1389,secret=keisgradyius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Adding
client 10.20.101.252 (asr-gk1389, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: WARNING: Ignoring duplicate client
10.20.101.252
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Read entry
nasname=10.20.101.253,shortname=asr-omc,secret=keisgradyius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Adding
client 10.20.101.253 (asr-omc, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: WARNING: Ignoring duplicate client
10.20.101.253
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Read entry
nasname=10.20.101.13,shortname=2951-1200,secret=hg39fJ93Onf1Y
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Adding
client 10.20.101.13 (2951-1200, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: WARNING: Ignoring duplicate client
10.20.101.13
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Read entry
nasname=10.25.17.1,shortname=wlc-okc-omc,secret=wlcradius
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Adding
client 10.25.17.1 (wlc-okc-omc, server=<none>) to clients list
Wed Jun 29 19:01:07 2016 : Debug: WARNING: Ignoring duplicate client
10.25.17.1
Wed Jun 29 19:01:07 2016 : Debug: rlm_sql (sql_mac-filter): Released sql
socket id: 31
Wed Jun 29 19:01:07 2016 : Debug: (Loaded rlm_attr_filter, checking
if it's valid)
Wed Jun 29 19:01:07 2016 : Debug: Module: Linked to module
rlm_attr_filter
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating module
"attr_filter.accounting_response" from file
/etc/freeradius/modules/attr_filter
Wed Jun 29 19:01:07 2016 : Debug: attr_filter
attr_filter.accounting_response {
Wed Jun 29 19:01:07 2016 : Debug: attrsfile =
"/etc/freeradius/attrs.accounting_response"
Wed Jun 29 19:01:07 2016 : Debug: key = "%{User-Name}"
Wed Jun 29 19:01:07 2016 : Debug: relaxed = no
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: reading pairlist file
/etc/freeradius/attrs.accounting_response
Wed Jun 29 19:01:07 2016 : Debug: Module: Checking session {...} for
more modules to load
Wed Jun 29 19:01:07 2016 : Debug: Module: Checking post-proxy {...} for
more modules to load
Wed Jun 29 19:01:07 2016 : Debug: Module: Checking post-auth {...} for
more modules to load
Wed Jun 29 19:01:07 2016 : Debug: Module: Instantiating module
"attr_filter.access_reject" from file
/etc/freeradius/modules/attr_filter
Wed Jun 29 19:01:07 2016 : Debug: attr_filter
attr_filter.access_reject {
Wed Jun 29 19:01:07 2016 : Debug: attrsfile =
"/etc/freeradius/attrs.access_reject"
Wed Jun 29 19:01:07 2016 : Debug: key = "%{User-Name}"
Wed Jun 29 19:01:07 2016 : Debug: relaxed = no
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: reading pairlist file
/etc/freeradius/attrs.access_reject
Wed Jun 29 19:01:07 2016 : Debug: } # modules
Wed Jun 29 19:01:07 2016 : Debug: } # server
Wed Jun 29 19:01:07 2016 : Debug: server inner-tunnel { # from file
/etc/freeradius/sites-enabled/inner-tunnel
Wed Jun 29 19:01:07 2016 : Debug: modules {
Wed Jun 29 19:01:07 2016 : Debug: Module: Checking authenticate {...}
for more modules to load
Wed Jun 29 19:01:07 2016 : Debug: Module: Checking authorize {...} for
more modules to load
Wed Jun 29 19:01:07 2016 : Debug: Module: Checking session {...} for
more modules to load
Wed Jun 29 19:01:07 2016 : Debug: Module: Checking post-proxy {...} for
more modules to load
Wed Jun 29 19:01:07 2016 : Debug: Module: Checking post-auth {...} for
more modules to load
Wed Jun 29 19:01:07 2016 : Debug: } # modules
Wed Jun 29 19:01:07 2016 : Debug: } # server
Wed Jun 29 19:01:07 2016 : Debug: radiusd: #### Opening IP addresses and
Ports ####
Wed Jun 29 19:01:07 2016 : Debug: listen {
Wed Jun 29 19:01:07 2016 : Debug: type = "auth"
Wed Jun 29 19:01:07 2016 : Debug: ipaddr = *
Wed Jun 29 19:01:07 2016 : Debug: port = 0
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: listen {
Wed Jun 29 19:01:07 2016 : Debug: type = "acct"
Wed Jun 29 19:01:07 2016 : Debug: ipaddr = *
Wed Jun 29 19:01:07 2016 : Debug: port = 0
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: listen {
Wed Jun 29 19:01:07 2016 : Debug: type = "auth"
Wed Jun 29 19:01:07 2016 : Debug: ipaddr = 127.0.0.1
Wed Jun 29 19:01:07 2016 : Debug: port = 18120
Wed Jun 29 19:01:07 2016 : Debug: }
Wed Jun 29 19:01:07 2016 : Debug: Listening on authentication address *
port 1812
Wed Jun 29 19:01:07 2016 : Debug: Listening on accounting address * port
1813
Wed Jun 29 19:01:07 2016 : Debug: Listening on authentication address
127.0.0.1 port 18120 as server inner-tunnel
Wed Jun 29 19:01:07 2016 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 10.25.17.2 port 32770, id=111,
length=185
User-Name = "90:00:4e:3d:fe:a2"
Called-Station-Id = "AP-Park-410:mf"
Calling-Station-Id = "90-00-4e-3d-fe-a2"
NAS-Port = 13
NAS-IP-Address = 10.25.17.2
NAS-Identifier = "wlc-okc-060-cth1"
Airespace-Wlan-Id = 13
Service-Type = Call-Check
Framed-MTU = 1300
NAS-Port-Type = Wireless-802.11
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "192"
Acct-Session-Id = "5773f0dd/90:00:4e:3d:fe:a2/64164"
Wed Jun 29 19:01:31 2016 : Info: # Executing section authorize from file
/etc/freeradius/sites-enabled/default
Wed Jun 29 19:01:31 2016 : Info: +group authorize {
Wed Jun 29 19:01:31 2016 : Info: ++[preprocess] = ok
Wed Jun 29 19:01:31 2016 : Info: ++? if ("%{sql_main:select count(id)
from vbmacs where mac='%{User-Name}'}" > "0")
Wed Jun 29 19:01:31 2016 : Info: sql_xlat
Wed Jun 29 19:01:31 2016 : Info: expand: %{User-Name} ->
90:00:4e:3d:fe:a2
Wed Jun 29 19:01:31 2016 : Info: sql_set_user escaped user -->
'90:00:4e:3d:fe:a2'
Wed Jun 29 19:01:31 2016 : Info: expand: select count(id) from
vbmacs where mac='%{User-Name}' -> select count(id) from vbmacs where
mac='90:00:4e:3d:fe:a2'
Wed Jun 29 19:01:31 2016 : Debug: rlm_sql (sql_main): Reserving sql
socket id: 30
Wed Jun 29 19:01:31 2016 : Info: sql_xlat finished
Wed Jun 29 19:01:31 2016 : Debug: rlm_sql (sql_main): Released sql
socket id: 30
Wed Jun 29 19:01:31 2016 : Info: expand: %{sql_main:select
count(id) from vbmacs where mac='%{User-Name}'} -> 1
Wed Jun 29 19:01:31 2016 : Info: ? Evaluating ("%{sql_main:select
count(id) from vbmacs where mac='%{User-Name}'}" > "0") -> TRUE
Wed Jun 29 19:01:31 2016 : Info: ++? if ("%{sql_main:select count(id)
from vbmacs where mac='%{User-Name}'}" > "0") -> TRUE
Wed Jun 29 19:01:31 2016 : Info: ++if ("%{sql_main:select count(id) from
vbmacs where mac='%{User-Name}'}" > "0") {
Wed Jun 29 19:01:31 2016 : Info: +++update request {
Wed Jun 29 19:01:31 2016 : Info: sql_xlat
Wed Jun 29 19:01:31 2016 : Info: expand: %{User-Name} ->
90:00:4e:3d:fe:a2
Wed Jun 29 19:01:31 2016 : Info: sql_set_user escaped user -->
'90:00:4e:3d:fe:a2'
Wed Jun 29 19:01:31 2016 : Info: expand: select phone from vbmacs
where mac='%{User-Name}' -> select phone from vbmacs where
mac='90:00:4e:3d:fe:a2'
Wed Jun 29 19:01:31 2016 : Debug: rlm_sql (sql_main): Reserving sql
socket id: 29
Wed Jun 29 19:01:31 2016 : Info: sql_xlat finished
Wed Jun 29 19:01:31 2016 : Debug: rlm_sql (sql_main): Released sql
socket id: 29
Wed Jun 29 19:01:31 2016 : Info: expand: %{sql_main:select phone
from vbmacs where mac='%{User-Name}'} -> 79280000000
Wed Jun 29 19:01:31 2016 : Info: +++} # update request = noop
Wed Jun 29 19:01:31 2016 : Info: ++} # if ("%{sql_main:select count(id)
from vbmacs where mac='%{User-Name}'}" > "0") = noop
Wed Jun 29 19:01:31 2016 : Info: ++ ... skipping else for request 0:
Preceding "if" was taken
Wed Jun 29 19:01:31 2016 : Info: ++[chap] = noop
Wed Jun 29 19:01:31 2016 : Info: ++[mschap] = noop
Wed Jun 29 19:01:31 2016 : Info: ++[digest] = noop
Wed Jun 29 19:01:31 2016 : Info: [suffix] No '@' in User-Name =
"90:00:4e:3d:fe:a2", looking up realm NULL
Wed Jun 29 19:01:31 2016 : Info: [suffix] No such realm "NULL"
Wed Jun 29 19:01:31 2016 : Info: ++[suffix] = noop
Wed Jun 29 19:01:31 2016 : Info: [eap] No EAP-Message, not doing EAP
Wed Jun 29 19:01:31 2016 : Info: ++[eap] = noop
Wed Jun 29 19:01:31 2016 : Info: ++[files] = noop
Wed Jun 29 19:01:31 2016 : Info: [sql_main] expand: %{User-Name} ->
90:00:4e:3d:fe:a2
Wed Jun 29 19:01:31 2016 : Info: [sql_main] sql_set_user escaped user
--> '90:00:4e:3d:fe:a2'
Wed Jun 29 19:01:31 2016 : Debug: rlm_sql (sql_main): Reserving sql
socket id: 28
Wed Jun 29 19:01:31 2016 : Info: [sql_main] expand: SELECT id,
username, attribute, value, op FROM radcheck WHERE
username = '%{SQL-User-Name}' ORDER BY id -> SELECT id,
username, attribute, value, op FROM radcheck WHERE
username = '90:00:4e:3d:fe:a2' ORDER BY id
Wed Jun 29 19:01:31 2016 : Info: [sql_main] expand: SELECT groupname
FROM radusergroup WHERE username =
'%{SQL-User-Name}' ORDER BY priority -> SELECT groupname
FROM radusergroup WHERE username = '90:00:4e:3d:fe:a2'
ORDER BY priority
Wed Jun 29 19:01:31 2016 : Debug: rlm_sql (sql_main): Released sql
socket id: 28
Wed Jun 29 19:01:31 2016 : Info: [sql_main] User 90:00:4e:3d:fe:a2 not
found
Wed Jun 29 19:01:31 2016 : Info: ++[sql_main] = notfound
Wed Jun 29 19:01:31 2016 : Info: ++[expiration] = noop
Wed Jun 29 19:01:31 2016 : Info: ++[logintime] = noop
Wed Jun 29 19:01:31 2016 : Info: [pap] WARNING! No "known good" password
found for the user. Authentication may fail because of this.
Wed Jun 29 19:01:31 2016 : Info: ++[pap] = noop
Wed Jun 29 19:01:31 2016 : Debug: rlm_sqlcounter: Entering module
authorize code
Wed Jun 29 19:01:31 2016 : Debug: rlm_sqlcounter: Could not find Check
item value pair
Wed Jun 29 19:01:31 2016 : Info: ++[expire_on_login] = noop
Wed Jun 29 19:01:31 2016 : Info: +} # group authorize = ok
Wed Jun 29 19:01:31 2016 : Info: ERROR: No authenticate method
(Auth-Type) found for the request: Rejecting the user
Wed Jun 29 19:01:31 2016 : Info: Failed to authenticate the user.
Wed Jun 29 19:01:31 2016 : Info: Using Post-Auth-Type REJECT
Wed Jun 29 19:01:31 2016 : Info: # Executing group from file
/etc/freeradius/sites-enabled/default
Wed Jun 29 19:01:31 2016 : Info: +group REJECT {
Wed Jun 29 19:01:31 2016 : Info: [attr_filter.access_reject] expand:
%{User-Name} -> 90:00:4e:3d:fe:a2
Wed Jun 29 19:01:31 2016 : Debug: attr_filter: Matched entry DEFAULT at
line 11
Wed Jun 29 19:01:31 2016 : Info: ++[attr_filter.access_reject] = updated
Wed Jun 29 19:01:31 2016 : Info: +} # group REJECT = updated
Sending Access-Reject of id 111 to 10.25.17.2 port 32770
Wed Jun 29 19:01:31 2016 : Info: Finished request 0.
Wed Jun 29 19:01:31 2016 : Debug: Going to the next request
Wed Jun 29 19:01:31 2016 : Debug: Waking up in 4.9 seconds.
Wed Jun 29 19:01:36 2016 : Info: Cleaning up request 0 ID 111 with
timestamp +24
Wed Jun 29 19:01:36 2016 : Info: Ready to process requests.
--
С уважением,
Бирюк Степан
Ведущий программист Компьютерного центра
Сочинский институт РУДН
2
2
Hello,
I recently found a case where the server crashes when using raddebug with a regexp condition, e.g.
# raddebug -c ‘( Calling-Station-Id =~ /00-01-03$/ )’
I’ve opened an issue on github (#1632), so I am not entirely sure this email is really needed.
Please disregard it if that’s the case.
Otherwise I’ll be happy to send more information, or admit I am doing something wrong if it turns out to be the case...
Regards,
--
Louis Munro
lmunro(a)inverse.ca :: www.inverse.ca
+1.514.447.4918 x125 :: +1 (866) 353-6153 x125
Inverse inc. :: Leaders behind SOGo (www.sogo.nu) and PacketFence (www.packetfence.org)
2
1
Hello, everyone
I'm having a problem when running freeradius with a non-root user/group.
The service can't start because of permissions on log and pid files.
When started in debug mode, the service starts and works fine, but fails in
production:
# radiusd
radiusd: Failed to open log file /usr/local/var/log/radius/radius.log:
Permission denied
Changed the folder owner, but still got same error
# chown -R radius:radius /usr/local/var/log/radius/
# radiusd
radiusd: Failed to open log file /usr/local/var/log/radius/radius.log:
Permission denied
If I specify the file, freeradius can create log file but shows nothing on
output
# radiusd -l /usr/local/var/log/radius/radius.log
#
Cheking de log file, happens the same with the pid file:
Error: Failed creating PID file /usr/local/var/run/radiusd/radiusd.pid:
Permission denied
Again, changed the folder owner, but still got same error
# chown -R radius:radius /usr/local/var/run/radiusd/
Running with commented user and group options, the service works fine.
I'm on Debian 8.0.3 and Freeradius 3.0.11
Freeradius was compiled with default options.
The user was created with:
useradd -r -d /usr/local/etc/raddb/ -s /bin/false radius
Thanks for any help.
2
3
o.k. the man page isn't very helpful
I want to pass a value for NAS-IP-Address to eapol_test as an argument.
the man page says
-N attr spec
Send arbitrary attribute specific by attr_id:syntax:value, or attr_id
alone. attr_id
should be the numeric ID of the attribute, and syntax should
be one of 's' (string),
'd' (integer), or 'x' (octet string). The value is the
attribute value to send. When
attr_id is given alone, NULL is used as the attribute value.
Multiple attributes can
be specified by using the option several times.
so I wanted to pass 144.32.126.139 as the NAS-IP-Address
I've tried
eapol_test -c /usr/local/etc/peap-ydh.conf -A 144.32.126.139 -a
144.32.128.68 -s <key> -N 61:d:15 -N 6:d:8 -N 4:s:144.32.126.139
but that gives me
Attribute 4 (NAS-IP-Address) length=16
Invalid IP address length 14
Putting the address in quotes makes no difference other
even tried -N 4:x:061064064056063062056061062066054061063071
which should be 144.32.126.139 in octal
Still got an invalid IP address Length
Any Ideas?
A
2
2
This morning I got the sources via:
$ git clone https://github.com/FreeRADIUS/freeradius-server.git
$ cd freeradius-server
$ git checkout -b v3.1.x origin/v3.1.x
I built and configured the server, it starts fine. When receiving a request from a radtest client it crashes.
"Datei oder Verzeichnis nicht gefunden" means "File not found".
Here is what gdb outputs:
(gdb) set args -X
(gdb) run
...
Ready to process requests
ASSERT FAILED src/main/process.c[1843]: request->server_cs != NULL
RAISING SIGNAL: Aborted
Program received signal SIGABRT, Aborted.
0x00007ffff647d79b in raise (sig=6) at ../nptl/sysdeps/unix/sysv/linux/pt-raise.c:37
37 ../nptl/sysdeps/unix/sysv/linux/pt-raise.c: Datei oder Verzeichnis nicht gefunden.
(gdb) bt
#0 0x00007ffff647d79b in raise (sig=6) at ../nptl/sysdeps/unix/sysv/linux/pt-raise.c:37
#1 0x00007ffff794c40e in fr_fault (sig=6) at src/lib/debug.c:650
#2 0x00007ffff7bbb77c in rad_assert_fail (file=0x475202 "src/main/process.c", line=1843,
expr=0x475adf "request->server_cs != NULL") at src/main/util.c:468
#3 0x000000000044756d in request_setup (ctx=0xeeb9e0, listener=0x9e97b0, packet=0xeeba40, client=0xd418b0,
fun=0x410f10 <rad_authenticate>) at src/main/process.c:1843
#4 0x00000000004471fb in request_receive (ctx=0xeeb9e0, listener=0x9e97b0, packet=0xeeba40, client=0xd418b0,
fun=0x410f10 <rad_authenticate>) at src/main/process.c:1740
#5 0x000000000041f64c in auth_socket_recv (listener=0x9e97b0) at src/main/listen.c:1906
#6 0x000000000044e752 in event_socket_handler (xel=0xedd4c0, fd=55, ctx=0x9e97b0) at src/main/process.c:4563
#7 0x00007ffff7977905 in fr_event_loop (el=0xedd4c0) at src/lib/event.c:636
#8 0x00000000004506ad in radius_event_process () at src/main/process.c:5458
#9 0x0000000000434d62 in main (argc=2, argv=0x7fffffffe618) at src/main/radiusd.c:584
(gdb)
Norbert Wegener
3
3
Hello,
I'm pretty sure what I'm seeing is related to the client I'm using, but
I think it's quite odd : the client is ProFTPd, and it's a login phase.
I'm sending user : unlogindeplus and pass : toast
But what I see in FR logs in debug mode is quite surprising :
<snip>
(5) User-Name = "unlogindeplus"
(5) User-Password = "toast\000ndtoast"
(5) NAS-Identifier = "ftps"
(5) NAS-IPv6-Address = ::ffff:188.165.117.231
(5) NAS-Port = 21
(5) NAS-Port-Type = Virtual
(5) Calling-Station-Id = "217.114.201.133"
(5) Service-Type = Login-User
<snip>
As you can see, FR "sees" User-Password : "toast\000ndtoast" and not
simply "toast".
I'm puzzled.
Thanks !
Hoggins!
2
3
Hi,
802.1x Authentication with EAP-TLS, works perfectly with a Centos
client, however not from a Cisco IP Phone.
Basic Specs For Server;
* Centos 7.2 x64
* freeradius-3.0.11
* Communicating through a Dell N3000 switch.
* Cisco 7945 IP Phone
I'm just after advice on how to solve the "certificate signature
failure" error?
Error:
(3) eap_tls: Creating attributes from certificate OIDs
(3) eap_tls: TLS-Cert-Serial := "01"
(3) eap_tls: TLS-Cert-Expiration := "190622025857Z"
(3) eap_tls: TLS-Cert-Subject := "/CN=ios-ca"
(3) eap_tls: TLS-Cert-Issuer := "/CN=ios-ca"
(3) eap_tls: TLS-Cert-Common-Name := "ios-ca"
(3) eap_tls: Creating attributes from certificate OIDs
(3) eap_tls: TLS-Client-Cert-Serial := "02"
(3) eap_tls: TLS-Client-Cert-Expiration := "190622025857Z"
(3) eap_tls: TLS-Client-Cert-Subject := "/CN=SEP20BBC092DE1D"
(3) eap_tls: TLS-Client-Cert-Issuer := "/CN=ios-ca"
(3) eap_tls: TLS-Client-Cert-Common-Name := "SEP20BBC092DE1D"
---> (3) eap_tls: ERROR: SSL says error 7 : certificate signature
failure <-------
(3) eap_tls: >>> send TLS 1.0 Alert [length 0002], fatal decrypt_error
(3) eap_tls: ERROR: TLS Alert write:fatal:decrypt error
tls: TLS_accept: Error in SSLv3 read client certificate B
(3) eap_tls: ERROR: SSL says: error:0D0C50A1:asn1 encoding
routines:ASN1_item_verify:unknown message digest algorithm
(3) eap_tls: ERROR: SSL_read failed inside of TLS (-1), TLS session
failed
(3) eap_tls: ERROR: TLS receive handshake failed during operation
(3) eap_tls: ERROR: [eaptls process] = fail
(3) eap: ERROR: Failed continuing EAP TLS (13) session. EAP sub-module
failed
Regards,
Craig
2
1