On 23.09.2017 16:23, Alan DeKok wrote:
On Sep 23, 2017, at 1:16 AM, Selahattin Cilek <selahattin_cilek@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!#+%&?*-_@." 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