Class Attribute Missing for Anonymous Users
Selahattin Cilek
selahattin_cilek at hotmail.com
Sat Sep 23 17:07:47 CEST 2017
On 23.09.2017 16:23, Alan DeKok wrote:
> On Sep 23, 2017, at 1:16 AM, Selahattin Cilek <selahattin_cilek at hotmail.com> wrote:
>> I installed FreeRADIUS 2.2.9 and copied the configuration of a running
>> site and ran some tests. I am afraid that does not happen with
>> FreeRADIUS 2.2.9. So I believe it has something to do with the
>> configuration of FreeRADIUS 3.0.15.
> Does 3.0.15 send the Class attribute in the Access-Accept? If not, that's the problem.
No, it does not.
> Otherwise, look at the Access-Accept packets from the two versions. If they're different, try to make them the same. Maybe the NAS is getting excited over those differences.
>
How do I do that?
authorize_group_check_query = "CALL
authorize_group_check('%{sql1-SQL-Group}')"
authorize_group_reply_query = "CALL
authorize_group_reply('%{sql1-SQL-Group}')"
group_membership_query = "CALL
group_membership('%{SQL-User-Name}')"
simul_count_query = "CALL simul_count('%{SQL-User-Name}')"
safe_characters =
"ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz0123456789!#+%&?*-_ at ."
accounting {
reference = "%{tolower:type.%{Acct-Status-Type}.query}"
type {
accounting-on {
query = "CALL accounting_on('%{Called-Station-Id}')"
}
accounting-off {
query = "CALL accounting_off('%{Called-Station-Id}')"
}
start {
query = "CALL
accounting_start('%{Acct-Session-Id}','%{SQL-User-Name}','%{Class}','%{NAS-IP-Address}','%{Called-Station-Id}','%{Calling-Station-Id}')"
}
interim-update {
query = "CALL accounting_update
('%{Acct-Session-Id}','%{Called-Station-Id}','%{Calling-Station-Id}','%{Acct-Session-Time}','%{Acct-Input-Octets}','%{
Acct-Input-Gigawords}','%{Acct-Output-Octets}','%{Acct-Output-Gigawords}')"
}
stop {
query = "CALL accounting_stop
('%{Acct-Session-Id}','%{SQL-User-Name}','%{Called-Station-Id}','%{Calling-Station-Id}','%{Acct-Session-Time}','%{Acct-I
nput-Octets}','%{Acct-Input-Gigawords}','%{Acct-Output-Octets}','%{Acct-Output-Gigawords}','%{Acct-Terminate-Cause}')"
}
}
}
post-auth {
reference = ".query"
}
}
rlm_sql (sql1): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and
linked
Creating attribute sql1-SQL-Group
# Loaded module rlm_sqlcounter
# Loading module "dailycounter" from file
/usr/local/etc/raddb/mods-enabled/sqlcounter
sqlcounter dailycounter {
sql_module_instance = "sql"
key = "User-Name"
query = "SELECT SUM(acctsessiontime - GREATEST((%%b -
UNIX_TIMESTAMP(acctstarttime)), 0)) FROM radacct WHERE username =
'%{User-Name}' AND UNIX_TIMEST
AMP(acctstarttime) + acctsessiontime > '%%b'"
reset = "daily"
counter_name = "Daily-Session-Time"
check_name = "Max-Daily-Session"
reply_name = "Session-Timeout"
}
# Loading module "monthlycounter" from file
/usr/local/etc/raddb/mods-enabled/sqlcounter
sqlcounter monthlycounter {
sql_module_instance = "sql"
key = "User-Name"
query = "SELECT SUM(acctsessiontime - GREATEST((%%b -
UNIX_TIMESTAMP(acctstarttime)), 0)) FROM radacct WHERE
username='%{User-Name}' AND UNIX_TIMESTAM
P(acctstarttime) + acctsessiontime > '%%b'"
reset = "monthly"
counter_name = "Monthly-Session-Time"
check_name = "Max-Monthly-Session"
reply_name = "Session-Timeout"
}
# Loading module "noresetcounter" from file
/usr/local/etc/raddb/mods-enabled/sqlcounter
sqlcounter noresetcounter {
sql_module_instance = "sql"
key = "User-Name"
query = "SELECT IFNULL(SUM(AcctSessionTime),0) FROM radacct
WHERE UserName='%{User-Name}'"
reset = "never"
counter_name = "Max-All-Session-Time"
check_name = "Max-All-Session"
reply_name = "Session-Timeout"
}
# Loading module "expire_on_login" from file
/usr/local/etc/raddb/mods-enabled/sqlcounter
sqlcounter expire_on_login {
sql_module_instance = "sql"
key = "User-Name"
query = "SELECT IFNULL( MAX(TIME_TO_SEC(TIMEDIFF(NOW(),
acctstarttime))),0) FROM radacct WHERE UserName='%{User-Name}' ORDER BY
acctstarttime LIMIT 1;
"
reset = "never"
counter_name = "Expire-After-Initial-Login"
check_name = "Expire-After"
reply_name = "Session-Timeout"
}
instantiate {
# Instantiating module "expiration" from file
/usr/local/etc/raddb/mods-enabled/expiration
# Instantiating module "logintime" from file
/usr/local/etc/raddb/mods-enabled/logintime
# Instantiating module "sql1" from file
/usr/local/etc/raddb/mods-enabled/sql
rlm_sql_mysql: libmysql version: 5.6.35
mysql {
tls {
}
warnings = "auto"
}
rlm_sql (sql1): Attempting to connect to database "raddb"
rlm_sql (sql1): Initialising connection pool
pool {
start = 5
min = 3
max = 5
spare = 10
uses = 0
lifetime = 0
cleanup_interval = 30
idle_timeout = 60
retry_delay = 60
spread = no
}
WARNING: Ignoring "spare = 10", forcing to "spare = 2"
rlm_sql (sql1): Opening additional connection (0), 1 of 5 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb' on Localhost via UNIX
socket, server version 5.6.37, protocol version 10
rlm_sql (sql1): Opening additional connection (1), 1 of 4 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb' on Localhost via UNIX
socket, server version 5.6.37, protocol version 10
rlm_sql (sql1): Opening additional connection (2), 1 of 3 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb' on Localhost via UNIX
socket, server version 5.6.37, protocol version 10
rlm_sql (sql1): Opening additional connection (3), 1 of 2 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb' on Localhost via UNIX
socket, server version 5.6.37, protocol version 10
rlm_sql (sql1): Opening additional connection (4), 1 of 1 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'raddb' on Localhost via UNIX
socket, server version 5.6.37, protocol version 10
rlm_sql (sql1): Processing generate_sql_clients
rlm_sql (sql1) in generate_sql_clients: query is CALL load_clients()
rlm_sql (sql1): Reserved connection (0)
rlm_sql (sql1): Executing select query: CALL load_clients()
rlm_sql (sql1): Adding client 192.168.0.4 (HOME_AP) to global clients list
rlm_sql (192.168.0.4): Client "HOME_AP" (sql1) added
rlm_sql (sql1): Released connection (0)
}
# Instantiating module "attr_filter.post-proxy" from file
/usr/local/etc/raddb/mods-enabled/attr_filter
reading pairlist file
/usr/local/etc/raddb/mods-config/attr_filter/post-proxy
# Instantiating module "attr_filter.pre-proxy" from file
/usr/local/etc/raddb/mods-enabled/attr_filter
reading pairlist file /usr/local/etc/raddb/mods-config/attr_filter/pre-proxy
# Instantiating module "attr_filter.access_reject" from file
/usr/local/etc/raddb/mods-enabled/attr_filter
reading pairlist file
/usr/local/etc/raddb/mods-config/attr_filter/access_reject
[/usr/local/etc/raddb/mods-config/attr_filter/access_reject]:11 Check
item "FreeRADIUS-Response-Delay" found in filter list for realm "DEFAULT".
[/usr/local/etc/raddb/mods-config/attr_filter/access_reject]:11 Check
item "FreeRADIUS-Response-Delay-USec" found in filter list for realm
"DEFAULT".
# Instantiating module "attr_filter.access_challenge" from file
/usr/local/etc/raddb/mods-enabled/attr_filter
reading pairlist file
/usr/local/etc/raddb/mods-config/attr_filter/access_challenge
# Instantiating module "attr_filter.accounting_response" from file
/usr/local/etc/raddb/mods-enabled/attr_filter
reading pairlist file
/usr/local/etc/raddb/mods-config/attr_filter/accounting_response
# Instantiating module "cache_eap" from file
/usr/local/etc/raddb/mods-enabled/cache_eap
rlm_cache (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree)
loaded and linked
# Instantiating module "detail" from file
/usr/local/etc/raddb/mods-enabled/detail
# Instantiating module "auth_log" from file
/usr/local/etc/raddb/mods-enabled/detail.log
rlm_detail (auth_log): 'User-Password' suppressed, will not appear in
detail output
# Instantiating module "reply_log" from file
/usr/local/etc/raddb/mods-enabled/detail.log
# Instantiating module "pre_proxy_log" from file
/usr/local/etc/raddb/mods-enabled/detail.log
# Instantiating module "post_proxy_log" from file
/usr/local/etc/raddb/mods-enabled/detail.log
# Instantiating module "eap" from file
/usr/local/etc/raddb/mods-enabled/eap
# Linked to sub-module rlm_eap_tls
tls {
tls = "tls-common"
}
tls-config tls-common {
verify_depth = 0
ca_path = "/usr/local/etc/raddb/certs"
pem_file_type = yes
private_key_file = "/usr/local/etc/raddb/certs/server_key.pem"
certificate_file = "/usr/local/etc/raddb/certs/server_cert.pem"
ca_file = "/usr/local/etc/raddb/certs/ca_cert.pem"
dh_file = "/usr/local/etc/raddb/certs/dh"
random_file = "/dev/urandom"
fragment_size = 1024
include_length = yes
auto_chain = yes
check_crl = no
check_all_crl = no
cipher_list = "DEFAULT"
cipher_server_preference = no
ecdh_curve = "prime256v1"
cache {
enable = no
lifetime = 24
max_entries = 255
}
verify {
skip_if_ocsp_ok = no
}
ocsp {
enable = no
override_cert_url = no
url = "http://127.0.0.1/ocsp/"
use_nonce = yes
timeout = 0
softfail = no
}
}
# Linked to sub-module rlm_eap_ttls
ttls {
tls = "tls-common"
default_eap_type = "tls"
copy_request_to_tunnel = yes
use_tunneled_reply = no
virtual_server = "inner-tunnel-ttls"
include_length = yes
require_client_cert = no
}
tls: Using cached TLS configuration from previous invocation
# Linked to sub-module rlm_eap_peap
peap {
tls = "tls-common"
default_eap_type = "tls"
copy_request_to_tunnel = yes
use_tunneled_reply = no
proxy_tunneled_request_as_eap = yes
virtual_server = "inner-tunnel-peap"
soh = no
require_client_cert = no
}
tls: Using cached TLS configuration from previous invocation
# Linked to sub-module rlm_eap_mschapv2
mschapv2 {
with_ntdomain_hack = no
send_error = no
}
# Instantiating module "files" from file
/usr/local/etc/raddb/mods-enabled/files
reading pairlist file /usr/local/etc/raddb/mods-config/files/authorize
reading pairlist file /usr/local/etc/raddb/mods-config/files/accounting
reading pairlist file /usr/local/etc/raddb/mods-config/files/pre-proxy
# Instantiating module "linelog" from file
/usr/local/etc/raddb/mods-enabled/linelog
# Instantiating module "log_accounting" from file
/usr/local/etc/raddb/mods-enabled/linelog
# Instantiating module "mschap" from file
/usr/local/etc/raddb/mods-enabled/mschap
rlm_mschap (mschap): using internal authentication
# Instantiating module "pap" from file
/usr/local/etc/raddb/mods-enabled/pap
# Instantiating module "etc_passwd" from file
/usr/local/etc/raddb/mods-enabled/passwd
rlm_passwd: nfields: 3 keyfield 0(User-Name) listable: no
# Instantiating module "preprocess" from file
/usr/local/etc/raddb/mods-enabled/preprocess
reading pairlist file /usr/local/etc/raddb/mods-config/preprocess/huntgroups
reading pairlist file /usr/local/etc/raddb/mods-config/preprocess/hints
# Instantiating module "IPASS" from file
/usr/local/etc/raddb/mods-enabled/realm
# Instantiating module "suffix" from file
/usr/local/etc/raddb/mods-enabled/realm
# Instantiating module "realmpercent" from file
/usr/local/etc/raddb/mods-enabled/realm
# Instantiating module "ntdomain" from file
/usr/local/etc/raddb/mods-enabled/realm
# Instantiating module "reject" from file
/usr/local/etc/raddb/mods-enabled/always
# Instantiating module "fail" from file
/usr/local/etc/raddb/mods-enabled/always
# Instantiating module "ok" from file
/usr/local/etc/raddb/mods-enabled/always
# Instantiating module "handled" from file
/usr/local/etc/raddb/mods-enabled/always
# Instantiating module "invalid" from file
/usr/local/etc/raddb/mods-enabled/always
# Instantiating module "userlock" from file
/usr/local/etc/raddb/mods-enabled/always
# Instantiating module "notfound" from file
/usr/local/etc/raddb/mods-enabled/always
# Instantiating module "noop" from file
/usr/local/etc/raddb/mods-enabled/always
# Instantiating module "updated" from file
/usr/local/etc/raddb/mods-enabled/always
# Instantiating module "dailycounter" from file
/usr/local/etc/raddb/mods-enabled/sqlcounter
rlm_sqlcounter: Current Time: 1506176265 [2017-09-23 17:17:45], Prev
reset 1506114000 [2017-09-23 00:00:00]
# Instantiating module "monthlycounter" from file
/usr/local/etc/raddb/mods-enabled/sqlcounter
rlm_sqlcounter: Current Time: 1506176265 [2017-09-23 17:17:45], Prev
reset 1504213200 [2017-09-01 00:00:00]
# Instantiating module "noresetcounter" from file
/usr/local/etc/raddb/mods-enabled/sqlcounter
rlm_sqlcounter: Current Time: 1506176265 [2017-09-23 17:17:45], Prev
reset 0 [2017-09-23 17:00:00]
# Instantiating module "expire_on_login" from file
/usr/local/etc/raddb/mods-enabled/sqlcounter
rlm_sqlcounter: Current Time: 1506176265 [2017-09-23 17:17:45], Prev
reset 0 [2017-09-23 17:00:00]
} # modules
radiusd: #### Loading Virtual Servers ####
server { # from file /usr/local/etc/raddb/radiusd.conf
} # server
server default { # from file /usr/local/etc/raddb/sites-enabled/default
# Loading authenticate {...}
# Loading authorize {...}
# Loading preacct {...}
# Loading accounting {...}
# Loading session {...}
# Loading post-proxy {...}
# Loading post-auth {...}
} # server default
server inner-tunnel-ttls { # from file
/usr/local/etc/raddb/sites-enabled/inner-tunnel-ttls
# Loading authenticate {...}
# Loading authorize {...}
# Loading session {...}
# Loading post-proxy {...}
# Loading post-auth {...}
} # server inner-tunnel-ttls
server inner-tunnel-peap { # from file
/usr/local/etc/raddb/sites-enabled/inner-tunnel-peap
# Loading authenticate {...}
# Loading authorize {...}
# Loading session {...}
# Loading post-proxy {...}
# Loading post-auth {...}
} # server inner-tunnel-peap
radiusd: #### Opening IP addresses and Ports ####
listen {
type = "auth"
ipaddr = 192.168.0.1
port = 1812
}
listen {
type = "acct"
ipaddr = 192.168.0.1
port = 1813
}
listen {
type = "auth"
ipaddr = 127.0.0.1
port = 18127
}
listen {
type = "auth"
ipaddr = 127.0.0.1
port = 18128
}
Listening on auth address 192.168.0.1 port 1812 bound to server default
Listening on acct address 192.168.0.1 port 1813 bound to server default
Listening on auth address 127.0.0.1 port 18127 bound to server
inner-tunnel-ttls
Listening on auth address 127.0.0.1 port 18128 bound to server
inner-tunnel-peap
Ready to process requests
(0) Received Access-Request Id 2 from 192.168.0.4:52371 to
192.168.0.1:1812 length 169
(0) User-Name = "anonymous"
(0) NAS-Identifier = "802aa8ac1ef9"
(0) NAS-Port = 0
(0) Called-Station-Id = "82-2A-A8-AD-1E-F9:SCILEK.NET"
(0) Calling-Station-Id = "00-26-C6-72-D2-F8"
(0) Framed-MTU = 1400
(0) NAS-Port-Type = Wireless-802.11
(0) Connect-Info = "CONNECT 0Mbps 802.11b"
(0) EAP-Message = 0x02ff000e01616e6f6e796d6f7573
(0) Message-Authenticator = 0x1e62d45b5b8abe56e27712fd43adc6c7
(0) # Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
(0) authorize {
(0) [preprocess] = ok
(0) redundant sql {
(0) sql1: EXPAND %{User-Name}
(0) sql1: --> anonymous
(0) sql1: SQL-User-Name set to 'anonymous'
rlm_sql (sql1): Reserved connection (1)
(0) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(0) sql1: --> CALL authorize_check('anonymous')
(0) sql1: Executing select query: CALL authorize_check('anonymous')
(0) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(0) sql1: --> CALL group_membership('anonymous')
(0) sql1: Executing select query: CALL group_membership('anonymous')
(0) sql1: User not found in any groups
rlm_sql (sql1): Released connection (1)
rlm_sql (sql1): Closing connection (2), from 3 unused connections
rlm_sql_mysql: Socket destructor called, closing socket
(0) [sql1] = notfound
(0) } # redundant sql = notfound
(0) pap: WARNING: No "known good" password found for the user. Not
setting Auth-Type
(0) pap: WARNING: Authentication will fail unless a "known good"
password is available
(0) [pap] = noop
(0) eap: Peer sent EAP Response (code 2) ID 255 length 14
(0) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the
rest of authorize
(0) [eap] = ok
(0) } # authorize = ok
(0) Found Auth-Type = eap
(0) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(0) authenticate {
(0) eap: Peer sent packet with method EAP Identity (1)
(0) eap: Calling submodule eap_ttls to process data
(0) eap_ttls: Initiating new EAP-TLS session
(0) eap_ttls: [eaptls start] = request
(0) eap: Sending EAP Request (code 1) ID 0 length 6
(0) eap: EAP session adding &reply:State = 0x418d1b1a418d0e7b
(0) [eap] = handled
(0) } # authenticate = handled
(0) Using Post-Auth-Type Challenge
(0) Post-Auth-Type sub-section not found. Ignoring.
(0) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(0) Sent Access-Challenge Id 2 from 192.168.0.1:1812 to
192.168.0.4:52371 length 0
(0) EAP-Message = 0x010000061520
(0) Message-Authenticator = 0x00000000000000000000000000000000
(0) State = 0x418d1b1a418d0e7baecbafb2f6fd97a1
(0) Finished request
Waking up in 4.9 seconds.
(1) Received Access-Request Id 3 from 192.168.0.4:52371 to
192.168.0.1:1812 length 229
(1) User-Name = "anonymous"
(1) NAS-Identifier = "802aa8ac1ef9"
(1) NAS-Port = 0
(1) Called-Station-Id = "82-2A-A8-AD-1E-F9:SCILEK.NET"
(1) Calling-Station-Id = "00-26-C6-72-D2-F8"
(1) Framed-MTU = 1400
(1) NAS-Port-Type = Wireless-802.11
(1) Connect-Info = "CONNECT 0Mbps 802.11b"
(1) EAP-Message =
0x020000381500160301002d010000290301f1b99311d79837940bc11a0f24e0e692dc8a7cfaa58df31a39f3f5802734aff4000002000a0100
(1) State = 0x418d1b1a418d0e7baecbafb2f6fd97a1
(1) Message-Authenticator = 0x3c448c950bc2dbf87263c61aa839c9ce
(1) session-state: No cached attributes
(1) # Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
(1) authorize {
(1) [preprocess] = ok
(1) redundant sql {
(1) sql1: EXPAND %{User-Name}
(1) sql1: --> anonymous
(1) sql1: SQL-User-Name set to 'anonymous'
rlm_sql (sql1): Reserved connection (3)
(1) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(1) sql1: --> CALL authorize_check('anonymous')
(1) sql1: Executing select query: CALL authorize_check('anonymous')
(1) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(1) sql1: --> CALL group_membership('anonymous')
(1) sql1: Executing select query: CALL group_membership('anonymous')
(1) sql1: User not found in any groups
rlm_sql (sql1): Released connection (3)
(1) [sql1] = notfound
(1) } # redundant sql = notfound
(1) pap: WARNING: No "known good" password found for the user. Not
setting Auth-Type
(1) pap: WARNING: Authentication will fail unless a "known good"
password is available
(1) [pap] = noop
(1) eap: Peer sent EAP Response (code 2) ID 0 length 56
(1) eap: Continuing tunnel setup
(1) [eap] = ok
(1) } # authorize = ok
(1) Found Auth-Type = eap
(1) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(1) authenticate {
(1) eap: Expiring EAP session with state 0x418d1b1a418d0e7b
(1) eap: Finished EAP session with state 0x418d1b1a418d0e7b
(1) eap: Previous EAP request found for state 0x418d1b1a418d0e7b,
released from the list
(1) eap: Peer sent packet with method EAP TTLS (21)
(1) eap: Calling submodule eap_ttls to process data
(1) eap_ttls: Authenticate
(1) eap_ttls: Continuing EAP-TLS
(1) eap_ttls: Got final TLS record fragment (50 bytes)
(1) eap_ttls: WARNING: Total received TLS record fragments (50 bytes),
does not equal indicated TLS record length (0 bytes)
(1) eap_ttls: [eaptls verify] = ok
(1) eap_ttls: Done initial handshake
(1) eap_ttls: (other): before/accept initialization
(1) eap_ttls: TLS_accept: before/accept initialization
(1) eap_ttls: <<< recv TLS 1.0 Handshake [length 002d], ClientHello
(1) eap_ttls: TLS_accept: SSLv3 read client hello A
(1) eap_ttls: >>> send TLS 1.0 Handshake [length 002a], ServerHello
(1) eap_ttls: TLS_accept: SSLv3 write server hello A
(1) eap_ttls: >>> send TLS 1.0 Handshake [length 09d4], Certificate
(1) eap_ttls: TLS_accept: SSLv3 write certificate A
(1) eap_ttls: >>> send TLS 1.0 Handshake [length 0004], ServerHelloDone
(1) eap_ttls: TLS_accept: SSLv3 write server done A
(1) eap_ttls: TLS_accept: SSLv3 flush data
(1) eap_ttls: TLS_accept: Need to read more data: SSLv3 read client
certificate A
(1) eap_ttls: TLS_accept: Need to read more data: SSLv3 read client
certificate A
(1) eap_ttls: In SSL Handshake Phase
(1) eap_ttls: In SSL Accept mode
(1) eap_ttls: [eaptls process] = handled
(1) eap: Sending EAP Request (code 1) ID 1 length 1004
(1) eap: EAP session adding &reply:State = 0x418d1b1a408c0e7b
(1) [eap] = handled
(1) } # authenticate = handled
(1) Using Post-Auth-Type Challenge
(1) Post-Auth-Type sub-section not found. Ignoring.
(1) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(1) Sent Access-Challenge Id 3 from 192.168.0.1:1812 to
192.168.0.4:52371 length 0
(1) EAP-Message =
0x010103ec15c000000a11160301002a02000026030190d37ae7310216fd6180e2b560cad45d9f7a873252076c9575efa7366262dce000000a0016030109d40b0009d00009
cd00051830820514308203fca003020102020101300d06092a864886f70d01010b0500308195310b3009060355040613025553
(1) Message-Authenticator = 0x00000000000000000000000000000000
(1) State = 0x418d1b1a408c0e7baecbafb2f6fd97a1
(1) Finished request
Waking up in 4.9 seconds.
(2) Received Access-Request Id 4 from 192.168.0.4:52371 to
192.168.0.1:1812 length 179
(2) User-Name = "anonymous"
(2) NAS-Identifier = "802aa8ac1ef9"
(2) NAS-Port = 0
(2) Called-Station-Id = "82-2A-A8-AD-1E-F9:SCILEK.NET"
(2) Calling-Station-Id = "00-26-C6-72-D2-F8"
(2) Framed-MTU = 1400
(2) NAS-Port-Type = Wireless-802.11
(2) Connect-Info = "CONNECT 0Mbps 802.11b"
(2) EAP-Message = 0x020100061500
(2) State = 0x418d1b1a408c0e7baecbafb2f6fd97a1
(2) Message-Authenticator = 0xcaa59edd5b9938d5385df84ec4650c82
(2) session-state: No cached attributes
(2) # Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
(2) authorize {
(2) [preprocess] = ok
(2) redundant sql {
(2) sql1: EXPAND %{User-Name}
(2) sql1: --> anonymous
(2) sql1: SQL-User-Name set to 'anonymous'
rlm_sql (sql1): Reserved connection (4)
(2) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(2) sql1: --> CALL authorize_check('anonymous')
(2) sql1: Executing select query: CALL authorize_check('anonymous')
(2) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(2) sql1: --> CALL group_membership('anonymous')
(2) sql1: Executing select query: CALL group_membership('anonymous')
(2) sql1: User not found in any groups
rlm_sql (sql1): Released connection (4)
(2) [sql1] = notfound
(2) } # redundant sql = notfound
(2) pap: WARNING: No "known good" password found for the user. Not
setting Auth-Type
(2) pap: WARNING: Authentication will fail unless a "known good"
password is available
(2) [pap] = noop
(2) eap: Peer sent EAP Response (code 2) ID 1 length 6
(2) eap: Continuing tunnel setup
(2) [eap] = ok
(2) } # authorize = ok
(2) Found Auth-Type = eap
(2) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(2) authenticate {
(2) eap: Expiring EAP session with state 0x418d1b1a408c0e7b
(2) eap: Finished EAP session with state 0x418d1b1a408c0e7b
(2) eap: Previous EAP request found for state 0x418d1b1a408c0e7b,
released from the list
(2) eap: Peer sent packet with method EAP TTLS (21)
(2) eap: Calling submodule eap_ttls to process data
(2) eap_ttls: Authenticate
(2) eap_ttls: Continuing EAP-TLS
(2) eap_ttls: Peer ACKed our handshake fragment
(2) eap_ttls: [eaptls verify] = request
(2) eap_ttls: [eaptls process] = handled
(2) eap: Sending EAP Request (code 1) ID 2 length 1004
(2) eap: EAP session adding &reply:State = 0x418d1b1a438f0e7b
(2) [eap] = handled
(2) } # authenticate = handled
(2) Using Post-Auth-Type Challenge
(2) Post-Auth-Type sub-section not found. Ignoring.
(2) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(2) Sent Access-Challenge Id 4 from 192.168.0.1:1812 to
192.168.0.4:52371 length 0
(2) EAP-Message =
0x010203ec15c000000a110116116365727473406578616d706c652e636f6d311b301906035504031312667265657261646975732d74656d702d6361820100301d0603551d
250416301406082b0601050507030106082b06010505080202300b0603551d0f0404030205a0300d06092a864886f70d01010b
(2) Message-Authenticator = 0x00000000000000000000000000000000
(2) State = 0x418d1b1a438f0e7baecbafb2f6fd97a1
(2) Finished request
Waking up in 4.9 seconds.
(3) Received Access-Request Id 5 from 192.168.0.4:52371 to
192.168.0.1:1812 length 179
(3) User-Name = "anonymous"
(3) NAS-Identifier = "802aa8ac1ef9"
(3) NAS-Port = 0
(3) Called-Station-Id = "82-2A-A8-AD-1E-F9:SCILEK.NET"
(3) Calling-Station-Id = "00-26-C6-72-D2-F8"
(3) Framed-MTU = 1400
(3) NAS-Port-Type = Wireless-802.11
(3) Connect-Info = "CONNECT 0Mbps 802.11b"
(3) EAP-Message = 0x020200061500
(3) State = 0x418d1b1a438f0e7baecbafb2f6fd97a1
(3) Message-Authenticator = 0x59326993c24ae834a3a1a4537a6d0f22
(3) session-state: No cached attributes
(3) # Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
(3) authorize {
(3) [preprocess] = ok
(3) redundant sql {
(3) sql1: EXPAND %{User-Name}
(3) sql1: --> anonymous
(3) sql1: SQL-User-Name set to 'anonymous'
rlm_sql (sql1): Reserved connection (0)
(3) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(3) sql1: --> CALL authorize_check('anonymous')
(3) sql1: Executing select query: CALL authorize_check('anonymous')
(3) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(3) sql1: --> CALL group_membership('anonymous')
(3) sql1: Executing select query: CALL group_membership('anonymous')
(3) sql1: User not found in any groups
rlm_sql (sql1): Released connection (0)
(3) [sql1] = notfound
(3) } # redundant sql = notfound
(3) pap: WARNING: No "known good" password found for the user. Not
setting Auth-Type
(3) pap: WARNING: Authentication will fail unless a "known good"
password is available
(3) [pap] = noop
(3) eap: Peer sent EAP Response (code 2) ID 2 length 6
(3) eap: Continuing tunnel setup
(3) [eap] = ok
(3) } # authorize = ok
(3) Found Auth-Type = eap
(3) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(3) authenticate {
(3) eap: Expiring EAP session with state 0x418d1b1a438f0e7b
(3) eap: Finished EAP session with state 0x418d1b1a438f0e7b
(3) eap: Previous EAP request found for state 0x418d1b1a438f0e7b,
released from the list
(3) eap: Peer sent packet with method EAP TTLS (21)
(3) eap: Calling submodule eap_ttls to process data
(3) eap_ttls: Authenticate
(3) eap_ttls: Continuing EAP-TLS
(3) eap_ttls: Peer ACKed our handshake fragment
(3) eap_ttls: [eaptls verify] = request
(3) eap_ttls: [eaptls process] = handled
(3) eap: Sending EAP Request (code 1) ID 3 length 599
(3) eap: EAP session adding &reply:State = 0x418d1b1a428e0e7b
(3) [eap] = handled
(3) } # authenticate = handled
(3) Using Post-Auth-Type Challenge
(3) Post-Auth-Type sub-section not found. Ignoring.
(3) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(3) Sent Access-Challenge Id 5 from 192.168.0.1:1812 to
192.168.0.4:52371 length 0
(3) EAP-Message =
0x01030257158000000a119e6baf6a1ca287e7fa5ec44940e1ba92019638e59efffa9ae07b75a7b4e4bf9850926106ed0203010001a38201023081ff301d0603551d0e0416
04141146326f07c5778d5978fe8a2de29dbefed4d0283081c20603551d230481ba3081b780141146326f07c5778d5978fe8a2d
(3) Message-Authenticator = 0x00000000000000000000000000000000
(3) State = 0x418d1b1a428e0e7baecbafb2f6fd97a1
(3) Finished request
Waking up in 4.9 seconds.
(4) Received Access-Request Id 6 from 192.168.0.4:52371 to
192.168.0.1:1812 length 499
(4) User-Name = "anonymous"
(4) NAS-Identifier = "802aa8ac1ef9"
(4) NAS-Port = 0
(4) Called-Station-Id = "82-2A-A8-AD-1E-F9:SCILEK.NET"
(4) Calling-Station-Id = "00-26-C6-72-D2-F8"
(4) Framed-MTU = 1400
(4) NAS-Port-Type = Wireless-802.11
(4) Connect-Info = "CONNECT 0Mbps 802.11b"
(4) EAP-Message =
0x020301441500160301010610000102010056802e5b5275d1632dbc7bb3ce78e79168b0048f90ab99fc720b86ca95354fc9d08dce0c11730ab5c6323fa837014cf8b83a4b
44f270b5280a8b08e772099004864b1190cddf939d48070fe58f1136d80ac62963138084a68d434e1584988866ad2d5140bd95
(4) State = 0x418d1b1a428e0e7baecbafb2f6fd97a1
(4) Message-Authenticator = 0x5c31b7e2c0ff66ad75e1fdf81268c6c9
(4) session-state: No cached attributes
(4) # Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
(4) authorize {
(4) [preprocess] = ok
(4) redundant sql {
(4) sql1: EXPAND %{User-Name}
(4) sql1: --> anonymous
(4) sql1: SQL-User-Name set to 'anonymous'
rlm_sql (sql1): Reserved connection (1)
(4) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(4) sql1: --> CALL authorize_check('anonymous')
(4) sql1: Executing select query: CALL authorize_check('anonymous')
(4) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(4) sql1: --> CALL group_membership('anonymous')
(4) sql1: Executing select query: CALL group_membership('anonymous')
(4) sql1: User not found in any groups
rlm_sql (sql1): Released connection (1)
(4) [sql1] = notfound
(4) } # redundant sql = notfound
(4) pap: WARNING: No "known good" password found for the user. Not
setting Auth-Type
(4) pap: WARNING: Authentication will fail unless a "known good"
password is available
(4) [pap] = noop
(4) eap: Peer sent EAP Response (code 2) ID 3 length 324
(4) eap: Continuing tunnel setup
(4) [eap] = ok
(4) } # authorize = ok
(4) Found Auth-Type = eap
(4) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(4) authenticate {
(4) eap: Expiring EAP session with state 0x418d1b1a428e0e7b
(4) eap: Finished EAP session with state 0x418d1b1a428e0e7b
(4) eap: Previous EAP request found for state 0x418d1b1a428e0e7b,
released from the list
(4) eap: Peer sent packet with method EAP TTLS (21)
(4) eap: Calling submodule eap_ttls to process data
(4) eap_ttls: Authenticate
(4) eap_ttls: Continuing EAP-TLS
(4) eap_ttls: [eaptls verify] = ok
(4) eap_ttls: Done initial handshake
(4) eap_ttls: <<< recv TLS 1.0 Handshake [length 0106], ClientKeyExchange
(4) eap_ttls: TLS_accept: SSLv3 read client key exchange A
(4) eap_ttls: TLS_accept: SSLv3 read certificate verify A
(4) eap_ttls: <<< recv TLS 1.0 ChangeCipherSpec [length 0001]
(4) eap_ttls: <<< recv TLS 1.0 Handshake [length 0010], Finished
(4) eap_ttls: TLS_accept: SSLv3 read finished A
(4) eap_ttls: >>> send TLS 1.0 ChangeCipherSpec [length 0001]
(4) eap_ttls: TLS_accept: SSLv3 write change cipher spec A
(4) eap_ttls: >>> send TLS 1.0 Handshake [length 0010], Finished
(4) eap_ttls: TLS_accept: SSLv3 write finished A
(4) eap_ttls: TLS_accept: SSLv3 flush data
(4) eap_ttls: (other): SSL negotiation finished successfully
(4) eap_ttls: SSL Connection Established
(4) eap_ttls: [eaptls process] = handled
(4) eap: Sending EAP Request (code 1) ID 4 length 61
(4) eap: EAP session adding &reply:State = 0x418d1b1a45890e7b
(4) [eap] = handled
(4) } # authenticate = handled
(4) Using Post-Auth-Type Challenge
(4) Post-Auth-Type sub-section not found. Ignoring.
(4) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(4) Sent Access-Challenge Id 6 from 192.168.0.1:1812 to
192.168.0.4:52371 length 0
(4) EAP-Message =
0x0104003d158000000033140301000101160301002820d5bef24e4864a308c6c562c26eb5b6e676f02418bf5da5390254c5100fd95680736b3980b80033
(4) Message-Authenticator = 0x00000000000000000000000000000000
(4) State = 0x418d1b1a45890e7baecbafb2f6fd97a1
(4) Finished request
Waking up in 4.7 seconds.
(5) Received Access-Request Id 7 from 192.168.0.4:52371 to
192.168.0.1:1812 length 240
(5) User-Name = "anonymous"
(5) NAS-Identifier = "802aa8ac1ef9"
(5) NAS-Port = 0
(5) Called-Station-Id = "82-2A-A8-AD-1E-F9:SCILEK.NET"
(5) Calling-Station-Id = "00-26-C6-72-D2-F8"
(5) Framed-MTU = 1400
(5) NAS-Port-Type = Wireless-802.11
(5) Connect-Info = "CONNECT 0Mbps 802.11b"
(5) EAP-Message =
0x0204004315001703010038790bbda0fd97f73c98474e19730eb2eabaa550aae994c4e54770671cd51560a5be3cfa25195fec12ee65e61900128ccd45473b7b8ef0842c
(5) State = 0x418d1b1a45890e7baecbafb2f6fd97a1
(5) Message-Authenticator = 0x5e50c0a036d0da8fe72186303ac6f412
(5) session-state: No cached attributes
(5) # Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
(5) authorize {
(5) [preprocess] = ok
(5) redundant sql {
(5) sql1: EXPAND %{User-Name}
(5) sql1: --> anonymous
(5) sql1: SQL-User-Name set to 'anonymous'
rlm_sql (sql1): Reserved connection (3)
(5) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(5) sql1: --> CALL authorize_check('anonymous')
(5) sql1: Executing select query: CALL authorize_check('anonymous')
(5) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(5) sql1: --> CALL group_membership('anonymous')
(5) sql1: Executing select query: CALL group_membership('anonymous')
(5) sql1: User not found in any groups
rlm_sql (sql1): Released connection (3)
(5) [sql1] = notfound
(5) } # redundant sql = notfound
(5) pap: WARNING: No "known good" password found for the user. Not
setting Auth-Type
(5) pap: WARNING: Authentication will fail unless a "known good"
password is available
(5) [pap] = noop
(5) eap: Peer sent EAP Response (code 2) ID 4 length 67
(5) eap: Continuing tunnel setup
(5) [eap] = ok
(5) } # authorize = ok
(5) Found Auth-Type = eap
(5) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(5) authenticate {
(5) eap: Expiring EAP session with state 0x418d1b1a45890e7b
(5) eap: Finished EAP session with state 0x418d1b1a45890e7b
(5) eap: Previous EAP request found for state 0x418d1b1a45890e7b,
released from the list
(5) eap: Peer sent packet with method EAP TTLS (21)
(5) eap: Calling submodule eap_ttls to process data
(5) eap_ttls: Authenticate
(5) eap_ttls: Continuing EAP-TLS
(5) eap_ttls: [eaptls verify] = ok
(5) eap_ttls: Done initial handshake
(5) eap_ttls: [eaptls process] = ok
(5) eap_ttls: Session established. Proceeding to decode tunneled attributes
(5) eap_ttls: Got tunneled request
(5) eap_ttls: User-Name = "scilek"
(5) eap_ttls: User-Password = "0000"
(5) eap_ttls: FreeRADIUS-Proxied-To = 127.0.0.1
(5) eap_ttls: Sending tunneled request
(5) Virtual server inner-tunnel-ttls received request
(5) User-Name = "scilek"
(5) User-Password = "0000"
(5) FreeRADIUS-Proxied-To = 127.0.0.1
(5) NAS-Identifier = "802aa8ac1ef9"
(5) NAS-Port = 0
(5) Called-Station-Id = "82-2A-A8-AD-1E-F9:SCILEK.NET"
(5) Calling-Station-Id = "00-26-C6-72-D2-F8"
(5) Framed-MTU = 1400
(5) NAS-Port-Type = Wireless-802.11
(5) Connect-Info = "CONNECT 0Mbps 802.11b"
(5) Event-Timestamp = "Sep 23 2017 17:18:17 +03"
(5) NAS-IP-Address = 192.168.0.4
(5) server inner-tunnel-ttls {
(5) # Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/inner-tunnel-ttls
(5) authorize {
(5) if ("%{sql: CALL is_login_allowed('%{User-Name}')}" == "0" ) {
(5) EXPAND %{User-Name}
(5) --> scilek
(5) SQL-User-Name set to 'scilek'
rlm_sql (sql1): Reserved connection (4)
(5) EXPAND /var/log/sqltrace.sql
(5) --> /var/log/sqltrace.sql
(5) Executing select query: CALL is_login_allowed('scilek')
rlm_sql (sql1): Released connection (4)
(5) EXPAND %{sql: CALL is_login_allowed('%{User-Name}')}
(5) --> 1
(5) if ("%{sql: CALL is_login_allowed('%{User-Name}')}" == "0" )
-> FALSE
(5) eap: No EAP-Message, not doing EAP
(5) [eap] = noop
(5) redundant sql {
(5) sql1: EXPAND %{User-Name}
(5) sql1: --> scilek
(5) sql1: SQL-User-Name set to 'scilek'
rlm_sql (sql1): Reserved connection (0)
(5) sql1: EXPAND CALL authorize_check('%{SQL-User-Name}')
(5) sql1: --> CALL authorize_check('scilek')
(5) sql1: Executing select query: CALL authorize_check('scilek')
(5) sql1: User found in radcheck table
(5) sql1: Conditional check items matched, merging assignment check items
(5) sql1: Cleartext-Password := "0000"
(5) sql1: Simultaneous-Use := 1
(5) sql1: EXPAND CALL authorize_reply('%{SQL-User-Name}')
(5) sql1: --> CALL authorize_reply('scilek')
(5) sql1: Executing select query: CALL authorize_reply('scilek')
(5) sql1: User found in radreply table, merging reply items
(5) sql1: Class := 0x5f7363696c656b
(5) sql1: Idle-Timeout := 120
(5) sql1: Acct-Interim-Interval := 600
(5) sql1: Exec-Program-Wait = "/usr/local/bin/bash
/usr/local/etc/raddb/scripts/datacounter_auth.sh scilek"
(5) sql1: EXPAND CALL group_membership('%{SQL-User-Name}')
(5) sql1: --> CALL group_membership('scilek')
(5) sql1: Executing select query: CALL group_membership('scilek')
(5) sql1: User not found in any groups
rlm_sql (sql1): Released connection (0)
(5) [sql1] = ok
(5) } # redundant sql = ok
(5) [expiration] = noop
(5) [logintime] = noop
(5) [pap] = updated
(5) } # authorize = updated
(5) Found Auth-Type = pap
(5) # Executing group from file
/usr/local/etc/raddb/sites-enabled/inner-tunnel-ttls
(5) Auth-Type PAP {
(5) pap: Login attempt with password
(5) pap: Comparing with "known good" Cleartext-Password
(5) pap: User authenticated successfully
(5) [pap] = ok
(5) } # Auth-Type PAP = ok
(5) # Executing section session from file
/usr/local/etc/raddb/sites-enabled/inner-tunnel-ttls
(5) session {
(5) redundant sql {
(5) sql1: EXPAND %{User-Name}
(5) sql1: --> scilek
(5) sql1: SQL-User-Name set to 'scilek'
(5) sql1: EXPAND CALL simul_count('%{SQL-User-Name}')
(5) sql1: --> CALL simul_count('scilek')
rlm_sql (sql1): Reserved connection (1)
(5) sql1: Executing select query: CALL simul_count('scilek')
rlm_sql (sql1): Released connection (1)
(5) [sql1] = ok
(5) } # redundant sql = ok
(5) } # session = ok
(5) # Executing section post-auth from file
/usr/local/etc/raddb/sites-enabled/inner-tunnel-ttls
(5) post-auth {
(5) if (1) {
(5) if (1) -> TRUE
(5) if (1) {
(5) update reply {
(5) User-Name !* ANY
(5) Message-Authenticator !* ANY
(5) EAP-Message !* ANY
(5) Proxy-State !* ANY
(5) MS-MPPE-Encryption-Types !* ANY
(5) MS-MPPE-Encryption-Policy !* ANY
(5) MS-MPPE-Send-Key !* ANY
(5) MS-MPPE-Recv-Key !* ANY
(5) } # update reply = noop
(5) update {
(5) &outer.session-state::Class += &reply:Class[*] ->
0x5f7363696c656b
(5) &outer.session-state::Idle-Timeout +=
&reply:Idle-Timeout[*] -> 120
(5) &outer.session-state::Acct-Interim-Interval +=
&reply:Acct-Interim-Interval[*] -> 600
(5) &outer.session-state::Exec-Program-Wait +=
&reply:Exec-Program-Wait[*] -> '/usr/local/bin/bash
/usr/local/etc/raddb/scripts/datacounter_auth.sh
scilek'
(5) } # update = noop
(5) } # if (1) = noop
(5) } # post-auth = noop
(5) Login OK: [scilek] (from client HOME_AP port 0 cli
00-26-C6-72-D2-F8 via TLS tunnel)
(5) } # server inner-tunnel-ttls
(5) Virtual server sending reply
(5) Class = 0x5f7363696c656b
(5) Idle-Timeout = 120
(5) Acct-Interim-Interval = 600
(5) Exec-Program-Wait = "/usr/local/bin/bash
/usr/local/etc/raddb/scripts/datacounter_auth.sh scilek"
(5) eap_ttls: Got tunneled Access-Accept
(5) eap: Sending EAP Success (code 3) ID 4 length 4
(5) eap: Freeing handler
(5) [eap] = ok
(5) } # authenticate = ok
(5) # Executing section post-auth from file
/usr/local/etc/raddb/sites-enabled/default
(5) post-auth {
(5) [exec] = noop
(5) } # post-auth = noop
(5) Login OK: [anonymous] (from client HOME_AP port 0 cli 00-26-C6-72-D2-F8)
(5) Sent Access-Accept Id 7 from 192.168.0.1:1812 to 192.168.0.4:52371
length 0
(5) MS-MPPE-Recv-Key =
0x4ea1660394b373c00aafe60fddb13369f19ffc3cae4ae7ee41cc7ff96f5ad6d1
(5) MS-MPPE-Send-Key =
0xd3e5cea80a4275aaefb15531d3ebef6e171ddc828752b9d903ed33d0e149ff61
(5) EAP-Message = 0x03040004
(5) Message-Authenticator = 0x00000000000000000000000000000000
(5) User-Name = "anonymous"
(5) Finished request
Waking up in 4.5 seconds.
(6) Received Accounting-Request Id 8 from 192.168.0.4:50672 to
192.168.0.1:1813 length 166
(6) Acct-Session-Id = "0000002B-00000000"
(6) Acct-Status-Type = Start
(6) Acct-Authentic = RADIUS
(6) User-Name = "anonymous"
(6) Framed-IP-Address = 192.168.255.23
(6) NAS-Identifier = "802aa8ac1ef9"
(6) NAS-Port = 0
(6) Called-Station-Id = "82-2A-A8-AD-1E-F9:SCILEK.NET"
(6) Calling-Station-Id = "00-26-C6-72-D2-F8"
(6) NAS-Port-Type = Wireless-802.11
(6) Connect-Info = "CONNECT 0Mbps 802.11b"
(6) # Executing section preacct from file
/usr/local/etc/raddb/sites-enabled/default
(6) preacct {
(6) [preprocess] = ok
(6) } # preacct = ok
(6) # Executing section accounting from file
/usr/local/etc/raddb/sites-enabled/default
(6) accounting {
(6) detail: EXPAND
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d
(6) detail: --> /var/log/radacct/192.168.0.4/detail_2017_09_23
(6) detail:
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d
expands to /var/log/radacct/192.168.0.4/detail_2017_09_23
(6) detail: EXPAND %t
(6) detail: --> Sat Sep 23 17:18:17 2017
(6) [detail] = ok
(6) redundant sql {
(6) sql1: EXPAND %{tolower:type.%{Acct-Status-Type}.query}
(6) sql1: --> type.start.query
(6) sql1: Using query template 'query'
rlm_sql (sql1): Reserved connection (3)
(6) sql1: EXPAND %{User-Name}
(6) sql1: --> anonymous
(6) sql1: SQL-User-Name set to 'anonymous'
(6) sql1: EXPAND CALL
accounting_start('%{Acct-Session-Id}','%{SQL-User-Name}','%{Class}','%{NAS-IP-Address}','%{Called-Station-Id}','%{Calling-Station-Id}')
(6) sql1: --> CALL
accounting_start('0000002B-00000000','anonymous','','192.168.0.4','82-2A-A8-AD-1E-F9=3ASCILEK.NET','00-26-C6-72-D2-F8')
(6) sql1: EXPAND /var/log/sqltrace.sql
(6) sql1: --> /var/log/sqltrace.sql
(6) sql1: Executing query: CALL
accounting_start('0000002B-00000000','anonymous','','192.168.0.4','82-2A-A8-AD-1E-F9=3ASCILEK.NET','00-26-C6-72-D2-F8')
(6) sql1: SQL query returned: success
(6) sql1: 1 record(s) updated
rlm_sql (sql1): Released connection (3)
(6) [sql1] = ok
(6) } # redundant sql = ok
(6) [exec] = noop
(6) if (request:Acct-Status-Type == Interim-Update) {
(6) if (request:Acct-Status-Type == Interim-Update) -> FALSE
(6) if (Acct-Session-Time == 0) {
(6) ERROR: Failed retrieving values required to evaluate condition
(6) } # accounting = ok
(6) Sent Accounting-Response Id 8 from 192.168.0.1:1813 to
192.168.0.4:50672 length 0
(6) Finished request
(6) Cleaning up request packet ID 8 with timestamp +32
Waking up in 4.1 seconds.
(0) Cleaning up request packet ID 2 with timestamp +31
(1) Cleaning up request packet ID 3 with timestamp +31
(2) Cleaning up request packet ID 4 with timestamp +32
(3) Cleaning up request packet ID 5 with timestamp +32
Waking up in 0.1 seconds.
(4) Cleaning up request packet ID 6 with timestamp +32
Waking up in 0.2 seconds.
(5) Cleaning up request packet ID 7 with timestamp +32
Ready to process requests
(7) Received Accounting-Request Id 9 from 192.168.0.4:50672 to
192.168.0.1:1813 length 202
(7) Acct-Session-Id = "0000002B-00000000"
(7) Acct-Status-Type = Interim-Update
(7) Acct-Authentic = RADIUS
(7) User-Name = "anonymous"
(7) Framed-IP-Address = 192.168.1.113
(7) NAS-Identifier = "802aa8ac1ef9"
(7) NAS-Port = 0
(7) Called-Station-Id = "82-2A-A8-AD-1E-F9:SCILEK.NET"
(7) Calling-Station-Id = "00-26-C6-72-D2-F8"
(7) NAS-Port-Type = Wireless-802.11
(7) Connect-Info = "CONNECT 0Mbps 802.11b"
(7) Acct-Session-Time = 5
(7) Acct-Input-Packets = 135
(7) Acct-Output-Packets = 43
(7) Acct-Input-Octets = 17992
(7) Acct-Output-Octets = 6888
(7) Event-Timestamp = "Sep 23 2017 17:18:22 +03"
(7) # Executing section preacct from file
/usr/local/etc/raddb/sites-enabled/default
(7) preacct {
(7) [preprocess] = ok
(7) } # preacct = ok
(7) # Executing section accounting from file
/usr/local/etc/raddb/sites-enabled/default
(7) accounting {
(7) detail: EXPAND
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d
(7) detail: --> /var/log/radacct/192.168.0.4/detail_2017_09_23
(7) detail:
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d
expands to /var/log/radacct/192.168.0.4/detail_2017_09_23
(7) detail: EXPAND %t
(7) detail: --> Sat Sep 23 17:18:22 2017
(7) [detail] = ok
(7) redundant sql {
(7) sql1: EXPAND %{tolower:type.%{Acct-Status-Type}.query}
(7) sql1: --> type.interim-update.query
(7) sql1: Using query template 'query'
rlm_sql (sql1): Reserved connection (4)
(7) sql1: EXPAND %{User-Name}
(7) sql1: --> anonymous
(7) sql1: SQL-User-Name set to 'anonymous'
(7) sql1: EXPAND CALL accounting_update
('%{Acct-Session-Id}','%{Called-Station-Id}','%{Calling-Station-Id}','%{Acct-Session-Time}','%{Acct-Input-Octets}','%{
Acct-Input-Gigawords}','%{Acct-Output-Octets}','%{Acct-Output-Gigawords}')
(7) sql1: --> CALL accounting_update
('0000002B-00000000','82-2A-A8-AD-1E-F9=3ASCILEK.NET','00-26-C6-72-D2-F8','5','17992','','6888','')
(7) sql1: EXPAND /var/log/sqltrace.sql
(7) sql1: --> /var/log/sqltrace.sql
(7) sql1: Executing query: CALL accounting_update
('0000002B-00000000','82-2A-A8-AD-1E-F9=3ASCILEK.NET','00-26-C6-72-D2-F8','5','17992','','6888','')
(7) sql1: SQL query returned: success
(7) sql1: 1 record(s) updated
rlm_sql (sql1): Released connection (4)
(7) [sql1] = ok
(7) } # redundant sql = ok
(7) [exec] = noop
(7) if (request:Acct-Status-Type == Interim-Update) {
(7) if (request:Acct-Status-Type == Interim-Update) -> TRUE
(7) if (request:Acct-Status-Type == Interim-Update) {
(7) check_quota: Executing: /usr/local/bin/bash
/usr/local/etc/raddb/scripts/datacounter_acct.sh %{request:User-Name}
%{request:Calling-Station-Id} %{request:
NAS-IP-Address} %{request:Class} %{request:Acct-Status-Type}:
(7) check_quota: EXPAND %{request:User-Name}
(7) check_quota: --> anonymous
(7) check_quota: EXPAND %{request:Calling-Station-Id}
(7) check_quota: --> 00-26-C6-72-D2-F8
(7) check_quota: EXPAND %{request:NAS-IP-Address}
(7) check_quota: --> 192.168.0.4
(7) check_quota: EXPAND %{request:Class}
(7) check_quota: -->
(7) check_quota: EXPAND %{request:Acct-Status-Type}
(7) check_quota: --> Interim-Update
(7) check_quota: Program executed successfully
(7) [check_quota] = ok
(7) } # if (request:Acct-Status-Type == Interim-Update) = ok
(7) if (Acct-Session-Time == 0) {
(7) if (Acct-Session-Time == 0) -> FALSE
(7) } # accounting = ok
(7) Sent Accounting-Response Id 9 from 192.168.0.1:1813 to
192.168.0.4:50672 length 0
(7) Finished request
(7) Cleaning up request packet ID 9 with timestamp +37
Ready to process requests
Warning: Using a password on the command line interface can be insecure.
Warning: Using a password on the command line interface can be insecure.
ERROR 1370 (42000) at line 1: execute command denied to user
'quota_checker'@'localhost' for routine 'raddb.get_simple_usage_info'
/usr/local/etc/raddb/scripts/datacounter_acct.sh: line 67: ((: < :
syntax error: operand expected (error token is "< ")
/bin/sh: can't open /etc/persistent/kick_mac.sh
(8) Received Accounting-Request Id 10 from 192.168.0.4:50672 to
192.168.0.1:1813 length 208
(8) Acct-Session-Id = "0000002B-00000000"
(8) Acct-Status-Type = Stop
(8) Acct-Authentic = RADIUS
(8) User-Name = "anonymous"
(8) Framed-IP-Address = 192.168.1.113
(8) NAS-Identifier = "802aa8ac1ef9"
(8) NAS-Port = 0
(8) Called-Station-Id = "82-2A-A8-AD-1E-F9:SCILEK.NET"
(8) Calling-Station-Id = "00-26-C6-72-D2-F8"
(8) NAS-Port-Type = Wireless-802.11
(8) Connect-Info = "CONNECT 0Mbps 802.11b"
(8) Acct-Session-Time = 35
(8) Acct-Input-Packets = 277
(8) Acct-Output-Packets = 48
(8) Acct-Input-Octets = 35621
(8) Acct-Output-Octets = 7261
(8) Event-Timestamp = "Sep 23 2017 17:18:52 +03"
(8) Acct-Terminate-Cause = User-Request
(8) # Executing section preacct from file
/usr/local/etc/raddb/sites-enabled/default
(8) preacct {
(8) [preprocess] = ok
(8) } # preacct = ok
(8) # Executing section accounting from file
/usr/local/etc/raddb/sites-enabled/default
(8) accounting {
(8) detail: EXPAND
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d
(8) detail: --> /var/log/radacct/192.168.0.4/detail_2017_09_23
(8) detail:
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d
expands to /var/log/radacct/192.168.0.4/detail_2017_09_23
(8) detail: EXPAND %t
(8) detail: --> Sat Sep 23 17:18:52 2017
(8) [detail] = ok
(8) redundant sql {
(8) sql1: EXPAND %{tolower:type.%{Acct-Status-Type}.query}
(8) sql1: --> type.stop.query
(8) sql1: Using query template 'query'
rlm_sql (sql1): Reserved connection (0)
(8) sql1: EXPAND %{User-Name}
(8) sql1: --> anonymous
(8) sql1: SQL-User-Name set to 'anonymous'
(8) sql1: EXPAND CALL accounting_stop
('%{Acct-Session-Id}','%{SQL-User-Name}','%{Called-Station-Id}','%{Calling-Station-Id}','%{Acct-Session-Time}','%{Acct-I
nput-Octets}','%{Acct-Input-Gigawords}','%{Acct-Output-Octets}','%{Acct-Output-Gigawords}','%{Acct-Terminate-Cause}')
(8) sql1: --> CALL accounting_stop
('0000002B-00000000','anonymous','82-2A-A8-AD-1E-F9=3ASCILEK.NET','00-26-C6-72-D2-F8','35','35621','','7261','','User-Re
quest')
(8) sql1: EXPAND /var/log/sqltrace.sql
(8) sql1: --> /var/log/sqltrace.sql
(8) sql1: Executing query: CALL accounting_stop
('0000002B-00000000','anonymous','82-2A-A8-AD-1E-F9=3ASCILEK.NET','00-26-C6-72-D2-F8','35','35621','','7261','
','User-Request')
(8) sql1: SQL query returned: success
(8) sql1: 1 record(s) updated
rlm_sql (sql1): Released connection (0)
rlm_sql (sql1): Closing connection (1), from 1 unused connections
rlm_sql_mysql: Socket destructor called, closing socket
(8) [sql1] = ok
(8) } # redundant sql = ok
(8) [exec] = noop
(8) if (request:Acct-Status-Type == Interim-Update) {
(8) if (request:Acct-Status-Type == Interim-Update) -> FALSE
(8) if (Acct-Session-Time == 0) {
(8) if (Acct-Session-Time == 0) -> FALSE
(8) } # accounting = ok
(8) Sent Accounting-Response Id 10 from 192.168.0.1:1813 to
192.168.0.4:50672 length 0
(8) Finished request
(8) Cleaning up request packet ID 10 with timestamp +67
Ready to process requests
---
This email has been checked for viruses by Avast antivirus software.
https://www.avast.com/antivirus
More information about the Freeradius-Users
mailing list