August 2019 - Freeradius-Users - lists.freeradius.org

PEAP - fast reconnect
by Marcin Marszałkowski 21 Aug '19

21 Aug '19

I’ve been looking through docs but I couldn’t find an answer. Does Freeradius support fast reconnect (for roaming wifi users) with EAP PEAP by default or it needs to be enabled/configured? Regards Martin

2 10

Internal vs external proxy server
by Artis Caune 21 Aug '19

21 Aug '19

Hi guys, Can someone please point me in right direction of why reply attributes gets deleted from internal proxy reply ? If I use: DEFAULT Proxy-To-Realm := "dialup" realm dialup { virtual_server = dialup } server dialup { authorize { dialup_sql_auth pap } authenticate { Auth-Type PAP { pap } } post-auth { update reply { &Alc-Subsc-ID-Str := "DIALUP-%{%{Stripped-User-Name}:-%{User-Name}}" } } } default server gets reply from dialup server but ignore any reply attributes and returns empty Accept. I can copy attribute from proxy-reply in post-proxy and see it in radclient accept. update reply { &Alc-Subsc-ID-Str := &proxy-reply:Alc-Subsc-ID-Str } But if i use same config but change dialup from internal to external proxy it works and I can see all return attributes: server dialup { listen { type = auth ipaddr = 127.0.0.1 port = 1645 } ... } realm dialup { authhost=127.0.0.1:1645 secret=xxx } Thanks, Artis

2 3

Error after modification in the users file.
by Schmid, Marco 20 Aug '19

20 Aug '19

Hello, after modifying the users file, I get the following error: „Parse error (check) for entry DEFAULT: Unknown name „Ldap-Group“ I’m using freeradius version 3.0.16. It worked under version 3.0.13 Greetings Marco Mit freundlichen Grüßen Marco Schmid Technik [cid:email_indasys_connectivity.jpg@9824D5A5.0001]<http://www.indasys.de> indasys connectivity GmbH Leitzstraße 4c D-70469 Stuttgart Telefon: Telefax: E-Mail: Web: +49 711 896659 110 +49 711 896659 149 Marco.Schmid(a)indasys.de<mailto:Marco.Schmid@indasys.de> www.indasys.de<http://www.indasys.de/> USID: DE273320932 HRB: 734651 AG Stuttgart Geschäftsführer: Sebastian Schwab, Dominik Appich

2 1

Runtime Memory Optimization - freeradius2 for OpenWRT
by Lalit Kumar Mishra 20 Aug '19

20 Aug '19

Hi, I recently compiled freeradius2 for OpenWrt attitude adjustment, did selective compilation of freeradius2 only with EAP-TLS module since I want to use only this module. I am facing two issues, Can someone help me over this. 1. Freeradius2 is taking 3.7 MB RAM runtime memory on OpenWRT board, Can we further optimize/ reduce runtime memory requirement on OpenWRT. 2. Freeradius2 is not starting without debug mode. Any input/ pointers would help. Thank you. Regards Lalit

2 1

Ldap Query
by Schmid, Marco 20 Aug '19

20 Aug '19

Hello, I’ve installed the packages „freeradius“ and „freeradius-ldap“ Freeradius in Version 3.0.16. When I modify the „user“-file, I can’t start freeradius any more. Parse errof „Ldap-Group“ unknown. I did the same under freeradius 3.0.13, and it worked. Has something changed since then? Greetings Marco Mit freundlichen Grüßen Marco Schmid Technik [cid:email_indasys_connectivity.jpg@9824D5A5.0001]<http://www.indasys.de> indasys connectivity GmbH Leitzstraße 4c D-70469 Stuttgart Telefon: Telefax: E-Mail: Web: +49 711 896659 110 +49 711 896659 149 Marco.Schmid(a)indasys.de<mailto:Marco.Schmid@indasys.de> www.indasys.de<http://www.indasys.de/> USID: DE273320932 HRB: 734651 AG Stuttgart Geschäftsführer: Sebastian Schwab, Dominik Appich

1 0

Invalid vendor name in attribute name error after migration from 2.2.6 to 3.0.13
by Лев Валуев 20 Aug '19

20 Aug '19

We trying to move from freeradius 2.2.6 to 3.0.13. Looks like I was able to modify almost all the configuration, but I have an issue with one of the attribute names in users file and I am not sure what's wrong with it. Error message: /etc/raddb/users[34]: Parse error (reply) for entry DEFAULT: Invalid vendor name in attribute name "GroupName" Failed reading /etc/raddb/users /etc/raddb/users file: DEFAULT Huntgroup-Name == "F5",Group == "NetworkAdmins",Auth-Type := pam Service-Type = NAS-Prompt-User, F5-LTM-User-Info-1 = admin DEFAULT Huntgroup-Name == "F5",Group == "PCCAdmins",Auth-Type := pam Service-Type = NAS-Prompt-User, F5-LTM-User-Info-1 = pccmanager DEFAULT Huntgroup-Name == "F5",Group == "InformationSecurity",Auth-Type := pam Service-Type = NAS-Prompt-User, F5-LTM-User-Info-1 = guest DEFAULT Huntgroup-Name == "F5",Group == "NOC",Auth-Type := pam Service-Type = NAS-Prompt-User, F5-LTM-User-Info-1 = noc DEFAULT Huntgroup-Name == "F5",Auth-Type := Reject DEFAULT Huntgroup-Name == "IOS",Group == "NetworkAdmins",Auth-Type := pam Service-Type = NAS-Prompt-User, cisco-avpair = "shell:priv-lvl=15" DEFAULT Huntgroup-Name == "IOS",Group == "NOC",Auth-Type := pam Service-Type = NAS-Prompt-User, cisco-avpair = "shell:priv-lvl=7" DEFAULT Huntgroup-Name == "IOS",Auth-Type := Reject DEFAULT Huntgroup-Name == "Nexus",Group == "NetworkAdmins",Auth-Type := pam Service-Type = NAS-Prompt-User, cisco-avpair = 'shell:roles="network-admin"' DEFAULT Huntgroup-Name == "Nexus",Group == "NOC",Auth-Type := pam DEFAULT Huntgroup-Name == "Nexus",Auth-Type := Reject DEFAULT Huntgroup-Name == "VDC",Group == "NetworkAdmins",Auth-Type := pam Service-Type = NAS-Prompt-User, cisco-avpair = 'shell:roles="vdc-admin"' DEFAULT Huntgroup-Name == "VDC",Group == "NOC",Auth-Type := pam DEFAULT Huntgroup-Name == "VDC",Auth-Type := Reject DEFAULT Huntgroup-Name == "SBC",Group == "SBCAdmins",Auth-Type := pam Service-Type = NAS-Prompt-User, cisco-avpair = "shell:priv-Alvl=15", GroupName = "Administrator" DEFAULT Huntgroup-Name == "SBC",Group == "NOC",Auth-Type := pam DEFAULT Huntgroup-Name == "SBC",Auth-Type := Reject DEFAULT Huntgroup-Name == "CON",Group == "NetworkAdmins",Auth-Type := pam Service-Type = NAS-Prompt-User, Filter-Id = "Raritan:G{Admin}" DEFAULT Huntgroup-Name == "CON",Group == "SBCAdmins",Auth-Type := pam Service-Type = NAS-Prompt-User, Filter-Id = "Raritan:G{Admin}" DEFAULT Huntgroup-Name == "CON",Group == "InformationSecurity",Auth-Type := pam Service-Type = NAS-Prompt-User, Filter-Id = "Raritan:G{Admin}" DEFAULT Huntgroup-Name == "CON",Group == "NOC",Auth-Type := pam Service-Type = NAS-Prompt-User, Filter-Id = "Raritan:G{Admin}" DEFAULT Huntgroup-Name == "CON",Auth-Type := Reject DEFAULT Huntgroup-Name == "CON-OG",Group == "NetworkAdmins",Auth-Type := pam Service-Type = NAS-Prompt-User, Filter-Id = ":group_name=admin:" DEFAULT Huntgroup-Name == "CON-OG",Group == "SBCAdmins",Auth-Type := pam Service-Type = NAS-Prompt-User, Filter-Id = ":group_name=admin:" DEFAULT Huntgroup-Name == "CON-OG",Group == "InformationSecurity",Auth-Type := pam Service-Type = NAS-Prompt-User, Filter-Id = ":group_name=admin:" DEFAULT Huntgroup-Name == "CON-OG",Group == "NOC",Auth-Type := pam Service-Type = NAS-Prompt-User, Filter-Id = ":group_name=admin:" DEFAULT Huntgroup-Name == "CON-OG",Auth-Type := Reject DEFAULT Auth-Type := pam radiusd -X log: FreeRADIUS Version 3.0.13 Copyright (C) 1999-2017 The FreeRADIUS server project and contributors There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE You may redistribute copies of FreeRADIUS under the terms of the GNU General Public License For more information about these matters, see the file named COPYRIGHT Starting - reading configuration files ... including dictionary file /usr/share/freeradius/dictionary including dictionary file /usr/share/freeradius/dictionary.dhcp including dictionary file /usr/share/freeradius/dictionary.vqp including dictionary file /etc/raddb/dictionary including configuration file /etc/raddb/radiusd.conf including configuration file /etc/raddb/proxy.conf including configuration file /etc/raddb/clients.conf including files in directory /etc/raddb/mods-enabled/ including configuration file /etc/raddb/mods-enabled/always including configuration file /etc/raddb/mods-enabled/attr_filter including configuration file /etc/raddb/mods-enabled/cache_eap including configuration file /etc/raddb/mods-enabled/chap including configuration file /etc/raddb/mods-enabled/date including configuration file /etc/raddb/mods-enabled/detail including configuration file /etc/raddb/mods-enabled/detail.log including configuration file /etc/raddb/mods-enabled/dhcp including configuration file /etc/raddb/mods-enabled/digest including configuration file /etc/raddb/mods-enabled/dynamic_clients including configuration file /etc/raddb/mods-enabled/eap including configuration file /etc/raddb/mods-enabled/echo including configuration file /etc/raddb/mods-enabled/exec including configuration file /etc/raddb/mods-enabled/expiration including configuration file /etc/raddb/mods-enabled/expr including configuration file /etc/raddb/mods-enabled/files including configuration file /etc/raddb/mods-enabled/linelog including configuration file /etc/raddb/mods-enabled/logintime including configuration file /etc/raddb/mods-enabled/mschap including configuration file /etc/raddb/mods-enabled/ntlm_auth including configuration file /etc/raddb/mods-enabled/pap including configuration file /etc/raddb/mods-enabled/passwd including configuration file /etc/raddb/mods-enabled/preprocess including configuration file /etc/raddb/mods-enabled/radutmp including configuration file /etc/raddb/mods-enabled/realm including configuration file /etc/raddb/mods-enabled/replicate including configuration file /etc/raddb/mods-enabled/soh including configuration file /etc/raddb/mods-enabled/sradutmp including configuration file /etc/raddb/mods-enabled/unix including configuration file /etc/raddb/mods-enabled/unpack including configuration file /etc/raddb/mods-enabled/utf8 including configuration file /etc/raddb/mods-enabled/pam including files in directory /etc/raddb/policy.d/ including configuration file /etc/raddb/policy.d/accounting including configuration file /etc/raddb/policy.d/canonicalization including configuration file /etc/raddb/policy.d/control including configuration file /etc/raddb/policy.d/cui including configuration file /etc/raddb/policy.d/debug including configuration file /etc/raddb/policy.d/dhcp including configuration file /etc/raddb/policy.d/eap including configuration file /etc/raddb/policy.d/operator-name including configuration file /etc/raddb/policy.d/filter including files in directory /etc/raddb/sites-enabled/ including configuration file /etc/raddb/sites-enabled/default including configuration file /etc/raddb/sites-enabled/inner-tunnel including configuration file /etc/raddb/sites-enabled/googleonly including configuration file /etc/raddb/sites-enabled/gen_net main { security { user = "radiusd" group = "radiusd" allow_core_dumps = no } name = "radiusd" prefix = "/usr" localstatedir = "/var" logdir = "/var/log/radius" run_dir = "/var/run/radiusd" } main { name = "radiusd" prefix = "/usr" localstatedir = "/var" sbindir = "/usr/sbin" logdir = "/var/log/radius" run_dir = "/var/run/radiusd" libdir = "/usr/lib64/freeradius" radacctdir = "/var/log/radius/radacct" hostname_lookups = no max_request_time = 30 cleanup_delay = 5 max_requests = 16384 pidfile = "/var/run/radiusd/radiusd.pid" checkrad = "/usr/sbin/checkrad" debug_level = 0 proxy_requests = yes log { stripped_names = no auth = no auth_badpass = no auth_goodpass = no colourise = yes msg_denied = "You are already logged in - access denied" } resources { } security { max_attributes = 200 reject_delay = 1.000000 status_server = yes } } radiusd: #### Loading Realms and Home Servers #### proxy server { retry_delay = 5 retry_count = 3 default_fallback = no dead_time = 120 wake_all_if_all_dead = no } home_server localhost { ipaddr = 127.0.0.1 port = 1812 type = "auth" secret = <<< secret >>> response_window = 20.000000 response_timeouts = 1 max_outstanding = 65536 zombie_period = 40 status_check = "status-server" ping_interval = 30 check_interval = 30 check_timeout = 4 num_answers_to_alive = 3 revive_interval = 120 limit { max_connections = 16 max_requests = 0 lifetime = 0 idle_timeout = 0 } coa { irt = 2 mrt = 16 mrc = 5 mrd = 30 } } home_server_pool my_auth_failover { type = fail-over home_server = localhost } realm example.com { auth_pool = my_auth_failover } realm LOCAL { } radiusd: #### Loading Clients #### ............................ client 10.56.36.33 { ipaddr = 10.56.36.33 require_message_authenticator = no secret = <<< secret >>> shortname = "hnd1-sonus-sbcvip" virtual_server = "gen_net" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client 10.56.36.38 { ipaddr = 10.56.36.38 require_message_authenticator = no secret = <<< secret >>> shortname = "hnd1-sonus-sbc02-2" virtual_server = "gen_net" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } ............................ Debugger not attached # Creating Auth-Type = pam # Creating Auth-Type = eap # Creating Auth-Type = mschap # Creating Auth-Type = PAP # Creating Auth-Type = CHAP # Creating Auth-Type = MS-CHAP radiusd: #### Instantiating modules #### modules { # Loaded module rlm_always # Loading module "reject" from file /etc/raddb/mods-enabled/always always reject { rcode = "reject" simulcount = 0 mpp = no } # Loading module "fail" from file /etc/raddb/mods-enabled/always always fail { rcode = "fail" simulcount = 0 mpp = no } # Loading module "ok" from file /etc/raddb/mods-enabled/always always ok { rcode = "ok" simulcount = 0 mpp = no } # Loading module "handled" from file /etc/raddb/mods-enabled/always always handled { rcode = "handled" simulcount = 0 mpp = no } # Loading module "invalid" from file /etc/raddb/mods-enabled/always always invalid { rcode = "invalid" simulcount = 0 mpp = no } # Loading module "userlock" from file /etc/raddb/mods-enabled/always always userlock { rcode = "userlock" simulcount = 0 mpp = no } # Loading module "notfound" from file /etc/raddb/mods-enabled/always always notfound { rcode = "notfound" simulcount = 0 mpp = no } # Loading module "noop" from file /etc/raddb/mods-enabled/always always noop { rcode = "noop" simulcount = 0 mpp = no } # Loading module "updated" from file /etc/raddb/mods-enabled/always always updated { rcode = "updated" simulcount = 0 mpp = no } # Loaded module rlm_attr_filter # Loading module "attr_filter.post-proxy" from file /etc/raddb/mods-enabled/attr_filter attr_filter attr_filter.post-proxy { filename = "/etc/raddb/mods-config/attr_filter/post-proxy" key = "%{Realm}" relaxed = no } # Loading module "attr_filter.pre-proxy" from file /etc/raddb/mods-enabled/attr_filter attr_filter attr_filter.pre-proxy { filename = "/etc/raddb/mods-config/attr_filter/pre-proxy" key = "%{Realm}" relaxed = no } # Loading module "attr_filter.access_reject" from file /etc/raddb/mods-enabled/attr_filter attr_filter attr_filter.access_reject { filename = "/etc/raddb/mods-config/attr_filter/access_reject" key = "%{User-Name}" relaxed = no } # Loading module "attr_filter.access_challenge" from file /etc/raddb/mods-enabled/attr_filter attr_filter attr_filter.access_challenge { filename = "/etc/raddb/mods-config/attr_filter/access_challenge" key = "%{User-Name}" relaxed = no } # Loading module "attr_filter.accounting_response" from file /etc/raddb/mods-enabled/attr_filter attr_filter attr_filter.accounting_response { filename = "/etc/raddb/mods-config/attr_filter/accounting_response" key = "%{User-Name}" relaxed = no } # Loaded module rlm_cache # Loading module "cache_eap" from file /etc/raddb/mods-enabled/cache_eap cache cache_eap { driver = "rlm_cache_rbtree" key = "%{%{control:State}:-%{%{reply:State}:-%{State}}}" ttl = 15 max_entries = 0 epoch = 0 add_stats = no } # Loaded module rlm_chap # Loading module "chap" from file /etc/raddb/mods-enabled/chap # Loaded module rlm_date # Loading module "date" from file /etc/raddb/mods-enabled/date date { format = "%b %e %Y %H:%M:%S %Z" } # Loaded module rlm_detail # Loading module "detail" from file /etc/raddb/mods-enabled/detail detail { filename = "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" header = "%t" permissions = 384 locking = no escape_filenames = no log_packet_header = no } # Loading module "auth_log" from file /etc/raddb/mods-enabled/detail.log detail auth_log { filename = "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d" header = "%t" permissions = 384 locking = no escape_filenames = no log_packet_header = no } # Loading module "reply_log" from file /etc/raddb/mods-enabled/detail.log detail reply_log { filename = "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d" header = "%t" permissions = 384 locking = no escape_filenames = no log_packet_header = no } # Loading module "pre_proxy_log" from file /etc/raddb/mods-enabled/detail.log detail pre_proxy_log { filename = "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d" header = "%t" permissions = 384 locking = no escape_filenames = no log_packet_header = no } # Loading module "post_proxy_log" from file /etc/raddb/mods-enabled/detail.log detail post_proxy_log { filename = "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d" header = "%t" permissions = 384 locking = no escape_filenames = no log_packet_header = no } # Loaded module rlm_dhcp # Loading module "dhcp" from file /etc/raddb/mods-enabled/dhcp # Loaded module rlm_digest # Loading module "digest" from file /etc/raddb/mods-enabled/digest # Loaded module rlm_dynamic_clients # Loading module "dynamic_clients" from file /etc/raddb/mods-enabled/dynamic_clients # Loaded module rlm_eap # Loading module "eap" from file /etc/raddb/mods-enabled/eap eap { default_eap_type = "md5" timer_expire = 60 ignore_unknown_eap_types = no cisco_accounting_username_bug = no max_sessions = 16384 } # Loaded module rlm_exec # Loading module "echo" from file /etc/raddb/mods-enabled/echo exec echo { wait = yes program = "/bin/echo %{User-Name}" input_pairs = "request" output_pairs = "reply" shell_escape = yes } # Loading module "exec" from file /etc/raddb/mods-enabled/exec exec { wait = no input_pairs = "request" shell_escape = yes timeout = 10 } # Loaded module rlm_expiration # Loading module "expiration" from file /etc/raddb/mods-enabled/expiration # Loaded module rlm_expr # Loading module "expr" from file /etc/raddb/mods-enabled/expr expr { safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ" } # Loaded module rlm_files # Loading module "files" from file /etc/raddb/mods-enabled/files files { filename = "/etc/raddb/users" acctusersfile = "/etc/raddb/mods-config/files/accounting" preproxy_usersfile = "/etc/raddb/mods-config/files/pre-proxy" } # Loaded module rlm_linelog # Loading module "linelog" from file /etc/raddb/mods-enabled/linelog linelog { filename = "/var/log/radius/linelog" escape_filenames = no syslog_severity = "info" permissions = 384 format = "This is a log message for %{User-Name}" reference = "messages.%{%{reply:Packet-Type}:-default}" } # Loading module "log_accounting" from file /etc/raddb/mods-enabled/linelog linelog log_accounting { filename = "/var/log/radius/linelog-accounting" escape_filenames = no syslog_severity = "info" permissions = 384 format = "" reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}" } # Loaded module rlm_logintime # Loading module "logintime" from file /etc/raddb/mods-enabled/logintime logintime { minimum_timeout = 60 } # Loaded module rlm_mschap # Loading module "mschap" from file /etc/raddb/mods-enabled/mschap mschap { use_mppe = yes require_encryption = no require_strong = no with_ntdomain_hack = yes passchange { } allow_retry = yes winbind_retry_with_normalised_username = no } # Loading module "ntlm_auth" from file /etc/raddb/mods-enabled/ntlm_auth exec ntlm_auth { wait = yes program = "/path/to/ntlm_auth --request-nt-key --domain=MYDOMAIN --username=%{mschap:User-Name} --password=%{User-Password}" shell_escape = yes } # Loaded module rlm_pap # Loading module "pap" from file /etc/raddb/mods-enabled/pap pap { normalise = yes } # Loaded module rlm_passwd # Loading module "etc_passwd" from file /etc/raddb/mods-enabled/passwd passwd etc_passwd { filename = "/etc/passwd" format = "*User-Name:Crypt-Password:" delimiter = ":" ignore_nislike = no ignore_empty = yes allow_multiple_keys = no hash_size = 100 } # Loaded module rlm_preprocess # Loading module "preprocess" from file /etc/raddb/mods-enabled/preprocess preprocess { huntgroups = "/etc/raddb/huntgroups" hints = "/etc/raddb/mods-config/preprocess/hints" with_ascend_hack = no ascend_channels_per_line = 23 with_ntdomain_hack = no with_specialix_jetstream_hack = no with_cisco_vsa_hack = no with_alvarion_vsa_hack = no } # Loaded module rlm_radutmp # Loading module "radutmp" from file /etc/raddb/mods-enabled/radutmp radutmp { filename = "/var/log/radius/radutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes permissions = 384 caller_id = yes } # Loaded module rlm_realm # Loading module "IPASS" from file /etc/raddb/mods-enabled/realm realm IPASS { format = "prefix" delimiter = "/" ignore_default = no ignore_null = no } # Loading module "suffix" from file /etc/raddb/mods-enabled/realm realm suffix { format = "suffix" delimiter = "@" ignore_default = no ignore_null = no } # Loading module "realmpercent" from file /etc/raddb/mods-enabled/realm realm realmpercent { format = "suffix" delimiter = "%" ignore_default = no ignore_null = no } # Loading module "ntdomain" from file /etc/raddb/mods-enabled/realm realm ntdomain { format = "prefix" delimiter = "\\" ignore_default = no ignore_null = no } # Loaded module rlm_replicate # Loading module "replicate" from file /etc/raddb/mods-enabled/replicate # Loaded module rlm_soh # Loading module "soh" from file /etc/raddb/mods-enabled/soh soh { dhcp = yes } # Loading module "sradutmp" from file /etc/raddb/mods-enabled/sradutmp radutmp sradutmp { filename = "/var/log/radius/sradutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes permissions = 420 caller_id = no } # Loaded module rlm_unix # Loading module "unix" from file /etc/raddb/mods-enabled/unix unix { radwtmp = "/var/log/radius/radwtmp" } Creating attribute Unix-Group # Loaded module rlm_unpack # Loading module "unpack" from file /etc/raddb/mods-enabled/unpack # Loaded module rlm_utf8 # Loading module "utf8" from file /etc/raddb/mods-enabled/utf8 # Loaded module rlm_pam # Loading module "pam" from file /etc/raddb/mods-enabled/pam pam { pam_auth = "radiusd" } instantiate { } } # Instantiating module "reject" from file /etc/raddb/mods-enabled/always # Instantiating module "fail" from file /etc/raddb/mods-enabled/always # Instantiating module "ok" from file /etc/raddb/mods-enabled/always # Instantiating module "handled" from file /etc/raddb/mods-enabled/always # Instantiating module "invalid" from file /etc/raddb/mods-enabled/always # Instantiating module "userlock" from file /etc/raddb/mods-enabled/always # Instantiating module "notfound" from file /etc/raddb/mods-enabled/always # Instantiating module "noop" from file /etc/raddb/mods-enabled/always # Instantiating module "updated" from file /etc/raddb/mods-enabled/always # Instantiating module "attr_filter.post-proxy" from file /etc/raddb/mods-enabled/attr_filter reading pairlist file /etc/raddb/mods-config/attr_filter/post-proxy # Instantiating module "attr_filter.pre-proxy" from file /etc/raddb/mods-enabled/attr_filter reading pairlist file /etc/raddb/mods-config/attr_filter/pre-proxy # Instantiating module "attr_filter.access_reject" from file /etc/raddb/mods-enabled/attr_filter reading pairlist file /etc/raddb/mods-config/attr_filter/access_reject [/etc/raddb/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay" found in filter list for realm "DEFAULT". [/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 /etc/raddb/mods-enabled/attr_filter reading pairlist file /etc/raddb/mods-config/attr_filter/access_challenge # Instantiating module "attr_filter.accounting_response" from file /etc/raddb/mods-enabled/attr_filter reading pairlist file /etc/raddb/mods-config/attr_filter/accounting_response # Instantiating module "cache_eap" from file /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 /etc/raddb/mods-enabled/detail # Instantiating module "auth_log" from file /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 /etc/raddb/mods-enabled/detail.log # Instantiating module "pre_proxy_log" from file /etc/raddb/mods-enabled/detail.log # Instantiating module "post_proxy_log" from file /etc/raddb/mods-enabled/detail.log # Instantiating module "eap" from file /etc/raddb/mods-enabled/eap # Linked to sub-module rlm_eap_md5 # Linked to sub-module rlm_eap_leap # Linked to sub-module rlm_eap_gtc gtc { challenge = "Password: " auth_type = "PAP" } # Linked to sub-module rlm_eap_tls tls { tls = "tls-common" } tls-config tls-common { verify_depth = 0 ca_path = "/etc/raddb/certs" pem_file_type = yes private_key_file = "/etc/raddb/certs/server.pem" certificate_file = "/etc/raddb/certs/server.pem" ca_file = "/etc/raddb/certs/ca.pem" private_key_password = <<< secret >>> dh_file = "/etc/raddb/certs/dh" 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 = yes 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 = "md5" copy_request_to_tunnel = no use_tunneled_reply = no virtual_server = "inner-tunnel" 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 = "mschapv2" copy_request_to_tunnel = no use_tunneled_reply = no proxy_tunneled_request_as_eap = yes virtual_server = "inner-tunnel" 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 "expiration" from file /etc/raddb/mods-enabled/expiration # Instantiating module "files" from file /etc/raddb/mods-enabled/files reading pairlist file /etc/raddb/users /etc/raddb/users[34]: Parse error (reply) for entry DEFAULT: Invalid vendor name in attribute name "GroupName" Failed reading /etc/raddb/users /etc/raddb/mods-enabled/files[9]: Instantiation failed for module "files"

2 4

Option to disable client certificate validation in freeradius server
by Kumaravel M 19 Aug '19

19 Aug '19

Hi, For quite some time, I am looking for an explicit option (configuration parameter) to disable client certificate validation in freeradius server. It's needed for my validation of my CPE WAN interface DHCP functionality post 802.1x authentication using EAP-TLS. Please suggest.

4 4

Freeradius 3.16 and mysql - duplicated entries in radpostauth
by Marcin Marszałkowski 19 Aug '19

19 Aug '19

Hi, I’m newbie to Freeradius and have been pulling my hair out… Installed Freeradius 3.16 with mysql and Daloradius. Autheticating and authorizing work (I think so). But I might have something misconfigured - radpostauth table is full of duplicated/always double entries with the same timestamp. And it happens only for EAP auth., PAP (radtest) and MD5 (MAC based auth.) are not affected. Does it may affect accounting? Following is request debug where double input to radpostauth is visible: ———————————————— Sat Aug 17 18:23:36 2019 : Debug: (10) Received Access-Request Id 248 from 172.16.0.5:48453 to 172.16.0.12:1812 length 242 Sat Aug 17 18:23:36 2019 : Debug: (10) User-Name = "Robert" Sat Aug 17 18:23:36 2019 : Debug: (10) NAS-Identifier = "feec3a9aeda5" Sat Aug 17 18:23:36 2019 : Debug: (10) Called-Station-Id = "FE-EC-3A-9A-ED-A5:Guest" Sat Aug 17 18:23:36 2019 : Debug: (10) NAS-Port-Type = Wireless-802.11 Sat Aug 17 18:23:36 2019 : Debug: (10) Service-Type = Framed-User Sat Aug 17 18:23:36 2019 : Debug: (10) Calling-Station-Id = "04-DB-56-F0-C3-36" Sat Aug 17 18:23:36 2019 : Debug: (10) Connect-Info = "CONNECT 0Mbps 802.11b" Sat Aug 17 18:23:36 2019 : Debug: (10) Acct-Session-Id = "D9B312EA0EEDF1F6" Sat Aug 17 18:23:36 2019 : Debug: (10) Mobility-Domain-Id = 1826 Sat Aug 17 18:23:36 2019 : Debug: (10) WLAN-Pairwise-Cipher = 1027076 Sat Aug 17 18:23:36 2019 : Debug: (10) WLAN-Group-Cipher = 1027076 Sat Aug 17 18:23:36 2019 : Debug: (10) WLAN-AKM-Suite = 1027075 Sat Aug 17 18:23:36 2019 : Debug: (10) Framed-MTU = 1400 Sat Aug 17 18:23:36 2019 : Debug: (10) EAP-Message = 0x021b00251900170303001a7ee7eda10323b3262a8342edbba1f2cff9ae93b8127cc51c3b47 Sat Aug 17 18:23:36 2019 : Debug: (10) State = 0x7d7976aa75626f6ce06082b82288935b Sat Aug 17 18:23:36 2019 : Debug: (10) Message-Authenticator = 0xdcedbfc0f49a2c315fa3a073561ea26c Sat Aug 17 18:23:36 2019 : Debug: (10) session-state: No cached attributes Sat Aug 17 18:23:36 2019 : Debug: (10) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default Sat Aug 17 18:23:36 2019 : Debug: (10) authorize { Sat Aug 17 18:23:36 2019 : Debug: (10) policy filter_username { Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name) { Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name) -> TRUE Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name) { Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ / /) { Sat Aug 17 18:23:36 2019 : Debug: No matches Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ / /) -> FALSE Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /@[^@]*@/ ) { Sat Aug 17 18:23:36 2019 : Debug: No matches Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /@[^@]*@/ ) -> FALSE Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /\.\./ ) { Sat Aug 17 18:23:36 2019 : Debug: No matches Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /\.\./ ) -> FALSE Sat Aug 17 18:23:36 2019 : Debug: (10) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { Sat Aug 17 18:23:36 2019 : Debug: No matches Sat Aug 17 18:23:36 2019 : Debug: (10) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /\.$/) { Sat Aug 17 18:23:36 2019 : Debug: No matches Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /\.$/) -> FALSE Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /(a)\./) { Sat Aug 17 18:23:36 2019 : Debug: No matches Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /(a)\./) -> FALSE Sat Aug 17 18:23:36 2019 : Debug: (10) } # if (&User-Name) = notfound Sat Aug 17 18:23:36 2019 : Debug: (10) } # policy filter_username = notfound Sat Aug 17 18:23:36 2019 : Debug: (10) policy filter_password { Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Password && (&User-Password != "%{string:User-Password}")) { Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Password && (&User-Password != "%{string:User-Password}")) -> FALSE Sat Aug 17 18:23:36 2019 : Debug: (10) } # policy filter_password = notfound Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling preprocess (rlm_preprocess) Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from preprocess (rlm_preprocess) Sat Aug 17 18:23:36 2019 : Debug: (10) [preprocess] = ok Sat Aug 17 18:23:36 2019 : Debug: (10) update request { Sat Aug 17 18:23:36 2019 : Debug: %{User-Name} Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree: Sat Aug 17 18:23:36 2019 : Debug: attribute --> User-Name Sat Aug 17 18:23:36 2019 : Debug: (10) EXPAND %{User-Name} Sat Aug 17 18:23:36 2019 : Debug: (10) --> Robert Sat Aug 17 18:23:36 2019 : Debug: (10) SQL-User-Name set to 'Robert' Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Reserved connection (6) Sat Aug 17 18:23:36 2019 : Debug: (10) Executing select query: select groupname from radhuntgroup where nasipaddress="172.16.0.5" Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Released connection (6) Sat Aug 17 18:23:36 2019 : Debug: (10) EXPAND %{sql:select groupname from radhuntgroup where nasipaddress="%{NAS-IP-Address}"} Sat Aug 17 18:23:36 2019 : Debug: (10) --> WiFi Sat Aug 17 18:23:36 2019 : Debug: (10) Huntgroup-Name := WiFi Sat Aug 17 18:23:36 2019 : Debug: (10) } # update request = noop Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling mschap (rlm_mschap) Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from mschap (rlm_mschap) Sat Aug 17 18:23:36 2019 : Debug: (10) [mschap] = noop Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling suffix (rlm_realm) Sat Aug 17 18:23:36 2019 : Debug: (10) suffix: Checking for suffix after "@" Sat Aug 17 18:23:36 2019 : Debug: (10) suffix: No '@' in User-Name = "Robert", looking up realm NULL Sat Aug 17 18:23:36 2019 : Debug: (10) suffix: No such realm "NULL" Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from suffix (rlm_realm) Sat Aug 17 18:23:36 2019 : Debug: (10) [suffix] = noop Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling eap (rlm_eap) Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Peer sent EAP Response (code 2) ID 27 length 37 Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Continuing tunnel setup Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from eap (rlm_eap) Sat Aug 17 18:23:36 2019 : Debug: (10) [eap] = ok Sat Aug 17 18:23:36 2019 : Debug: (10) } # authorize = ok Sat Aug 17 18:23:36 2019 : Debug: (10) Found Auth-Type = eap Sat Aug 17 18:23:36 2019 : Debug: (10) # Executing group from file /etc/freeradius/3.0/sites-enabled/default Sat Aug 17 18:23:36 2019 : Debug: (10) authenticate { Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authenticate]: calling eap (rlm_eap) Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Expiring EAP session with state 0xba6ef1b9bb75eb14 Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Finished EAP session with state 0x7d7976aa75626f6c Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Previous EAP request found for state 0x7d7976aa75626f6c, released from the list Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Peer sent packet with method EAP PEAP (25) Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Calling submodule eap_peap to process data Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Continuing EAP-TLS Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Peer sent flags --- Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: [eaptls verify] = ok Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Done initial handshake Sat Aug 17 18:23:36 2019 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0 Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: [eaptls process] = ok Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Session established. Decoding tunneled attributes Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: PEAP state phase2 Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: EAP method MSCHAPv2 (26) Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Got tunneled request Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: EAP-Message = 0x021b00061a03 Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Setting User-Name to Robert Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Sending tunneled request to inner-tunnel Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: EAP-Message = 0x021b00061a03 Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: FreeRADIUS-Proxied-To = 127.0.0.1 Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: User-Name = "Robert" Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: State = 0xba6ef1b9bb75eb14f919ef4d049db6e4 Sat Aug 17 18:23:36 2019 : Debug: (10) Virtual server inner-tunnel received request Sat Aug 17 18:23:36 2019 : Debug: (10) EAP-Message = 0x021b00061a03 Sat Aug 17 18:23:36 2019 : Debug: (10) FreeRADIUS-Proxied-To = 127.0.0.1 Sat Aug 17 18:23:36 2019 : Debug: (10) User-Name = "Robert" Sat Aug 17 18:23:36 2019 : Debug: (10) State = 0xba6ef1b9bb75eb14f919ef4d049db6e4 Sat Aug 17 18:23:36 2019 : WARNING: (10) Outer and inner identities are the same. User privacy is compromised. Sat Aug 17 18:23:36 2019 : Debug: (10) server inner-tunnel { Sat Aug 17 18:23:36 2019 : Debug: (10) session-state: No cached attributes Sat Aug 17 18:23:36 2019 : Debug: (10) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/inner-tunnel Sat Aug 17 18:23:36 2019 : Debug: (10) authorize { Sat Aug 17 18:23:36 2019 : Debug: (10) policy filter_username { Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name) { Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name) -> TRUE Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name) { Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ / /) { Sat Aug 17 18:23:36 2019 : Debug: No matches Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ / /) -> FALSE Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /@[^@]*@/ ) { Sat Aug 17 18:23:36 2019 : Debug: No matches Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /@[^@]*@/ ) -> FALSE Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /\.\./ ) { Sat Aug 17 18:23:36 2019 : Debug: No matches Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /\.\./ ) -> FALSE Sat Aug 17 18:23:36 2019 : Debug: (10) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { Sat Aug 17 18:23:36 2019 : Debug: No matches Sat Aug 17 18:23:36 2019 : Debug: (10) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /\.$/) { Sat Aug 17 18:23:36 2019 : Debug: No matches Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /\.$/) -> FALSE Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /(a)\./) { Sat Aug 17 18:23:36 2019 : Debug: No matches Sat Aug 17 18:23:36 2019 : Debug: (10) if (&User-Name =~ /(a)\./) -> FALSE Sat Aug 17 18:23:36 2019 : Debug: (10) } # if (&User-Name) = notfound Sat Aug 17 18:23:36 2019 : Debug: (10) } # policy filter_username = notfound Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling mschap (rlm_mschap) Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from mschap (rlm_mschap) Sat Aug 17 18:23:36 2019 : Debug: (10) [mschap] = noop Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling suffix (rlm_realm) Sat Aug 17 18:23:36 2019 : Debug: (10) suffix: Checking for suffix after "@" Sat Aug 17 18:23:36 2019 : Debug: (10) suffix: No '@' in User-Name = "Robert", looking up realm NULL Sat Aug 17 18:23:36 2019 : Debug: (10) suffix: No such realm "NULL" Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from suffix (rlm_realm) Sat Aug 17 18:23:36 2019 : Debug: (10) [suffix] = noop Sat Aug 17 18:23:36 2019 : Debug: (10) update control { Sat Aug 17 18:23:36 2019 : Debug: (10) &Proxy-To-Realm := LOCAL Sat Aug 17 18:23:36 2019 : Debug: (10) } # update control = noop Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling eap (rlm_eap) Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Peer sent EAP Response (code 2) ID 27 length 6 Sat Aug 17 18:23:36 2019 : Debug: (10) eap: No EAP Start, assuming it's an on-going EAP conversation Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from eap (rlm_eap) Sat Aug 17 18:23:36 2019 : Debug: (10) [eap] = updated Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling sql (rlm_sql) Sat Aug 17 18:23:36 2019 : Debug: %{User-Name} Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree: Sat Aug 17 18:23:36 2019 : Debug: attribute --> User-Name Sat Aug 17 18:23:36 2019 : Debug: (10) sql: EXPAND %{User-Name} Sat Aug 17 18:23:36 2019 : Debug: (10) sql: --> Robert Sat Aug 17 18:23:36 2019 : Debug: (10) sql: SQL-User-Name set to 'Robert' Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Reserved connection (8) Sat Aug 17 18:23:36 2019 : Debug: SELECT id, username, attribute, value, op FROM radcheck WHERE username = BINARY '%{SQL-User-Name}' ORDER BY id Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree: Sat Aug 17 18:23:36 2019 : Debug: literal --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = BINARY ' Sat Aug 17 18:23:36 2019 : Debug: attribute --> SQL-User-Name Sat Aug 17 18:23:36 2019 : Debug: literal --> ' ORDER BY id Sat Aug 17 18:23:36 2019 : Debug: (10) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = BINARY '%{SQL-User-Name}' ORDER BY id Sat Aug 17 18:23:36 2019 : Debug: (10) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = BINARY 'Robert' ORDER BY id Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = BINARY 'Robert' ORDER BY id Sat Aug 17 18:23:36 2019 : Debug: (10) sql: User found in radcheck table Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Conditional check items matched, merging assignment check items Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Cleartext-Password := "Atina2011!" Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: FROM 1 TO 2 MAX 3 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Cleartext-Password Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Cleartext-Password FROM 0 TO 2 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: TO in 2 out 2 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: to[0] = Proxy-To-Realm Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: to[1] = Auth-Type Sat Aug 17 18:23:36 2019 : Debug: SELECT id, username, attribute, value, op FROM radreply WHERE username = BINARY '%{SQL-User-Name}' ORDER BY id Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree: Sat Aug 17 18:23:36 2019 : Debug: literal --> SELECT id, username, attribute, value, op FROM radreply WHERE username = BINARY ' Sat Aug 17 18:23:36 2019 : Debug: attribute --> SQL-User-Name Sat Aug 17 18:23:36 2019 : Debug: literal --> ' ORDER BY id Sat Aug 17 18:23:36 2019 : Debug: (10) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = BINARY '%{SQL-User-Name}' ORDER BY id Sat Aug 17 18:23:36 2019 : Debug: (10) sql: --> SELECT id, username, attribute, value, op FROM radreply WHERE username = BINARY 'Robert' ORDER BY id Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Executing select query: SELECT id, username, attribute, value, op FROM radreply WHERE username = BINARY 'Robert' ORDER BY id Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ... falling-through to group processing Sat Aug 17 18:23:36 2019 : Debug: SELECT groupname FROM radusergroup WHERE username = BINARY '%{SQL-User-Name}' ORDER BY priority Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree: Sat Aug 17 18:23:36 2019 : Debug: literal --> SELECT groupname FROM radusergroup WHERE username = BINARY ' Sat Aug 17 18:23:36 2019 : Debug: attribute --> SQL-User-Name Sat Aug 17 18:23:36 2019 : Debug: literal --> ' ORDER BY priority Sat Aug 17 18:23:36 2019 : Debug: (10) sql: EXPAND SELECT groupname FROM radusergroup WHERE username = BINARY '%{SQL-User-Name}' ORDER BY priority Sat Aug 17 18:23:36 2019 : Debug: (10) sql: --> SELECT groupname FROM radusergroup WHERE username = BINARY 'Robert' ORDER BY priority Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Executing select query: SELECT groupname FROM radusergroup WHERE username = BINARY 'Robert' ORDER BY priority Sat Aug 17 18:23:36 2019 : Debug: (10) sql: User found in the group table Sat Aug 17 18:23:36 2019 : Debug: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree: Sat Aug 17 18:23:36 2019 : Debug: literal --> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = ' Sat Aug 17 18:23:36 2019 : Debug: attribute --> SQL-Group Sat Aug 17 18:23:36 2019 : Debug: literal --> ' ORDER BY id Sat Aug 17 18:23:36 2019 : Debug: (10) sql: EXPAND SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id Sat Aug 17 18:23:36 2019 : Debug: (10) sql: --> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'Dzieci' ORDER BY id Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Executing select query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'Dzieci' ORDER BY id Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Group "Dzieci": Conditional check items matched Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Group "Dzieci": Merging assignment check items Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Simultaneous-Use := 2 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Max-Daily-Session := 10800 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Login-Time := "Wk1200-2330,Sa0800-2330,Su0800-2300" Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: FROM 3 TO 3 MAX 6 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Simultaneous-Use Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Simultaneous-Use FROM 0 TO 3 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Max-Daily-Session Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Max-Daily-Session FROM 1 TO 3 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Login-Time Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Login-Time FROM 2 TO 3 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: TO in 3 out 3 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: to[0] = Proxy-To-Realm Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: to[1] = Auth-Type Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: to[2] = Cleartext-Password Sat Aug 17 18:23:36 2019 : Debug: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree: Sat Aug 17 18:23:36 2019 : Debug: literal --> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = ' Sat Aug 17 18:23:36 2019 : Debug: attribute --> SQL-Group Sat Aug 17 18:23:36 2019 : Debug: literal --> ' ORDER BY id Sat Aug 17 18:23:36 2019 : Debug: (10) sql: EXPAND SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id Sat Aug 17 18:23:36 2019 : Debug: (10) sql: --> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'Dzieci' ORDER BY id Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Executing select query: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'Dzieci' ORDER BY id Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Group "Dzieci": Merging reply items Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Tunnel-Private-Group-Id := "11" Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Tunnel-Type := VLAN Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Tunnel-Medium-Type := IEEE-802 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Fall-Through = Yes Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Session-Timeout := 3600 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Acct-Interim-Interval := 300 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Idle-Timeout := 450 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Termination-Action := RADIUS-Request Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: FROM 8 TO 0 MAX 8 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Tunnel-Private-Group-Id Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Tunnel-Private-Group-Id FROM 0 TO 0 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Tunnel-Type Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Tunnel-Type FROM 1 TO 0 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Tunnel-Medium-Type Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Tunnel-Medium-Type FROM 2 TO 0 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Fall-Through Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Fall-Through FROM 3 TO 0 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Session-Timeout Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Session-Timeout FROM 4 TO 0 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Acct-Interim-Interval Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Acct-Interim-Interval FROM 5 TO 0 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Idle-Timeout Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Idle-Timeout FROM 6 TO 0 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: Examining Termination-Action Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: APPENDING Termination-Action FROM 7 TO 0 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ::: TO in 0 out 0 Sat Aug 17 18:23:36 2019 : Debug: (10) sql: ... falling-through to profile processing Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Released connection (8) Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from sql (rlm_sql) Sat Aug 17 18:23:36 2019 : Debug: (10) [sql] = ok Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling dailycounter (rlm_sqlcounter) Sat Aug 17 18:23:36 2019 : Debug: sqlcounter_expand: 'SELECT SUM(acctsessiontime) FROM radacct WHERE username = '%{User-Name}' AND acctstarttime BETWEEN FROM_UNIXTIME('1565992800') AND FROM_UNIXTIME('1566079200')' Sat Aug 17 18:23:36 2019 : Debug: %{sql:SELECT SUM(acctsessiontime) FROM radacct WHERE username = '%{User-Name}' AND acctstarttime BETWEEN FROM_UNIXTIME('1565992800') AND FROM_UNIXTIME('1566079200')} Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree: Sat Aug 17 18:23:36 2019 : Debug: xlat --> sql Sat Aug 17 18:23:36 2019 : Debug: { Sat Aug 17 18:23:36 2019 : Debug: literal --> SELECT SUM(acctsessiontime) FROM radacct WHERE username = ' Sat Aug 17 18:23:36 2019 : Debug: attribute --> User-Name Sat Aug 17 18:23:36 2019 : Debug: literal --> ' AND acctstarttime BETWEEN FROM_UNIXTIME('1565992800') AND FROM_UNIXTIME('1566079200') Sat Aug 17 18:23:36 2019 : Debug: } Sat Aug 17 18:23:36 2019 : Debug: %{User-Name} Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree: Sat Aug 17 18:23:36 2019 : Debug: attribute --> User-Name Sat Aug 17 18:23:36 2019 : Debug: (10) dailycounter: EXPAND %{User-Name} Sat Aug 17 18:23:36 2019 : Debug: (10) dailycounter: --> Robert Sat Aug 17 18:23:36 2019 : Debug: (10) dailycounter: SQL-User-Name set to 'Robert' Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Reserved connection (7) Sat Aug 17 18:23:36 2019 : Debug: (10) dailycounter: Executing select query: SELECT SUM(acctsessiontime) FROM radacct WHERE username = 'Robert' AND acctstarttime BETWEEN FROM_UNIXTIME('1565992800') AND FROM_UNIXTIME('1566079200') Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Released connection (7) Sat Aug 17 18:23:36 2019 : Debug: (10) dailycounter: EXPAND %{sql:SELECT SUM(acctsessiontime) FROM radacct WHERE username = '%{User-Name}' AND acctstarttime BETWEEN FROM_UNIXTIME('1565992800') AND FROM_UNIXTIME('1566079200')} Sat Aug 17 18:23:36 2019 : Debug: (10) dailycounter: --> 9927 Sat Aug 17 18:23:36 2019 : Debug: (10) dailycounter: Allowing user, &control:Max-Daily-Session value (10800) is greater than counter value (9927) Sat Aug 17 18:23:36 2019 : Debug: (10) dailycounter: Setting &reply:Session-Timeout value to 873 Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from dailycounter (rlm_sqlcounter) Sat Aug 17 18:23:36 2019 : Debug: (10) [dailycounter] = ok Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling expiration (rlm_expiration) Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from expiration (rlm_expiration) Sat Aug 17 18:23:36 2019 : Debug: (10) [expiration] = noop Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling logintime (rlm_logintime) Sat Aug 17 18:23:36 2019 : Debug: (10) logintime: Checking Login-Time Sat Aug 17 18:23:36 2019 : Debug: (10) logintime: Login within allowed time-slot, 18480 seconds left in this session Sat Aug 17 18:23:36 2019 : Debug: (10) logintime: reply:Session-Timeout set to 18480 Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from logintime (rlm_logintime) Sat Aug 17 18:23:36 2019 : Debug: (10) [logintime] = updated Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: calling pap (rlm_pap) Sat Aug 17 18:23:36 2019 : WARNING: (10) pap: Auth-Type already set. Not setting to PAP Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authorize]: returned from pap (rlm_pap) Sat Aug 17 18:23:36 2019 : Debug: (10) [pap] = noop Sat Aug 17 18:23:36 2019 : Debug: (10) } # authorize = updated Sat Aug 17 18:23:36 2019 : Debug: (10) Found Auth-Type = eap Sat Aug 17 18:23:36 2019 : Debug: (10) # Executing group from file /etc/freeradius/3.0/sites-enabled/inner-tunnel Sat Aug 17 18:23:36 2019 : Debug: (10) authenticate { Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authenticate]: calling eap (rlm_eap) Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Expiring EAP session with state 0xba6ef1b9bb75eb14 Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Finished EAP session with state 0xba6ef1b9bb75eb14 Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Previous EAP request found for state 0xba6ef1b9bb75eb14, released from the list Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Peer sent packet with method EAP MSCHAPv2 (26) Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Calling submodule eap_mschapv2 to process data Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Sending EAP Success (code 3) ID 27 length 4 Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Freeing handler Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authenticate]: returned from eap (rlm_eap) Sat Aug 17 18:23:36 2019 : Debug: (10) [eap] = ok Sat Aug 17 18:23:36 2019 : Debug: (10) } # authenticate = ok Sat Aug 17 18:23:36 2019 : Debug: (10) # Executing section session from file /etc/freeradius/3.0/sites-enabled/inner-tunnel Sat Aug 17 18:23:36 2019 : Debug: (10) session { Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[session]: calling sql (rlm_sql) Sat Aug 17 18:23:36 2019 : Debug: %{User-Name} Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree: Sat Aug 17 18:23:36 2019 : Debug: attribute --> User-Name Sat Aug 17 18:23:36 2019 : Debug: (10) sql: EXPAND %{User-Name} Sat Aug 17 18:23:36 2019 : Debug: (10) sql: --> Robert Sat Aug 17 18:23:36 2019 : Debug: (10) sql: SQL-User-Name set to 'Robert' Sat Aug 17 18:23:36 2019 : Debug: SELECT COUNT(*) FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree: Sat Aug 17 18:23:36 2019 : Debug: literal --> SELECT COUNT(*) FROM radacct WHERE username = ' Sat Aug 17 18:23:36 2019 : Debug: attribute --> SQL-User-Name Sat Aug 17 18:23:36 2019 : Debug: literal --> ' AND acctstoptime IS NULL Sat Aug 17 18:23:36 2019 : Debug: (10) sql: EXPAND SELECT COUNT(*) FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL Sat Aug 17 18:23:36 2019 : Debug: (10) sql: --> SELECT COUNT(*) FROM radacct WHERE username = 'Robert' AND acctstoptime IS NULL Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Reserved connection (6) Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Executing select query: SELECT COUNT(*) FROM radacct WHERE username = 'Robert' AND acctstoptime IS NULL Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Released connection (6) Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[session]: returned from sql (rlm_sql) Sat Aug 17 18:23:36 2019 : Debug: (10) [sql] = ok Sat Aug 17 18:23:36 2019 : Debug: (10) } # session = ok Sat Aug 17 18:23:36 2019 : Debug: (10) # Executing section post-auth from file /etc/freeradius/3.0/sites-enabled/inner-tunnel Sat Aug 17 18:23:36 2019 : Debug: (10) post-auth { Sat Aug 17 18:23:36 2019 : Debug: (10) update reply { Sat Aug 17 18:23:36 2019 : Debug: (10) User-Name := &request:User-Name -> 'Robert' Sat Aug 17 18:23:36 2019 : Debug: (10) Overwriting value "Robert" with "Robert" Sat Aug 17 18:23:36 2019 : Debug: (10) } # update reply = noop Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[post-auth]: calling sql (rlm_sql) Sat Aug 17 18:23:36 2019 : Debug: .query Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree: Sat Aug 17 18:23:36 2019 : Debug: literal --> .query Sat Aug 17 18:23:36 2019 : Debug: (10) sql: EXPAND .query Sat Aug 17 18:23:36 2019 : Debug: (10) sql: --> .query Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Using query template 'query' Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Reserved connection (8) Sat Aug 17 18:23:36 2019 : Debug: %{User-Name} Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree: Sat Aug 17 18:23:36 2019 : Debug: attribute --> User-Name Sat Aug 17 18:23:36 2019 : Debug: (10) sql: EXPAND %{User-Name} Sat Aug 17 18:23:36 2019 : Debug: (10) sql: --> Robert Sat Aug 17 18:23:36 2019 : Debug: (10) sql: SQL-User-Name set to 'Robert' Sat Aug 17 18:23:36 2019 : Debug: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree: Sat Aug 17 18:23:36 2019 : Debug: literal --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( ' Sat Aug 17 18:23:36 2019 : Debug: attribute --> SQL-User-Name Sat Aug 17 18:23:36 2019 : Debug: literal --> ', ' Sat Aug 17 18:23:36 2019 : Debug: XLAT-IF { Sat Aug 17 18:23:36 2019 : Debug: attribute --> User-Password Sat Aug 17 18:23:36 2019 : Debug: } Sat Aug 17 18:23:36 2019 : Debug: XLAT-ELSE { Sat Aug 17 18:23:36 2019 : Debug: attribute --> CHAP-Password Sat Aug 17 18:23:36 2019 : Debug: } Sat Aug 17 18:23:36 2019 : Debug: literal --> ', ' Sat Aug 17 18:23:36 2019 : Debug: attribute --> Packet-Type Sat Aug 17 18:23:36 2019 : Debug: literal --> ', ' Sat Aug 17 18:23:36 2019 : Debug: percent --> S Sat Aug 17 18:23:36 2019 : Debug: literal --> ') Sat Aug 17 18:23:36 2019 : Debug: (10) sql: EXPAND INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') Sat Aug 17 18:23:36 2019 : Debug: (10) sql: --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'Robert', '', 'Access-Accept', '2019-08-17 18:23:36') Sat Aug 17 18:23:36 2019 : Debug: (10) sql: Executing query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'Robert', '', 'Access-Accept', '2019-08-17 18:23:36') Sat Aug 17 18:23:36 2019 : Debug: (10) sql: SQL query returned: success Sat Aug 17 18:23:36 2019 : Debug: (10) sql: 1 record(s) updated Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Released connection (8) Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[post-auth]: returned from sql (rlm_sql) Sat Aug 17 18:23:36 2019 : Debug: (10) [sql] = ok Sat Aug 17 18:23:36 2019 : Debug: (10) if (1) { Sat Aug 17 18:23:36 2019 : Debug: (10) if (1) -> TRUE Sat Aug 17 18:23:36 2019 : Debug: (10) if (1) { Sat Aug 17 18:23:36 2019 : Debug: (10) update reply { Sat Aug 17 18:23:36 2019 : Debug: (10) Message-Authenticator !* ANY Sat Aug 17 18:23:36 2019 : Debug: (10) EAP-Message !* ANY Sat Aug 17 18:23:36 2019 : Debug: (10) Proxy-State !* ANY Sat Aug 17 18:23:36 2019 : Debug: (10) MS-MPPE-Encryption-Types !* ANY Sat Aug 17 18:23:36 2019 : Debug: (10) MS-MPPE-Encryption-Policy !* ANY Sat Aug 17 18:23:36 2019 : Debug: (10) MS-MPPE-Send-Key !* ANY Sat Aug 17 18:23:36 2019 : Debug: (10) MS-MPPE-Recv-Key !* ANY Sat Aug 17 18:23:36 2019 : Debug: (10) } # update reply = noop Sat Aug 17 18:23:36 2019 : Debug: (10) update { Sat Aug 17 18:23:36 2019 : Debug: (10) &outer.session-state::Tunnel-Private-Group-Id += &reply:Tunnel-Private-Group-Id[*] -> '11' Sat Aug 17 18:23:36 2019 : Debug: (10) &outer.session-state::Tunnel-Type += &reply:Tunnel-Type[*] -> VLAN Sat Aug 17 18:23:36 2019 : Debug: (10) &outer.session-state::Tunnel-Medium-Type += &reply:Tunnel-Medium-Type[*] -> IEEE-802 Sat Aug 17 18:23:36 2019 : Debug: (10) &outer.session-state::Fall-Through += &reply:Fall-Through[*] -> Yes Sat Aug 17 18:23:36 2019 : Debug: (10) &outer.session-state::Session-Timeout += &reply:Session-Timeout[*] -> 873 Sat Aug 17 18:23:36 2019 : Debug: (10) &outer.session-state::Acct-Interim-Interval += &reply:Acct-Interim-Interval[*] -> 300 Sat Aug 17 18:23:36 2019 : Debug: (10) &outer.session-state::Idle-Timeout += &reply:Idle-Timeout[*] -> 450 Sat Aug 17 18:23:36 2019 : Debug: (10) &outer.session-state::Termination-Action += &reply:Termination-Action[*] -> RADIUS-Request Sat Aug 17 18:23:36 2019 : Debug: (10) &outer.session-state::User-Name += &reply:User-Name[*] -> 'Robert' Sat Aug 17 18:23:36 2019 : Debug: (10) } # update = noop Sat Aug 17 18:23:36 2019 : Debug: (10) } # if (1) = noop Sat Aug 17 18:23:36 2019 : Debug: (10) } # post-auth = ok Sat Aug 17 18:23:36 2019 : Debug: (10) } # server inner-tunnel Sat Aug 17 18:23:36 2019 : Debug: (10) Virtual server sending reply Sat Aug 17 18:23:36 2019 : Debug: (10) Tunnel-Private-Group-Id = "11" Sat Aug 17 18:23:36 2019 : Debug: (10) Tunnel-Type = VLAN Sat Aug 17 18:23:36 2019 : Debug: (10) Tunnel-Medium-Type = IEEE-802 Sat Aug 17 18:23:36 2019 : Debug: (10) Fall-Through = Yes Sat Aug 17 18:23:36 2019 : Debug: (10) Session-Timeout = 873 Sat Aug 17 18:23:36 2019 : Debug: (10) Acct-Interim-Interval = 300 Sat Aug 17 18:23:36 2019 : Debug: (10) Idle-Timeout = 450 Sat Aug 17 18:23:36 2019 : Debug: (10) Termination-Action = RADIUS-Request Sat Aug 17 18:23:36 2019 : Debug: (10) User-Name := "Robert" Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Got tunneled reply code 2 Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Tunnel-Private-Group-Id = "11" Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Tunnel-Type = VLAN Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Tunnel-Medium-Type = IEEE-802 Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Fall-Through = Yes Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Session-Timeout = 873 Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Acct-Interim-Interval = 300 Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Idle-Timeout = 450 Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Termination-Action = RADIUS-Request Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: User-Name := "Robert" Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Got tunneled reply RADIUS code 2 Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Tunnel-Private-Group-Id = "11" Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Tunnel-Type = VLAN Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Tunnel-Medium-Type = IEEE-802 Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Fall-Through = Yes Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Session-Timeout = 873 Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Acct-Interim-Interval = 300 Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Idle-Timeout = 450 Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Termination-Action = RADIUS-Request Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: User-Name := "Robert" Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Tunneled authentication was successful Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: SUCCESS Sat Aug 17 18:23:36 2019 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0 Sat Aug 17 18:23:36 2019 : Debug: (10) eap_peap: Saving tunneled attributes for later Sat Aug 17 18:23:36 2019 : Debug: (10) eap: Sending EAP Request (code 1) ID 28 length 46 Sat Aug 17 18:23:36 2019 : Debug: (10) eap: EAP session adding &reply:State = 0x7d7976aa74656f6c Sat Aug 17 18:23:36 2019 : Debug: (10) modsingle[authenticate]: returned from eap (rlm_eap) Sat Aug 17 18:23:36 2019 : Debug: (10) [eap] = handled Sat Aug 17 18:23:36 2019 : Debug: (10) } # authenticate = handled Sat Aug 17 18:23:36 2019 : Debug: (10) Using Post-Auth-Type Challenge Sat Aug 17 18:23:36 2019 : Debug: (10) Post-Auth-Type sub-section not found. Ignoring. Sat Aug 17 18:23:36 2019 : Debug: (10) # Executing group from file /etc/freeradius/3.0/sites-enabled/default Sat Aug 17 18:23:36 2019 : Debug: (10) session-state: Saving cached attributes Sat Aug 17 18:23:36 2019 : Debug: (10) Tunnel-Private-Group-Id += "11" Sat Aug 17 18:23:36 2019 : Debug: (10) Tunnel-Type += VLAN Sat Aug 17 18:23:36 2019 : Debug: (10) Tunnel-Medium-Type += IEEE-802 Sat Aug 17 18:23:36 2019 : Debug: (10) Session-Timeout += 873 Sat Aug 17 18:23:36 2019 : Debug: (10) Acct-Interim-Interval += 300 Sat Aug 17 18:23:36 2019 : Debug: (10) Idle-Timeout += 450 Sat Aug 17 18:23:36 2019 : Debug: (10) Termination-Action += RADIUS-Request Sat Aug 17 18:23:36 2019 : Debug: (10) User-Name += "Robert" Sat Aug 17 18:23:36 2019 : Debug: (10) Sent Access-Challenge Id 248 from 172.16.0.12:1812 to 172.16.0.5:48453 length 0 Sat Aug 17 18:23:36 2019 : Debug: (10) EAP-Message = 0x011c002e19001703030023b6cc9859d9e1d9fbccb915ae16456ad2c329aa053517b0282f4ff9fdf0e8bc45841a94 Sat Aug 17 18:23:36 2019 : Debug: (10) Message-Authenticator = 0x00000000000000000000000000000000 Sat Aug 17 18:23:36 2019 : Debug: (10) State = 0x7d7976aa74656f6ce06082b82288935b Sat Aug 17 18:23:36 2019 : Debug: (10) Finished request Sat Aug 17 18:23:36 2019 : Debug: Waking up in 2.7 seconds. Sat Aug 17 18:23:36 2019 : Debug: (11) Received Access-Request Id 249 from 172.16.0.5:48453 to 172.16.0.12:1812 length 251 Sat Aug 17 18:23:36 2019 : Debug: (11) User-Name = "Robert" Sat Aug 17 18:23:36 2019 : Debug: (11) NAS-Identifier = "feec3a9aeda5" Sat Aug 17 18:23:36 2019 : Debug: (11) Called-Station-Id = "FE-EC-3A-9A-ED-A5:Guest" Sat Aug 17 18:23:36 2019 : Debug: (11) NAS-Port-Type = Wireless-802.11 Sat Aug 17 18:23:36 2019 : Debug: (11) Service-Type = Framed-User Sat Aug 17 18:23:36 2019 : Debug: (11) Calling-Station-Id = "04-DB-56-F0-C3-36" Sat Aug 17 18:23:36 2019 : Debug: (11) Connect-Info = "CONNECT 0Mbps 802.11b" Sat Aug 17 18:23:36 2019 : Debug: (11) Acct-Session-Id = "D9B312EA0EEDF1F6" Sat Aug 17 18:23:36 2019 : Debug: (11) Mobility-Domain-Id = 1826 Sat Aug 17 18:23:36 2019 : Debug: (11) WLAN-Pairwise-Cipher = 1027076 Sat Aug 17 18:23:36 2019 : Debug: (11) WLAN-Group-Cipher = 1027076 Sat Aug 17 18:23:36 2019 : Debug: (11) WLAN-AKM-Suite = 1027075 Sat Aug 17 18:23:36 2019 : Debug: (11) Framed-MTU = 1400 Sat Aug 17 18:23:36 2019 : Debug: (11) EAP-Message = 0x021c002e190017030300237ee7eda10323b327ee4332f9f48ce3978ef4ac3929fc08c00d246f066c893b4a182b1d Sat Aug 17 18:23:36 2019 : Debug: (11) State = 0x7d7976aa74656f6ce06082b82288935b Sat Aug 17 18:23:36 2019 : Debug: (11) Message-Authenticator = 0xd6f3c9ee16eb98c8d0217d85c9804c2e Sat Aug 17 18:23:36 2019 : Debug: (11) Restoring &session-state Sat Aug 17 18:23:36 2019 : Debug: (11) &session-state:Tunnel-Private-Group-Id += "11" Sat Aug 17 18:23:36 2019 : Debug: (11) &session-state:Tunnel-Type += VLAN Sat Aug 17 18:23:36 2019 : Debug: (11) &session-state:Tunnel-Medium-Type += IEEE-802 Sat Aug 17 18:23:36 2019 : Debug: (11) &session-state:Session-Timeout += 873 Sat Aug 17 18:23:36 2019 : Debug: (11) &session-state:Acct-Interim-Interval += 300 Sat Aug 17 18:23:36 2019 : Debug: (11) &session-state:Idle-Timeout += 450 Sat Aug 17 18:23:36 2019 : Debug: (11) &session-state:Termination-Action += RADIUS-Request Sat Aug 17 18:23:36 2019 : Debug: (11) &session-state:User-Name += "Robert" Sat Aug 17 18:23:36 2019 : Debug: (11) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default Sat Aug 17 18:23:36 2019 : Debug: (11) authorize { Sat Aug 17 18:23:36 2019 : Debug: (11) policy filter_username { Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name) { Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name) -> TRUE Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name) { Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name =~ / /) { Sat Aug 17 18:23:36 2019 : Debug: No matches Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name =~ / /) -> FALSE Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name =~ /@[^@]*@/ ) { Sat Aug 17 18:23:36 2019 : Debug: No matches Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name =~ /@[^@]*@/ ) -> FALSE Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name =~ /\.\./ ) { Sat Aug 17 18:23:36 2019 : Debug: No matches Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name =~ /\.\./ ) -> FALSE Sat Aug 17 18:23:36 2019 : Debug: (11) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { Sat Aug 17 18:23:36 2019 : Debug: No matches Sat Aug 17 18:23:36 2019 : Debug: (11) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name =~ /\.$/) { Sat Aug 17 18:23:36 2019 : Debug: No matches Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name =~ /\.$/) -> FALSE Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name =~ /(a)\./) { Sat Aug 17 18:23:36 2019 : Debug: No matches Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Name =~ /(a)\./) -> FALSE Sat Aug 17 18:23:36 2019 : Debug: (11) } # if (&User-Name) = notfound Sat Aug 17 18:23:36 2019 : Debug: (11) } # policy filter_username = notfound Sat Aug 17 18:23:36 2019 : Debug: (11) policy filter_password { Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Password && (&User-Password != "%{string:User-Password}")) { Sat Aug 17 18:23:36 2019 : Debug: (11) if (&User-Password && (&User-Password != "%{string:User-Password}")) -> FALSE Sat Aug 17 18:23:36 2019 : Debug: (11) } # policy filter_password = notfound Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[authorize]: calling preprocess (rlm_preprocess) Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[authorize]: returned from preprocess (rlm_preprocess) Sat Aug 17 18:23:36 2019 : Debug: (11) [preprocess] = ok Sat Aug 17 18:23:36 2019 : Debug: (11) update request { Sat Aug 17 18:23:36 2019 : Debug: %{User-Name} Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree: Sat Aug 17 18:23:36 2019 : Debug: attribute --> User-Name Sat Aug 17 18:23:36 2019 : Debug: (11) EXPAND %{User-Name} Sat Aug 17 18:23:36 2019 : Debug: (11) --> Robert Sat Aug 17 18:23:36 2019 : Debug: (11) SQL-User-Name set to 'Robert' Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Reserved connection (7) Sat Aug 17 18:23:36 2019 : Debug: (11) Executing select query: select groupname from radhuntgroup where nasipaddress="172.16.0.5" Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Released connection (7) Sat Aug 17 18:23:36 2019 : Debug: (11) EXPAND %{sql:select groupname from radhuntgroup where nasipaddress="%{NAS-IP-Address}"} Sat Aug 17 18:23:36 2019 : Debug: (11) --> WiFi Sat Aug 17 18:23:36 2019 : Debug: (11) Huntgroup-Name := WiFi Sat Aug 17 18:23:36 2019 : Debug: (11) } # update request = noop Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[authorize]: calling mschap (rlm_mschap) Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[authorize]: returned from mschap (rlm_mschap) Sat Aug 17 18:23:36 2019 : Debug: (11) [mschap] = noop Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[authorize]: calling suffix (rlm_realm) Sat Aug 17 18:23:36 2019 : Debug: (11) suffix: Checking for suffix after "@" Sat Aug 17 18:23:36 2019 : Debug: (11) suffix: No '@' in User-Name = "Robert", looking up realm NULL Sat Aug 17 18:23:36 2019 : Debug: (11) suffix: No such realm "NULL" Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[authorize]: returned from suffix (rlm_realm) Sat Aug 17 18:23:36 2019 : Debug: (11) [suffix] = noop Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[authorize]: calling eap (rlm_eap) Sat Aug 17 18:23:36 2019 : Debug: (11) eap: Peer sent EAP Response (code 2) ID 28 length 46 Sat Aug 17 18:23:36 2019 : Debug: (11) eap: Continuing tunnel setup Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[authorize]: returned from eap (rlm_eap) Sat Aug 17 18:23:36 2019 : Debug: (11) [eap] = ok Sat Aug 17 18:23:36 2019 : Debug: (11) } # authorize = ok Sat Aug 17 18:23:36 2019 : Debug: (11) Found Auth-Type = eap Sat Aug 17 18:23:36 2019 : Debug: (11) # Executing group from file /etc/freeradius/3.0/sites-enabled/default Sat Aug 17 18:23:36 2019 : Debug: (11) authenticate { Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[authenticate]: calling eap (rlm_eap) Sat Aug 17 18:23:36 2019 : Debug: (11) eap: Expiring EAP session with state 0x7d7976aa74656f6c Sat Aug 17 18:23:36 2019 : Debug: (11) eap: Finished EAP session with state 0x7d7976aa74656f6c Sat Aug 17 18:23:36 2019 : Debug: (11) eap: Previous EAP request found for state 0x7d7976aa74656f6c, released from the list Sat Aug 17 18:23:36 2019 : Debug: (11) eap: Peer sent packet with method EAP PEAP (25) Sat Aug 17 18:23:36 2019 : Debug: (11) eap: Calling submodule eap_peap to process data Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Continuing EAP-TLS Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Peer sent flags --- Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: [eaptls verify] = ok Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Done initial handshake Sat Aug 17 18:23:36 2019 : Debug: Ignoring cbtls_msg call with pseudo content type 256, version 0 Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: [eaptls process] = ok Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Session established. Decoding tunneled attributes Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: PEAP state send tlv success Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Received EAP-TLV response Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Success Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Using saved attributes from the original Access-Accept Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Tunnel-Private-Group-Id = "11" Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Tunnel-Type = VLAN Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Tunnel-Medium-Type = IEEE-802 Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Fall-Through = Yes Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Session-Timeout = 873 Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Acct-Interim-Interval = 300 Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Idle-Timeout = 450 Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: Termination-Action = RADIUS-Request Sat Aug 17 18:23:36 2019 : Debug: (11) eap_peap: User-Name := "Robert" Sat Aug 17 18:23:36 2019 : Debug: (11) eap: Sending EAP Success (code 3) ID 28 length 4 Sat Aug 17 18:23:36 2019 : Debug: (11) eap: Freeing handler Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[authenticate]: returned from eap (rlm_eap) Sat Aug 17 18:23:36 2019 : Debug: (11) [eap] = ok Sat Aug 17 18:23:36 2019 : Debug: (11) } # authenticate = ok Sat Aug 17 18:23:36 2019 : Debug: (11) # Executing section post-auth from file /etc/freeradius/3.0/sites-enabled/default Sat Aug 17 18:23:36 2019 : Debug: (11) post-auth { Sat Aug 17 18:23:36 2019 : Debug: (11) if (!&reply:State) { Sat Aug 17 18:23:36 2019 : Debug: (11) if (!&reply:State) -> TRUE Sat Aug 17 18:23:36 2019 : Debug: (11) if (!&reply:State) { Sat Aug 17 18:23:36 2019 : Debug: (11) update reply { Sat Aug 17 18:23:36 2019 : Debug: (11) EXPAND 0x%{randstr:16h} Sat Aug 17 18:23:36 2019 : Debug: (11) --> 0x8ce7b66eb9b9d607320857ccac1d3c220f Sat Aug 17 18:23:36 2019 : Debug: (11) State := 0x8ce7b66eb9b9d607320857ccac1d3c220f Sat Aug 17 18:23:36 2019 : Debug: (11) } # update reply = noop Sat Aug 17 18:23:36 2019 : Debug: (11) } # if (!&reply:State) = noop Sat Aug 17 18:23:36 2019 : Debug: (11) update { Sat Aug 17 18:23:36 2019 : Debug: (11) &reply::Tunnel-Private-Group-Id += &session-state:Tunnel-Private-Group-Id[*] -> '11' Sat Aug 17 18:23:36 2019 : Debug: (11) &reply::Tunnel-Type += &session-state:Tunnel-Type[*] -> VLAN Sat Aug 17 18:23:36 2019 : Debug: (11) &reply::Tunnel-Medium-Type += &session-state:Tunnel-Medium-Type[*] -> IEEE-802 Sat Aug 17 18:23:36 2019 : Debug: (11) &reply::Session-Timeout += &session-state:Session-Timeout[*] -> 873 Sat Aug 17 18:23:36 2019 : Debug: (11) &reply::Acct-Interim-Interval += &session-state:Acct-Interim-Interval[*] -> 300 Sat Aug 17 18:23:36 2019 : Debug: (11) &reply::Idle-Timeout += &session-state:Idle-Timeout[*] -> 450 Sat Aug 17 18:23:36 2019 : Debug: (11) &reply::Termination-Action += &session-state:Termination-Action[*] -> RADIUS-Request Sat Aug 17 18:23:36 2019 : Debug: (11) &reply::User-Name += &session-state:User-Name[*] -> 'Robert' Sat Aug 17 18:23:36 2019 : Debug: (11) } # update = noop Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[post-auth]: calling sql (rlm_sql) Sat Aug 17 18:23:36 2019 : Debug: .query Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree: Sat Aug 17 18:23:36 2019 : Debug: literal --> .query Sat Aug 17 18:23:36 2019 : Debug: (11) sql: EXPAND .query Sat Aug 17 18:23:36 2019 : Debug: (11) sql: --> .query Sat Aug 17 18:23:36 2019 : Debug: (11) sql: Using query template 'query' Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Reserved connection (6) Sat Aug 17 18:23:36 2019 : Debug: %{User-Name} Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree: Sat Aug 17 18:23:36 2019 : Debug: attribute --> User-Name Sat Aug 17 18:23:36 2019 : Debug: (11) sql: EXPAND %{User-Name} Sat Aug 17 18:23:36 2019 : Debug: (11) sql: --> Robert Sat Aug 17 18:23:36 2019 : Debug: (11) sql: SQL-User-Name set to 'Robert' Sat Aug 17 18:23:36 2019 : Debug: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') Sat Aug 17 18:23:36 2019 : Debug: Parsed xlat tree: Sat Aug 17 18:23:36 2019 : Debug: literal --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( ' Sat Aug 17 18:23:36 2019 : Debug: attribute --> SQL-User-Name Sat Aug 17 18:23:36 2019 : Debug: literal --> ', ' Sat Aug 17 18:23:36 2019 : Debug: XLAT-IF { Sat Aug 17 18:23:36 2019 : Debug: attribute --> User-Password Sat Aug 17 18:23:36 2019 : Debug: } Sat Aug 17 18:23:36 2019 : Debug: XLAT-ELSE { Sat Aug 17 18:23:36 2019 : Debug: attribute --> CHAP-Password Sat Aug 17 18:23:36 2019 : Debug: } Sat Aug 17 18:23:36 2019 : Debug: literal --> ', ' Sat Aug 17 18:23:36 2019 : Debug: attribute --> Packet-Type Sat Aug 17 18:23:36 2019 : Debug: literal --> ', ' Sat Aug 17 18:23:36 2019 : Debug: percent --> S Sat Aug 17 18:23:36 2019 : Debug: literal --> ') Sat Aug 17 18:23:36 2019 : Debug: (11) sql: EXPAND INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') Sat Aug 17 18:23:36 2019 : Debug: (11) sql: --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'Robert', '', 'Access-Accept', '2019-08-17 18:23:36') Sat Aug 17 18:23:36 2019 : Debug: (11) sql: Executing query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'Robert', '', 'Access-Accept', '2019-08-17 18:23:36') Sat Aug 17 18:23:36 2019 : Debug: (11) sql: SQL query returned: success Sat Aug 17 18:23:36 2019 : Debug: (11) sql: 1 record(s) updated Sat Aug 17 18:23:36 2019 : Debug: rlm_sql (sql): Released connection (6) Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[post-auth]: returned from sql (rlm_sql) Sat Aug 17 18:23:36 2019 : Debug: (11) [sql] = ok Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[post-auth]: calling exec (rlm_exec) Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[post-auth]: returned from exec (rlm_exec) Sat Aug 17 18:23:36 2019 : Debug: (11) [exec] = noop Sat Aug 17 18:23:36 2019 : Debug: (11) policy insert_acct_class { Sat Aug 17 18:23:36 2019 : Debug: (11) update reply { Sat Aug 17 18:23:36 2019 : Debug: (11) EXPAND ai:%{md5:%t,%I,%{Packet-Src-Port},%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}},%{NAS-IP-Address},%{Calling-Station-ID},%{User-Name}} Sat Aug 17 18:23:36 2019 : Debug: (11) --> ai:acc29570a803c6c1a2268e867f1ed360 Sat Aug 17 18:23:36 2019 : Debug: (11) &Class = 0x61693a6163633239353730613830336336633161323236386538363766316564333630 Sat Aug 17 18:23:36 2019 : Debug: (11) } # update reply = noop Sat Aug 17 18:23:36 2019 : Debug: (11) } # policy insert_acct_class = noop Sat Aug 17 18:23:36 2019 : Debug: (11) if (&reply:EAP-Session-Id) { Sat Aug 17 18:23:36 2019 : Debug: (11) if (&reply:EAP-Session-Id) -> TRUE Sat Aug 17 18:23:36 2019 : Debug: (11) if (&reply:EAP-Session-Id) { Sat Aug 17 18:23:36 2019 : Debug: (11) update reply { Sat Aug 17 18:23:36 2019 : Debug: (11) EAP-Key-Name := &reply:EAP-Session-Id -> 0x195d582a086518d8626f3c8c8eb4ed1ae02b0e4d222b2363d0d6bb66028aebd9db3ec9aff3e280360a837f90ade646df976f66d4b2d287de285083a6df4935b8d7 Sat Aug 17 18:23:36 2019 : Debug: (11) } # update reply = noop Sat Aug 17 18:23:36 2019 : Debug: (11) } # if (&reply:EAP-Session-Id) = noop Sat Aug 17 18:23:36 2019 : Debug: (11) policy remove_reply_message_if_eap { Sat Aug 17 18:23:36 2019 : Debug: (11) if (&reply:EAP-Message && &reply:Reply-Message) { Sat Aug 17 18:23:36 2019 : Debug: (11) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE Sat Aug 17 18:23:36 2019 : Debug: (11) else { Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[post-auth]: calling noop (rlm_always) Sat Aug 17 18:23:36 2019 : Debug: (11) modsingle[post-auth]: returned from noop (rlm_always) Sat Aug 17 18:23:36 2019 : Debug: (11) [noop] = noop Sat Aug 17 18:23:36 2019 : Debug: (11) } # else = noop Sat Aug 17 18:23:36 2019 : Debug: (11) } # policy remove_reply_message_if_eap = noop Sat Aug 17 18:23:36 2019 : Debug: (11) } # post-auth = ok Sat Aug 17 18:23:36 2019 : Debug: (11) Sent Access-Accept Id 249 from 172.16.0.12:1812 to 172.16.0.5:48453 length 0 Sat Aug 17 18:23:36 2019 : Debug: (11) Tunnel-Private-Group-Id = "11" Sat Aug 17 18:23:36 2019 : Debug: (11) Tunnel-Type = VLAN Sat Aug 17 18:23:36 2019 : Debug: (11) Tunnel-Medium-Type = IEEE-802 Sat Aug 17 18:23:36 2019 : Debug: (11) Session-Timeout = 873 Sat Aug 17 18:23:36 2019 : Debug: (11) Acct-Interim-Interval = 300 Sat Aug 17 18:23:36 2019 : Debug: (11) Idle-Timeout = 450 Sat Aug 17 18:23:36 2019 : Debug: (11) Termination-Action = RADIUS-Request Sat Aug 17 18:23:36 2019 : Debug: (11) User-Name := "Robert" Sat Aug 17 18:23:36 2019 : Debug: (11) MS-MPPE-Recv-Key = 0x452f2e97de2dbf05277fd62b8844b590145d436fb68df569f785b973c302e8c2 Sat Aug 17 18:23:36 2019 : Debug: (11) MS-MPPE-Send-Key = 0x4512fafa8219e461fbc3822b8f22ed4bde669628ef7a05918a3192c173cbfbaf Sat Aug 17 18:23:36 2019 : Debug: (11) EAP-Message = 0x031c0004 Sat Aug 17 18:23:36 2019 : Debug: (11) Message-Authenticator = 0x00000000000000000000000000000000 Sat Aug 17 18:23:36 2019 : Debug: (11) State := 0x8ce7b66eb9b9d607320857ccac1d3c220f Sat Aug 17 18:23:36 2019 : Debug: (11) Tunnel-Private-Group-Id += "11" Sat Aug 17 18:23:36 2019 : Debug: (11) Tunnel-Type += VLAN Sat Aug 17 18:23:36 2019 : Debug: (11) Tunnel-Medium-Type += IEEE-802 Sat Aug 17 18:23:36 2019 : Debug: (11) Session-Timeout += 873 Sat Aug 17 18:23:36 2019 : Debug: (11) Acct-Interim-Interval += 300 Sat Aug 17 18:23:36 2019 : Debug: (11) Idle-Timeout += 450 Sat Aug 17 18:23:36 2019 : Debug: (11) Termination-Action += RADIUS-Request Sat Aug 17 18:23:36 2019 : Debug: (11) User-Name += "Robert" Sat Aug 17 18:23:36 2019 : Debug: (11) Class = 0x61693a6163633239353730613830336336633161323236386538363766316564333630 Sat Aug 17 18:23:36 2019 : Debug: (11) EAP-Key-Name := 0x195d582a086518d8626f3c8c8eb4ed1ae02b0e4d222b2363d0d6bb66028aebd9db3ec9aff3e280360a837f90ade646df976f66d4b2d287de285083a6df4935b8d7 Sat Aug 17 18:23:36 2019 : Debug: (11) Finished request ———————————————— Server configuration: ————————————— Sat Aug 17 18:20:38 2019 : Info: Starting - reading configuration files ... Sat Aug 17 18:20:38 2019 : Debug: including dictionary file /usr/share/freeradius/dictionary Sat Aug 17 18:20:38 2019 : Debug: including dictionary file /usr/share/freeradius/dictionary.dhcp Sat Aug 17 18:20:38 2019 : Debug: including dictionary file /usr/share/freeradius/dictionary.vqp Sat Aug 17 18:20:38 2019 : Debug: including dictionary file /etc/freeradius/3.0/dictionary Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/radiusd.conf Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/proxy.conf Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/clients.conf Sat Aug 17 18:20:38 2019 : Debug: including files in directory /etc/freeradius/3.0/mods-enabled/ Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/always Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/attr_filter Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/cache_eap Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/chap Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/detail Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/detail.log Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/digest Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/dynamic_clients Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/eap Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/echo Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/exec Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/expiration Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/expr Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/files Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/linelog Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/logintime Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/mschap Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/ntlm_auth Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/pap Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/passwd Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/preprocess Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/radutmp Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/realm Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/replicate Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/soh Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/sradutmp Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/unix Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/unpack Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/utf8 Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/sql Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-config/sql/main/mysql/queries.conf Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/sqlcounter Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-config/sql/counter/mysql/dailycounter.conf Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-config/sql/counter/mysql/monthlycounter.conf Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-config/sql/counter/mysql/noresetcounter.conf Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-config/sql/counter/mysql/expire_on_login.conf Sat Aug 17 18:20:38 2019 : Debug: including files in directory /etc/freeradius/3.0/policy.d/ Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/abfab-tr Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/accounting Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/canonicalization Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/control Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/cui Sat Aug 17 18:20:38 2019 : Debug: OPTIMIZING (${policy.cui_require_operator_name} == yes) --> FALSE Sat Aug 17 18:20:38 2019 : Debug: OPTIMIZING (no == yes) --> FALSE Sat Aug 17 18:20:38 2019 : Debug: OPTIMIZING (${policy.cui_require_operator_name} == yes) --> FALSE Sat Aug 17 18:20:38 2019 : Debug: OPTIMIZING (no == yes) --> FALSE Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/debug Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/dhcp Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/eap Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/filter Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/moonshot-targeted-ids Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/operator-name Sat Aug 17 18:20:38 2019 : Debug: including files in directory /etc/freeradius/3.0/sites-enabled/ Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/sites-enabled/default Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/sites-enabled/inner-tunnel Sat Aug 17 18:20:38 2019 : Debug: including configuration file /etc/freeradius/3.0/sites-enabled/status Sat Aug 17 18:20:38 2019 : Debug: main { Sat Aug 17 18:20:38 2019 : Debug: security { Sat Aug 17 18:20:38 2019 : Debug: user = "freerad" Sat Aug 17 18:20:38 2019 : Debug: group = "freerad" Sat Aug 17 18:20:38 2019 : Debug: allow_core_dumps = no Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[424]: The item 'max_attributes' is defined, but is unused by the configuration Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[442]: The item 'reject_delay' is defined, but is unused by the configuration Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[462]: The item 'status_server' is defined, but is unused by the configuration Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: name = "freeradius" Sat Aug 17 18:20:38 2019 : Debug: prefix = "/usr" Sat Aug 17 18:20:38 2019 : Debug: localstatedir = "/var" Sat Aug 17 18:20:38 2019 : Debug: logdir = "/var/log/freeradius" Sat Aug 17 18:20:38 2019 : Debug: run_dir = "/var/run/freeradius" Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[55]: The item 'sysconfdir' is defined, but is unused by the configuration Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[67]: The item 'confdir' is defined, but is unused by the configuration Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[74]: The item 'db_dir' is defined, but is unused by the configuration Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[108]: The item 'libdir' is defined, but is unused by the configuration Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[119]: The item 'pidfile' is defined, but is unused by the configuration Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[140]: The item 'correct_escapes' is defined, but is unused by the configuration Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[194]: The item 'max_request_time' is defined, but is unused by the configuration Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[213]: The item 'cleanup_delay' is defined, but is unused by the configuration Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[250]: The item 'hostname_lookups' is defined, but is unused by the configuration Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[334]: The item 'checkrad' is defined, but is unused by the configuration Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[483]: The item 'proxy_requests' is defined, but is unused by the configuration Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: main { Sat Aug 17 18:20:38 2019 : Debug: name = "freeradius" Sat Aug 17 18:20:38 2019 : Debug: prefix = "/usr" Sat Aug 17 18:20:38 2019 : Debug: localstatedir = "/var" Sat Aug 17 18:20:38 2019 : Debug: sbindir = "/usr/sbin" Sat Aug 17 18:20:38 2019 : Debug: logdir = "/var/log/freeradius" Sat Aug 17 18:20:38 2019 : Debug: run_dir = "/var/run/freeradius" Sat Aug 17 18:20:38 2019 : Debug: libdir = "/usr/lib/freeradius" Sat Aug 17 18:20:38 2019 : Debug: radacctdir = "/var/log/freeradius/radacct" Sat Aug 17 18:20:38 2019 : Debug: hostname_lookups = no Sat Aug 17 18:20:38 2019 : Debug: max_request_time = 15 Sat Aug 17 18:20:38 2019 : Debug: cleanup_delay = 3 Sat Aug 17 18:20:38 2019 : Debug: max_requests = 16384 Sat Aug 17 18:20:38 2019 : Debug: pidfile = "/var/run/freeradius/freeradius.pid" Sat Aug 17 18:20:38 2019 : Debug: checkrad = "/usr/sbin/checkrad" Sat Aug 17 18:20:38 2019 : Debug: debug_level = 0 Sat Aug 17 18:20:38 2019 : Debug: proxy_requests = yes Sat Aug 17 18:20:38 2019 : Debug: log { Sat Aug 17 18:20:38 2019 : Debug: stripped_names = no Sat Aug 17 18:20:38 2019 : Debug: auth = no Sat Aug 17 18:20:38 2019 : Debug: auth_badpass = no Sat Aug 17 18:20:38 2019 : Debug: auth_goodpass = no Sat Aug 17 18:20:38 2019 : Debug: colourise = yes Sat Aug 17 18:20:38 2019 : Debug: msg_denied = "You are already logged in - access denied" Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[268]: The item 'destination' is defined, but is unused by the configuration Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[285]: The item 'file' is defined, but is unused by the configuration Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[293]: The item 'syslog_facility' is defined, but is unused by the configuration Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: resources { Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: security { Sat Aug 17 18:20:38 2019 : Debug: max_attributes = 200 Sat Aug 17 18:20:38 2019 : Debug: reject_delay = 1.000000 Sat Aug 17 18:20:38 2019 : Debug: status_server = yes Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[55]: The item 'sysconfdir' is defined, but is unused by the configuration Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[67]: The item 'confdir' is defined, but is unused by the configuration Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[74]: The item 'db_dir' is defined, but is unused by the configuration Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[140]: The item 'correct_escapes' is defined, but is unused by the configuration Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: radiusd: #### Loading Realms and Home Servers #### Sat Aug 17 18:20:38 2019 : Debug: proxy server { Sat Aug 17 18:20:38 2019 : Debug: retry_delay = 5 Sat Aug 17 18:20:38 2019 : Debug: retry_count = 3 Sat Aug 17 18:20:38 2019 : Debug: default_fallback = no Sat Aug 17 18:20:38 2019 : Debug: dead_time = 120 Sat Aug 17 18:20:38 2019 : Debug: wake_all_if_all_dead = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: home_server localhost { Sat Aug 17 18:20:38 2019 : Debug: ipaddr = 127.0.0.1 Sat Aug 17 18:20:38 2019 : Debug: port = 1812 Sat Aug 17 18:20:38 2019 : Debug: type = "auth" Sat Aug 17 18:20:38 2019 : Debug: secret = "testing123" Sat Aug 17 18:20:38 2019 : Debug: response_window = 20.000000 Sat Aug 17 18:20:38 2019 : Debug: response_timeouts = 1 Sat Aug 17 18:20:38 2019 : Debug: max_outstanding = 65536 Sat Aug 17 18:20:38 2019 : Debug: zombie_period = 40 Sat Aug 17 18:20:38 2019 : Debug: status_check = "status-server" Sat Aug 17 18:20:38 2019 : Debug: ping_interval = 30 Sat Aug 17 18:20:38 2019 : Debug: check_interval = 30 Sat Aug 17 18:20:38 2019 : Debug: check_timeout = 4 Sat Aug 17 18:20:38 2019 : Debug: num_answers_to_alive = 3 Sat Aug 17 18:20:38 2019 : Debug: revive_interval = 120 Sat Aug 17 18:20:38 2019 : Debug: limit { Sat Aug 17 18:20:38 2019 : Debug: max_connections = 16 Sat Aug 17 18:20:38 2019 : Debug: max_requests = 0 Sat Aug 17 18:20:38 2019 : Debug: lifetime = 0 Sat Aug 17 18:20:38 2019 : Debug: idle_timeout = 0 Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: coa { Sat Aug 17 18:20:38 2019 : Debug: irt = 2 Sat Aug 17 18:20:38 2019 : Debug: mrt = 16 Sat Aug 17 18:20:38 2019 : Debug: mrc = 5 Sat Aug 17 18:20:38 2019 : Debug: mrd = 30 Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Warning: WARNING: Ignoring "response_window = 20.000000", forcing to "response_window = 15.000000" Sat Aug 17 18:20:38 2019 : Debug: home_server_pool my_auth_failover { Sat Aug 17 18:20:38 2019 : Debug: type = fail-over Sat Aug 17 18:20:38 2019 : Debug: home_server = localhost Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: realm example.com { Sat Aug 17 18:20:38 2019 : Debug: auth_pool = my_auth_failover Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: realm LOCAL { Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: radiusd: #### Loading Clients #### Sat Aug 17 18:20:38 2019 : Debug: client localhost { Sat Aug 17 18:20:38 2019 : Debug: ipaddr = 127.0.0.1 Sat Aug 17 18:20:38 2019 : Debug: require_message_authenticator = no Sat Aug 17 18:20:38 2019 : Debug: secret = "testing123" Sat Aug 17 18:20:38 2019 : Debug: nas_type = "other" Sat Aug 17 18:20:38 2019 : Debug: proto = "*" Sat Aug 17 18:20:38 2019 : Debug: limit { Sat Aug 17 18:20:38 2019 : Debug: max_connections = 16 Sat Aug 17 18:20:38 2019 : Debug: lifetime = 0 Sat Aug 17 18:20:38 2019 : Debug: idle_timeout = 30 Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Adding client 127.0.0.1/32 (127.0.0.1) to prefix tree 32 Sat Aug 17 18:20:38 2019 : Debug: client localhost_ipv6 { Sat Aug 17 18:20:38 2019 : Debug: ipv6addr = ::1 Sat Aug 17 18:20:38 2019 : Debug: require_message_authenticator = no Sat Aug 17 18:20:38 2019 : Debug: secret = "testing123" Sat Aug 17 18:20:38 2019 : Debug: limit { Sat Aug 17 18:20:38 2019 : Debug: max_connections = 16 Sat Aug 17 18:20:38 2019 : Debug: lifetime = 0 Sat Aug 17 18:20:38 2019 : Debug: idle_timeout = 30 Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Adding client ::1/128 (::1) to prefix tree 128 Sat Aug 17 18:20:38 2019 : Info: Debug state unknown (cap_sys_ptrace capability not set) Sat Aug 17 18:20:38 2019 : Debug: # Creating Auth-Type = mschap Sat Aug 17 18:20:38 2019 : Debug: # Creating Auth-Type = eap Sat Aug 17 18:20:38 2019 : Debug: # Creating Auth-Type = PAP Sat Aug 17 18:20:38 2019 : Debug: # Creating Auth-Type = MS-CHAP Sat Aug 17 18:20:38 2019 : Debug: # Creating Autz-Type = radius-status Sat Aug 17 18:20:38 2019 : Debug: # Creating Acct-Type = radius-status Sat Aug 17 18:20:38 2019 : Debug: radiusd: #### Instantiating modules #### Sat Aug 17 18:20:38 2019 : Debug: modules { Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_always with path: /usr/lib/freeradius/rlm_always.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_always, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_always Sat Aug 17 18:20:38 2019 : Debug: # Loading module "reject" from file /etc/freeradius/3.0/mods-enabled/always Sat Aug 17 18:20:38 2019 : Debug: always reject { Sat Aug 17 18:20:38 2019 : Debug: rcode = "reject" Sat Aug 17 18:20:38 2019 : Debug: simulcount = 0 Sat Aug 17 18:20:38 2019 : Debug: mpp = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "fail" from file /etc/freeradius/3.0/mods-enabled/always Sat Aug 17 18:20:38 2019 : Debug: always fail { Sat Aug 17 18:20:38 2019 : Debug: rcode = "fail" Sat Aug 17 18:20:38 2019 : Debug: simulcount = 0 Sat Aug 17 18:20:38 2019 : Debug: mpp = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "ok" from file /etc/freeradius/3.0/mods-enabled/always Sat Aug 17 18:20:38 2019 : Debug: always ok { Sat Aug 17 18:20:38 2019 : Debug: rcode = "ok" Sat Aug 17 18:20:38 2019 : Debug: simulcount = 0 Sat Aug 17 18:20:38 2019 : Debug: mpp = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "handled" from file /etc/freeradius/3.0/mods-enabled/always Sat Aug 17 18:20:38 2019 : Debug: always handled { Sat Aug 17 18:20:38 2019 : Debug: rcode = "handled" Sat Aug 17 18:20:38 2019 : Debug: simulcount = 0 Sat Aug 17 18:20:38 2019 : Debug: mpp = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "invalid" from file /etc/freeradius/3.0/mods-enabled/always Sat Aug 17 18:20:38 2019 : Debug: always invalid { Sat Aug 17 18:20:38 2019 : Debug: rcode = "invalid" Sat Aug 17 18:20:38 2019 : Debug: simulcount = 0 Sat Aug 17 18:20:38 2019 : Debug: mpp = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "userlock" from file /etc/freeradius/3.0/mods-enabled/always Sat Aug 17 18:20:38 2019 : Debug: always userlock { Sat Aug 17 18:20:38 2019 : Debug: rcode = "userlock" Sat Aug 17 18:20:38 2019 : Debug: simulcount = 0 Sat Aug 17 18:20:38 2019 : Debug: mpp = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "notfound" from file /etc/freeradius/3.0/mods-enabled/always Sat Aug 17 18:20:38 2019 : Debug: always notfound { Sat Aug 17 18:20:38 2019 : Debug: rcode = "notfound" Sat Aug 17 18:20:38 2019 : Debug: simulcount = 0 Sat Aug 17 18:20:38 2019 : Debug: mpp = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "noop" from file /etc/freeradius/3.0/mods-enabled/always Sat Aug 17 18:20:38 2019 : Debug: always noop { Sat Aug 17 18:20:38 2019 : Debug: rcode = "noop" Sat Aug 17 18:20:38 2019 : Debug: simulcount = 0 Sat Aug 17 18:20:38 2019 : Debug: mpp = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "updated" from file /etc/freeradius/3.0/mods-enabled/always Sat Aug 17 18:20:38 2019 : Debug: always updated { Sat Aug 17 18:20:38 2019 : Debug: rcode = "updated" Sat Aug 17 18:20:38 2019 : Debug: simulcount = 0 Sat Aug 17 18:20:38 2019 : Debug: mpp = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_attr_filter with path: /usr/lib/freeradius/rlm_attr_filter.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_attr_filter, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_attr_filter Sat Aug 17 18:20:38 2019 : Debug: # Loading module "attr_filter.post-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter Sat Aug 17 18:20:38 2019 : Debug: attr_filter attr_filter.post-proxy { Sat Aug 17 18:20:38 2019 : Debug: filename = "/etc/freeradius/3.0/mods-config/attr_filter/post-proxy" Sat Aug 17 18:20:38 2019 : Debug: key = "%{Realm}" Sat Aug 17 18:20:38 2019 : Debug: relaxed = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "attr_filter.pre-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter Sat Aug 17 18:20:38 2019 : Debug: attr_filter attr_filter.pre-proxy { Sat Aug 17 18:20:38 2019 : Debug: filename = "/etc/freeradius/3.0/mods-config/attr_filter/pre-proxy" Sat Aug 17 18:20:38 2019 : Debug: key = "%{Realm}" Sat Aug 17 18:20:38 2019 : Debug: relaxed = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "attr_filter.access_reject" from file /etc/freeradius/3.0/mods-enabled/attr_filter Sat Aug 17 18:20:38 2019 : Debug: attr_filter attr_filter.access_reject { Sat Aug 17 18:20:38 2019 : Debug: filename = "/etc/freeradius/3.0/mods-config/attr_filter/access_reject" Sat Aug 17 18:20:38 2019 : Debug: key = "%{User-Name}" Sat Aug 17 18:20:38 2019 : Debug: relaxed = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "attr_filter.access_challenge" from file /etc/freeradius/3.0/mods-enabled/attr_filter Sat Aug 17 18:20:38 2019 : Debug: attr_filter attr_filter.access_challenge { Sat Aug 17 18:20:38 2019 : Debug: filename = "/etc/freeradius/3.0/mods-config/attr_filter/access_challenge" Sat Aug 17 18:20:38 2019 : Debug: key = "%{User-Name}" Sat Aug 17 18:20:38 2019 : Debug: relaxed = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "attr_filter.accounting_response" from file /etc/freeradius/3.0/mods-enabled/attr_filter Sat Aug 17 18:20:38 2019 : Debug: attr_filter attr_filter.accounting_response { Sat Aug 17 18:20:38 2019 : Debug: filename = "/etc/freeradius/3.0/mods-config/attr_filter/accounting_response" Sat Aug 17 18:20:38 2019 : Debug: key = "%{User-Name}" Sat Aug 17 18:20:38 2019 : Debug: relaxed = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_cache with path: /usr/lib/freeradius/rlm_cache.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_cache, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_cache Sat Aug 17 18:20:38 2019 : Debug: # Loading module "cache_eap" from file /etc/freeradius/3.0/mods-enabled/cache_eap Sat Aug 17 18:20:38 2019 : Debug: cache cache_eap { Sat Aug 17 18:20:38 2019 : Debug: driver = "rlm_cache_rbtree" Sat Aug 17 18:20:38 2019 : Debug: key = "%{%{control:State}:-%{%{reply:State}:-%{State}}}" Sat Aug 17 18:20:38 2019 : Debug: ttl = 15 Sat Aug 17 18:20:38 2019 : Debug: max_entries = 0 Sat Aug 17 18:20:38 2019 : Debug: epoch = 0 Sat Aug 17 18:20:38 2019 : Debug: add_stats = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_chap with path: /usr/lib/freeradius/rlm_chap.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_chap, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_chap Sat Aug 17 18:20:38 2019 : Debug: # Loading module "chap" from file /etc/freeradius/3.0/mods-enabled/chap Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_detail with path: /usr/lib/freeradius/rlm_detail.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_detail, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_detail Sat Aug 17 18:20:38 2019 : Debug: # Loading module "detail" from file /etc/freeradius/3.0/mods-enabled/detail Sat Aug 17 18:20:38 2019 : Debug: detail { Sat Aug 17 18:20:38 2019 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" Sat Aug 17 18:20:38 2019 : Debug: header = "%t" Sat Aug 17 18:20:38 2019 : Debug: permissions = 384 Sat Aug 17 18:20:38 2019 : Debug: locking = no Sat Aug 17 18:20:38 2019 : Debug: escape_filenames = no Sat Aug 17 18:20:38 2019 : Debug: log_packet_header = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "auth_log" from file /etc/freeradius/3.0/mods-enabled/detail.log Sat Aug 17 18:20:38 2019 : Debug: detail auth_log { Sat Aug 17 18:20:38 2019 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d" Sat Aug 17 18:20:38 2019 : Debug: header = "%t" Sat Aug 17 18:20:38 2019 : Debug: permissions = 384 Sat Aug 17 18:20:38 2019 : Debug: locking = no Sat Aug 17 18:20:38 2019 : Debug: escape_filenames = no Sat Aug 17 18:20:38 2019 : Debug: log_packet_header = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "reply_log" from file /etc/freeradius/3.0/mods-enabled/detail.log Sat Aug 17 18:20:38 2019 : Debug: detail reply_log { Sat Aug 17 18:20:38 2019 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d" Sat Aug 17 18:20:38 2019 : Debug: header = "%t" Sat Aug 17 18:20:38 2019 : Debug: permissions = 384 Sat Aug 17 18:20:38 2019 : Debug: locking = no Sat Aug 17 18:20:38 2019 : Debug: escape_filenames = no Sat Aug 17 18:20:38 2019 : Debug: log_packet_header = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "pre_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log Sat Aug 17 18:20:38 2019 : Debug: detail pre_proxy_log { Sat Aug 17 18:20:38 2019 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d" Sat Aug 17 18:20:38 2019 : Debug: header = "%t" Sat Aug 17 18:20:38 2019 : Debug: permissions = 384 Sat Aug 17 18:20:38 2019 : Debug: locking = no Sat Aug 17 18:20:38 2019 : Debug: escape_filenames = no Sat Aug 17 18:20:38 2019 : Debug: log_packet_header = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "post_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log Sat Aug 17 18:20:38 2019 : Debug: detail post_proxy_log { Sat Aug 17 18:20:38 2019 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d" Sat Aug 17 18:20:38 2019 : Debug: header = "%t" Sat Aug 17 18:20:38 2019 : Debug: permissions = 384 Sat Aug 17 18:20:38 2019 : Debug: locking = no Sat Aug 17 18:20:38 2019 : Debug: escape_filenames = no Sat Aug 17 18:20:38 2019 : Debug: log_packet_header = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_digest with path: /usr/lib/freeradius/rlm_digest.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_digest, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_digest Sat Aug 17 18:20:38 2019 : Debug: # Loading module "digest" from file /etc/freeradius/3.0/mods-enabled/digest Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_dynamic_clients with path: /usr/lib/freeradius/rlm_dynamic_clients.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_dynamic_clients, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_dynamic_clients Sat Aug 17 18:20:38 2019 : Debug: # Loading module "dynamic_clients" from file /etc/freeradius/3.0/mods-enabled/dynamic_clients Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_eap with path: /usr/lib/freeradius/rlm_eap.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_eap, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_eap Sat Aug 17 18:20:38 2019 : Debug: # Loading module "eap" from file /etc/freeradius/3.0/mods-enabled/eap Sat Aug 17 18:20:38 2019 : Debug: eap { Sat Aug 17 18:20:38 2019 : Debug: default_eap_type = "peap" Sat Aug 17 18:20:38 2019 : Debug: timer_expire = 60 Sat Aug 17 18:20:38 2019 : Debug: ignore_unknown_eap_types = no Sat Aug 17 18:20:38 2019 : Debug: cisco_accounting_username_bug = no Sat Aug 17 18:20:38 2019 : Debug: max_sessions = 16384 Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_exec with path: /usr/lib/freeradius/rlm_exec.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_exec, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_exec Sat Aug 17 18:20:38 2019 : Debug: # Loading module "echo" from file /etc/freeradius/3.0/mods-enabled/echo Sat Aug 17 18:20:38 2019 : Debug: exec echo { Sat Aug 17 18:20:38 2019 : Debug: wait = yes Sat Aug 17 18:20:38 2019 : Debug: program = "/bin/echo %{User-Name}" Sat Aug 17 18:20:38 2019 : Debug: input_pairs = "request" Sat Aug 17 18:20:38 2019 : Debug: output_pairs = "reply" Sat Aug 17 18:20:38 2019 : Debug: shell_escape = yes Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "exec" from file /etc/freeradius/3.0/mods-enabled/exec Sat Aug 17 18:20:38 2019 : Debug: exec { Sat Aug 17 18:20:38 2019 : Debug: wait = no Sat Aug 17 18:20:38 2019 : Debug: input_pairs = "request" Sat Aug 17 18:20:38 2019 : Debug: shell_escape = yes Sat Aug 17 18:20:38 2019 : Debug: timeout = 10 Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_expiration with path: /usr/lib/freeradius/rlm_expiration.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_expiration, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_expiration Sat Aug 17 18:20:38 2019 : Debug: # Loading module "expiration" from file /etc/freeradius/3.0/mods-enabled/expiration Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_expr with path: /usr/lib/freeradius/rlm_expr.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_expr, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_expr Sat Aug 17 18:20:38 2019 : Debug: # Loading module "expr" from file /etc/freeradius/3.0/mods-enabled/expr Sat Aug 17 18:20:38 2019 : Debug: expr { Sat Aug 17 18:20:38 2019 : Debug: safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_files with path: /usr/lib/freeradius/rlm_files.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_files, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_files Sat Aug 17 18:20:38 2019 : Debug: # Loading module "files" from file /etc/freeradius/3.0/mods-enabled/files Sat Aug 17 18:20:38 2019 : Debug: files { Sat Aug 17 18:20:38 2019 : Debug: filename = "/etc/freeradius/3.0/mods-config/files/authorize" Sat Aug 17 18:20:38 2019 : Debug: acctusersfile = "/etc/freeradius/3.0/mods-config/files/accounting" Sat Aug 17 18:20:38 2019 : Debug: preproxy_usersfile = "/etc/freeradius/3.0/mods-config/files/pre-proxy" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_linelog with path: /usr/lib/freeradius/rlm_linelog.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_linelog, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_linelog Sat Aug 17 18:20:38 2019 : Debug: # Loading module "linelog" from file /etc/freeradius/3.0/mods-enabled/linelog Sat Aug 17 18:20:38 2019 : Debug: linelog { Sat Aug 17 18:20:38 2019 : Debug: filename = "/var/log/freeradius/linelog" Sat Aug 17 18:20:38 2019 : Debug: escape_filenames = no Sat Aug 17 18:20:38 2019 : Debug: syslog_severity = "info" Sat Aug 17 18:20:38 2019 : Debug: permissions = 384 Sat Aug 17 18:20:38 2019 : Debug: format = "This is a log message for %{User-Name}" Sat Aug 17 18:20:38 2019 : Debug: reference = "messages.%{%{reply:Packet-Type}:-default}" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "log_accounting" from file /etc/freeradius/3.0/mods-enabled/linelog Sat Aug 17 18:20:38 2019 : Debug: linelog log_accounting { Sat Aug 17 18:20:38 2019 : Debug: filename = "/var/log/freeradius/linelog-accounting" Sat Aug 17 18:20:38 2019 : Debug: escape_filenames = no Sat Aug 17 18:20:38 2019 : Debug: syslog_severity = "info" Sat Aug 17 18:20:38 2019 : Debug: permissions = 384 Sat Aug 17 18:20:38 2019 : Debug: format = "" Sat Aug 17 18:20:38 2019 : Debug: reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_logintime with path: /usr/lib/freeradius/rlm_logintime.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_logintime, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_logintime Sat Aug 17 18:20:38 2019 : Debug: # Loading module "logintime" from file /etc/freeradius/3.0/mods-enabled/logintime Sat Aug 17 18:20:38 2019 : Debug: logintime { Sat Aug 17 18:20:38 2019 : Debug: minimum_timeout = 60 Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_mschap with path: /usr/lib/freeradius/rlm_mschap.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_mschap, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_mschap Sat Aug 17 18:20:38 2019 : Debug: # Loading module "mschap" from file /etc/freeradius/3.0/mods-enabled/mschap Sat Aug 17 18:20:38 2019 : Debug: mschap { Sat Aug 17 18:20:38 2019 : Debug: use_mppe = yes Sat Aug 17 18:20:38 2019 : Debug: require_encryption = no Sat Aug 17 18:20:38 2019 : Debug: require_strong = no Sat Aug 17 18:20:38 2019 : Debug: with_ntdomain_hack = yes Sat Aug 17 18:20:38 2019 : Debug: passchange { Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: allow_retry = yes Sat Aug 17 18:20:38 2019 : Debug: winbind_retry_with_normalised_username = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "ntlm_auth" from file /etc/freeradius/3.0/mods-enabled/ntlm_auth Sat Aug 17 18:20:38 2019 : Debug: exec ntlm_auth { Sat Aug 17 18:20:38 2019 : Debug: wait = yes Sat Aug 17 18:20:38 2019 : Debug: program = "/path/to/ntlm_auth --request-nt-key --domain=MYDOMAIN --username=%{mschap:User-Name} --password=%{User-Password}" Sat Aug 17 18:20:38 2019 : Debug: shell_escape = yes Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_pap with path: /usr/lib/freeradius/rlm_pap.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_pap, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_pap Sat Aug 17 18:20:38 2019 : Debug: # Loading module "pap" from file /etc/freeradius/3.0/mods-enabled/pap Sat Aug 17 18:20:38 2019 : Debug: pap { Sat Aug 17 18:20:38 2019 : Debug: normalise = yes Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_passwd with path: /usr/lib/freeradius/rlm_passwd.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_passwd, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_passwd Sat Aug 17 18:20:38 2019 : Debug: # Loading module "etc_passwd" from file /etc/freeradius/3.0/mods-enabled/passwd Sat Aug 17 18:20:38 2019 : Debug: passwd etc_passwd { Sat Aug 17 18:20:38 2019 : Debug: filename = "/etc/passwd" Sat Aug 17 18:20:38 2019 : Debug: format = "*User-Name:Crypt-Password:" Sat Aug 17 18:20:38 2019 : Debug: delimiter = ":" Sat Aug 17 18:20:38 2019 : Debug: ignore_nislike = no Sat Aug 17 18:20:38 2019 : Debug: ignore_empty = yes Sat Aug 17 18:20:38 2019 : Debug: allow_multiple_keys = no Sat Aug 17 18:20:38 2019 : Debug: hash_size = 100 Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_preprocess with path: /usr/lib/freeradius/rlm_preprocess.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_preprocess, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_preprocess Sat Aug 17 18:20:38 2019 : Debug: # Loading module "preprocess" from file /etc/freeradius/3.0/mods-enabled/preprocess Sat Aug 17 18:20:38 2019 : Debug: preprocess { Sat Aug 17 18:20:38 2019 : Debug: huntgroups = "/etc/freeradius/3.0/mods-config/preprocess/huntgroups" Sat Aug 17 18:20:38 2019 : Debug: hints = "/etc/freeradius/3.0/mods-config/preprocess/hints" Sat Aug 17 18:20:38 2019 : Debug: with_ascend_hack = no Sat Aug 17 18:20:38 2019 : Debug: ascend_channels_per_line = 23 Sat Aug 17 18:20:38 2019 : Debug: with_ntdomain_hack = no Sat Aug 17 18:20:38 2019 : Debug: with_specialix_jetstream_hack = no Sat Aug 17 18:20:38 2019 : Debug: with_cisco_vsa_hack = no Sat Aug 17 18:20:38 2019 : Debug: with_alvarion_vsa_hack = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_radutmp with path: /usr/lib/freeradius/rlm_radutmp.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_radutmp, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_radutmp Sat Aug 17 18:20:38 2019 : Debug: # Loading module "radutmp" from file /etc/freeradius/3.0/mods-enabled/radutmp Sat Aug 17 18:20:38 2019 : Debug: radutmp { Sat Aug 17 18:20:38 2019 : Debug: filename = "/var/log/freeradius/radutmp" Sat Aug 17 18:20:38 2019 : Debug: username = "%{User-Name}" Sat Aug 17 18:20:38 2019 : Debug: case_sensitive = yes Sat Aug 17 18:20:38 2019 : Debug: check_with_nas = yes Sat Aug 17 18:20:38 2019 : Debug: permissions = 384 Sat Aug 17 18:20:38 2019 : Debug: caller_id = yes Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_realm with path: /usr/lib/freeradius/rlm_realm.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_realm, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_realm Sat Aug 17 18:20:38 2019 : Debug: # Loading module "IPASS" from file /etc/freeradius/3.0/mods-enabled/realm Sat Aug 17 18:20:38 2019 : Debug: realm IPASS { Sat Aug 17 18:20:38 2019 : Debug: format = "prefix" Sat Aug 17 18:20:38 2019 : Debug: delimiter = "/" Sat Aug 17 18:20:38 2019 : Debug: ignore_default = no Sat Aug 17 18:20:38 2019 : Debug: ignore_null = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "suffix" from file /etc/freeradius/3.0/mods-enabled/realm Sat Aug 17 18:20:38 2019 : Debug: realm suffix { Sat Aug 17 18:20:38 2019 : Debug: format = "suffix" Sat Aug 17 18:20:38 2019 : Debug: delimiter = "@" Sat Aug 17 18:20:38 2019 : Debug: ignore_default = no Sat Aug 17 18:20:38 2019 : Debug: ignore_null = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "realmpercent" from file /etc/freeradius/3.0/mods-enabled/realm Sat Aug 17 18:20:38 2019 : Debug: realm realmpercent { Sat Aug 17 18:20:38 2019 : Debug: format = "suffix" Sat Aug 17 18:20:38 2019 : Debug: delimiter = "%" Sat Aug 17 18:20:38 2019 : Debug: ignore_default = no Sat Aug 17 18:20:38 2019 : Debug: ignore_null = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "ntdomain" from file /etc/freeradius/3.0/mods-enabled/realm Sat Aug 17 18:20:38 2019 : Debug: realm ntdomain { Sat Aug 17 18:20:38 2019 : Debug: format = "prefix" Sat Aug 17 18:20:38 2019 : Debug: delimiter = "\\" Sat Aug 17 18:20:38 2019 : Debug: ignore_default = no Sat Aug 17 18:20:38 2019 : Debug: ignore_null = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_replicate with path: /usr/lib/freeradius/rlm_replicate.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_replicate, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_replicate Sat Aug 17 18:20:38 2019 : Debug: # Loading module "replicate" from file /etc/freeradius/3.0/mods-enabled/replicate Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_soh with path: /usr/lib/freeradius/rlm_soh.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_soh, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_soh Sat Aug 17 18:20:38 2019 : Debug: # Loading module "soh" from file /etc/freeradius/3.0/mods-enabled/soh Sat Aug 17 18:20:38 2019 : Debug: soh { Sat Aug 17 18:20:38 2019 : Debug: dhcp = yes Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "sradutmp" from file /etc/freeradius/3.0/mods-enabled/sradutmp Sat Aug 17 18:20:38 2019 : Debug: radutmp sradutmp { Sat Aug 17 18:20:38 2019 : Debug: filename = "/var/log/freeradius/sradutmp" Sat Aug 17 18:20:38 2019 : Debug: username = "%{User-Name}" Sat Aug 17 18:20:38 2019 : Debug: case_sensitive = yes Sat Aug 17 18:20:38 2019 : Debug: check_with_nas = yes Sat Aug 17 18:20:38 2019 : Debug: permissions = 420 Sat Aug 17 18:20:38 2019 : Debug: caller_id = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_unix with path: /usr/lib/freeradius/rlm_unix.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_unix, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_unix Sat Aug 17 18:20:38 2019 : Debug: # Loading module "unix" from file /etc/freeradius/3.0/mods-enabled/unix Sat Aug 17 18:20:38 2019 : Debug: unix { Sat Aug 17 18:20:38 2019 : Debug: radwtmp = "/var/log/freeradius/radwtmp" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Creating attribute Unix-Group Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_unpack with path: /usr/lib/freeradius/rlm_unpack.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_unpack, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_unpack Sat Aug 17 18:20:38 2019 : Debug: # Loading module "unpack" from file /etc/freeradius/3.0/mods-enabled/unpack Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_utf8 with path: /usr/lib/freeradius/rlm_utf8.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_utf8, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_utf8 Sat Aug 17 18:20:38 2019 : Debug: # Loading module "utf8" from file /etc/freeradius/3.0/mods-enabled/utf8 Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_sql with path: /usr/lib/freeradius/rlm_sql.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_sql, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_sql Sat Aug 17 18:20:38 2019 : Debug: # Loading module "sql" from file /etc/freeradius/3.0/mods-enabled/sql Sat Aug 17 18:20:38 2019 : Debug: sql { Sat Aug 17 18:20:38 2019 : Debug: driver = "rlm_sql_mysql" Sat Aug 17 18:20:38 2019 : Debug: server = "localhost" Sat Aug 17 18:20:38 2019 : Debug: port = 3306 Sat Aug 17 18:20:38 2019 : Debug: login = "root" Sat Aug 17 18:20:38 2019 : Debug: password = "XXXX" Sat Aug 17 18:20:38 2019 : Debug: radius_db = "radius" Sat Aug 17 18:20:38 2019 : Debug: read_groups = yes Sat Aug 17 18:20:38 2019 : Debug: read_profiles = yes Sat Aug 17 18:20:38 2019 : Debug: read_clients = yes Sat Aug 17 18:20:38 2019 : Debug: delete_stale_sessions = yes Sat Aug 17 18:20:38 2019 : Debug: sql_user_name = "%{User-Name}" Sat Aug 17 18:20:38 2019 : Debug: default_user_profile = "" Sat Aug 17 18:20:38 2019 : Debug: client_query = "SELECT id, nasname, shortname, type, secret, server FROM nas" Sat Aug 17 18:20:38 2019 : Debug: authorize_check_query = "SELECT id, username, attribute, value, op FROM radcheck WHERE username = BINARY '%{SQL-User-Name}' ORDER BY id" Sat Aug 17 18:20:38 2019 : Debug: authorize_reply_query = "SELECT id, username, attribute, value, op FROM radreply WHERE username = BINARY '%{SQL-User-Name}' ORDER BY id" Sat Aug 17 18:20:38 2019 : Debug: authorize_group_check_query = "SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id" Sat Aug 17 18:20:38 2019 : Debug: authorize_group_reply_query = "SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id" Sat Aug 17 18:20:38 2019 : Debug: group_membership_query = "SELECT groupname FROM radusergroup WHERE username = BINARY '%{SQL-User-Name}' ORDER BY priority" Sat Aug 17 18:20:38 2019 : Debug: simul_count_query = "SELECT COUNT(*) FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL" Sat Aug 17 18:20:38 2019 : Debug: simul_verify_query = "SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL" Sat Aug 17 18:20:38 2019 : Debug: safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" Sat Aug 17 18:20:38 2019 : Debug: query_timeout = 5 Sat Aug 17 18:20:38 2019 : Debug: accounting { Sat Aug 17 18:20:38 2019 : Debug: reference = "%{tolower:type.%{Acct-Status-Type}.query}" Sat Aug 17 18:20:38 2019 : Debug: type { Sat Aug 17 18:20:38 2019 : Debug: accounting-on { Sat Aug 17 18:20:38 2019 : Debug: query = "UPDATE radacct SET acctstoptime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime = '%{integer:Event-Timestamp}' - UNIX_TIMESTAMP(acctstarttime), acctterminatecause = '%{%{Acct-Terminate-Cause}:-NAS-Reboot}' WHERE acctstoptime IS NULL AND nasipaddress = '%{NAS-IP-Address}' AND acctstarttime <= FROM_UNIXTIME(%{integer:Event-Timestamp})" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: accounting-off { Sat Aug 17 18:20:38 2019 : Debug: query = "UPDATE radacct SET acctstoptime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime = '%{integer:Event-Timestamp}' - UNIX_TIMESTAMP(acctstarttime), acctterminatecause = '%{%{Acct-Terminate-Cause}:-NAS-Reboot}' WHERE acctstoptime IS NULL AND nasipaddress = '%{NAS-IP-Address}' AND acctstarttime <= FROM_UNIXTIME(%{integer:Event-Timestamp})" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: start { Sat Aug 17 18:20:38 2019 : Debug: query = "INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctupdatetime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop,acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{%{NAS-Port-ID}:-%{NAS-Port}}', '%{NAS-Port-Type}', FROM_UNIXTIME(%{integer:Event-Timestamp}), FROM_UNIXTIME(%{integer:Event-Timestamp}), NULL, '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}')" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: interim-update { Sat Aug 17 18:20:38 2019 : Debug: query = "UPDATE radacct SET acctupdatetime = (@acctupdatetime_old:=acctupdatetime), acctupdatetime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctinterval = %{integer:Event-Timestamp} - UNIX_TIMESTAMP(@acctupdatetime_old), framedipaddress = '%{Framed-IP-Address}', acctsessiontime = %{%{Acct-Session-Time}:-NULL}, acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}'" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: stop { Sat Aug 17 18:20:38 2019 : Debug: query = "UPDATE radacct SET acctstoptime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime = %{%{Acct-Session-Time}:-NULL}, acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', acctterminatecause = '%{Acct-Terminate-Cause}', connectinfo_stop = '%{Connect-Info}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}'" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: post-auth { Sat Aug 17 18:20:38 2019 : Debug: reference = ".query" Sat Aug 17 18:20:38 2019 : Debug: query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_sql_mysql with path: /usr/lib/freeradius/rlm_sql_mysql.so Sat Aug 17 18:20:38 2019 : Info: rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked Sat Aug 17 18:20:38 2019 : Debug: Creating attribute SQL-Group Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_sqlcounter with path: /usr/lib/freeradius/rlm_sqlcounter.so Sat Aug 17 18:20:38 2019 : Debug: Loaded rlm_sqlcounter, checking if it's valid Sat Aug 17 18:20:38 2019 : Debug: # Loaded module rlm_sqlcounter Sat Aug 17 18:20:38 2019 : Debug: # Loading module "dailycounter" from file /etc/freeradius/3.0/mods-enabled/sqlcounter Sat Aug 17 18:20:38 2019 : Debug: sqlcounter dailycounter { Sat Aug 17 18:20:38 2019 : Debug: sql_module_instance = "sql" Sat Aug 17 18:20:38 2019 : Debug: key = "User-Name" Sat Aug 17 18:20:38 2019 : Debug: query = "SELECT SUM(acctsessiontime) FROM radacct WHERE username = '%{User-Name}' AND acctstarttime BETWEEN FROM_UNIXTIME('%%b') AND FROM_UNIXTIME('%%e')" Sat Aug 17 18:20:38 2019 : Debug: reset = "daily" Sat Aug 17 18:20:38 2019 : Debug: counter_name = "Daily-Session-Time" Sat Aug 17 18:20:38 2019 : Debug: check_name = "Max-Daily-Session" Sat Aug 17 18:20:38 2019 : Debug: reply_name = "Session-Timeout" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "monthlycounter" from file /etc/freeradius/3.0/mods-enabled/sqlcounter Sat Aug 17 18:20:38 2019 : Debug: sqlcounter monthlycounter { Sat Aug 17 18:20:38 2019 : Debug: sql_module_instance = "sql" Sat Aug 17 18:20:38 2019 : Debug: key = "User-Name" Sat Aug 17 18:20:38 2019 : Debug: query = "SELECT SUM(acctsessiontime - GREATEST((%%b - UNIX_TIMESTAMP(acctstarttime)), 0)) FROM radacct WHERE username='%{User-Name}' AND UNIX_TIMESTAMP(acctstarttime) + acctsessiontime > '%%b'" Sat Aug 17 18:20:38 2019 : Debug: reset = "monthly" Sat Aug 17 18:20:38 2019 : Debug: counter_name = "Monthly-Session-Time" Sat Aug 17 18:20:38 2019 : Debug: check_name = "Max-Monthly-Session" Sat Aug 17 18:20:38 2019 : Debug: reply_name = "Session-Timeout" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "noresetcounter" from file /etc/freeradius/3.0/mods-enabled/sqlcounter Sat Aug 17 18:20:38 2019 : Debug: sqlcounter noresetcounter { Sat Aug 17 18:20:38 2019 : Debug: sql_module_instance = "sql" Sat Aug 17 18:20:38 2019 : Debug: key = "User-Name" Sat Aug 17 18:20:38 2019 : Debug: query = "SELECT IFNULL(SUM(AcctSessionTime),0) FROM radacct WHERE UserName='%{User-Name}'" Sat Aug 17 18:20:38 2019 : Debug: reset = "never" Sat Aug 17 18:20:38 2019 : Debug: counter_name = "Max-All-Session-Time" Sat Aug 17 18:20:38 2019 : Debug: check_name = "Max-All-Session" Sat Aug 17 18:20:38 2019 : Debug: reply_name = "Session-Timeout" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Loading module "expire_on_login" from file /etc/freeradius/3.0/mods-enabled/sqlcounter Sat Aug 17 18:20:38 2019 : Debug: sqlcounter expire_on_login { Sat Aug 17 18:20:38 2019 : Debug: sql_module_instance = "sql" Sat Aug 17 18:20:38 2019 : Debug: key = "User-Name" Sat Aug 17 18:20:38 2019 : Debug: query = "SELECT IFNULL( MAX(TIME_TO_SEC(TIMEDIFF(NOW(), acctstarttime))),0) FROM radacct WHERE UserName='%{User-Name}' ORDER BY acctstarttime LIMIT 1;" Sat Aug 17 18:20:38 2019 : Debug: reset = "never" Sat Aug 17 18:20:38 2019 : Debug: counter_name = "Expire-After-Initial-Login" Sat Aug 17 18:20:38 2019 : Debug: check_name = "Expire-After" Sat Aug 17 18:20:38 2019 : Debug: reply_name = "Session-Timeout" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: instantiate { Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "dailycounter" from file /etc/freeradius/3.0/mods-enabled/sqlcounter Sat Aug 17 18:20:38 2019 : Debug: rlm_sqlcounter: Current Time: 1566058838 [2019-08-17 18:20:38], Prev reset 1565992800 [2019-08-17 00:00:00] Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "reject" from file /etc/freeradius/3.0/mods-enabled/always Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "fail" from file /etc/freeradius/3.0/mods-enabled/always Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "ok" from file /etc/freeradius/3.0/mods-enabled/always Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "handled" from file /etc/freeradius/3.0/mods-enabled/always Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "invalid" from file /etc/freeradius/3.0/mods-enabled/always Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "userlock" from file /etc/freeradius/3.0/mods-enabled/always Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "notfound" from file /etc/freeradius/3.0/mods-enabled/always Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "noop" from file /etc/freeradius/3.0/mods-enabled/always Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "updated" from file /etc/freeradius/3.0/mods-enabled/always Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "attr_filter.post-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter Sat Aug 17 18:20:38 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/post-proxy Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "attr_filter.pre-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter Sat Aug 17 18:20:38 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/pre-proxy Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "attr_filter.access_reject" from file /etc/freeradius/3.0/mods-enabled/attr_filter Sat Aug 17 18:20:38 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/access_reject Sat Aug 17 18:20:38 2019 : Warning: [/etc/freeradius/3.0/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay" found in filter list for realm "DEFAULT". Sat Aug 17 18:20:38 2019 : Warning: [/etc/freeradius/3.0/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay-USec" found in filter list for realm "DEFAULT". Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "attr_filter.access_challenge" from file /etc/freeradius/3.0/mods-enabled/attr_filter Sat Aug 17 18:20:38 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/access_challenge Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "attr_filter.accounting_response" from file /etc/freeradius/3.0/mods-enabled/attr_filter Sat Aug 17 18:20:38 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/accounting_response Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "cache_eap" from file /etc/freeradius/3.0/mods-enabled/cache_eap Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_cache_rbtree with path: /usr/lib/freeradius/rlm_cache_rbtree.so Sat Aug 17 18:20:38 2019 : Debug: rlm_cache (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linked Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "detail" from file /etc/freeradius/3.0/mods-enabled/detail Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "auth_log" from file /etc/freeradius/3.0/mods-enabled/detail.log Sat Aug 17 18:20:38 2019 : Debug: rlm_detail (auth_log): 'User-Password' suppressed, will not appear in detail output Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "reply_log" from file /etc/freeradius/3.0/mods-enabled/detail.log Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "pre_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "post_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "eap" from file /etc/freeradius/3.0/mods-enabled/eap Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_eap_tls with path: /usr/lib/freeradius/rlm_eap_tls.so Sat Aug 17 18:20:38 2019 : Debug: # Linked to sub-module rlm_eap_tls Sat Aug 17 18:20:38 2019 : Debug: tls { Sat Aug 17 18:20:38 2019 : Debug: tls = "tls-common" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: tls-config tls-common { Sat Aug 17 18:20:38 2019 : Debug: verify_depth = 0 Sat Aug 17 18:20:38 2019 : Debug: ca_path = "/etc/freeradius/3.0/certs" Sat Aug 17 18:20:38 2019 : Debug: pem_file_type = yes Sat Aug 17 18:20:38 2019 : Debug: private_key_file = "/etc/ssl/private/server.key" Sat Aug 17 18:20:38 2019 : Debug: certificate_file = "/etc/ssl/private/server.pem" Sat Aug 17 18:20:38 2019 : Debug: ca_file = "/etc/ssl/certs/ca-certificates.crt" Sat Aug 17 18:20:38 2019 : Debug: private_key_password = "whatever" Sat Aug 17 18:20:38 2019 : Debug: dh_file = "/etc/freeradius/3.0/certs/dh" Sat Aug 17 18:20:38 2019 : Debug: fragment_size = 1024 Sat Aug 17 18:20:38 2019 : Debug: include_length = yes Sat Aug 17 18:20:38 2019 : Debug: auto_chain = yes Sat Aug 17 18:20:38 2019 : Debug: check_crl = no Sat Aug 17 18:20:38 2019 : Debug: check_all_crl = no Sat Aug 17 18:20:38 2019 : Debug: cipher_list = "DEFAULT" Sat Aug 17 18:20:38 2019 : Debug: cipher_server_preference = no Sat Aug 17 18:20:38 2019 : Debug: ecdh_curve = "prime256v1" Sat Aug 17 18:20:38 2019 : Debug: tls_max_version = "" Sat Aug 17 18:20:38 2019 : Debug: tls_min_version = "1.0" Sat Aug 17 18:20:38 2019 : Debug: cache { Sat Aug 17 18:20:38 2019 : Debug: enable = no Sat Aug 17 18:20:38 2019 : Debug: lifetime = 24 Sat Aug 17 18:20:38 2019 : Debug: max_entries = 255 Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: verify { Sat Aug 17 18:20:38 2019 : Debug: skip_if_ocsp_ok = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: ocsp { Sat Aug 17 18:20:38 2019 : Debug: enable = no Sat Aug 17 18:20:38 2019 : Debug: override_cert_url = yes Sat Aug 17 18:20:38 2019 : Debug: url = "http://127.0.0.1/ocsp/" Sat Aug 17 18:20:38 2019 : Debug: use_nonce = yes Sat Aug 17 18:20:38 2019 : Debug: timeout = 0 Sat Aug 17 18:20:38 2019 : Debug: softfail = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_eap_ttls with path: /usr/lib/freeradius/rlm_eap_ttls.so Sat Aug 17 18:20:38 2019 : Debug: # Linked to sub-module rlm_eap_ttls Sat Aug 17 18:20:38 2019 : Debug: ttls { Sat Aug 17 18:20:38 2019 : Debug: tls = "tls-common" Sat Aug 17 18:20:38 2019 : Debug: default_eap_type = "md5" Sat Aug 17 18:20:38 2019 : Debug: copy_request_to_tunnel = no Sat Aug 17 18:20:38 2019 : Debug: use_tunneled_reply = yes Sat Aug 17 18:20:38 2019 : Debug: virtual_server = "inner-tunnel" Sat Aug 17 18:20:38 2019 : Debug: include_length = yes Sat Aug 17 18:20:38 2019 : Debug: require_client_cert = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: tls: Using cached TLS configuration from previous invocation Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_eap_peap with path: /usr/lib/freeradius/rlm_eap_peap.so Sat Aug 17 18:20:38 2019 : Debug: # Linked to sub-module rlm_eap_peap Sat Aug 17 18:20:38 2019 : Debug: peap { Sat Aug 17 18:20:38 2019 : Debug: tls = "tls-common" Sat Aug 17 18:20:38 2019 : Debug: default_eap_type = "mschapv2" Sat Aug 17 18:20:38 2019 : Debug: copy_request_to_tunnel = no Sat Aug 17 18:20:38 2019 : Debug: use_tunneled_reply = yes Sat Aug 17 18:20:38 2019 : Debug: proxy_tunneled_request_as_eap = yes Sat Aug 17 18:20:38 2019 : Debug: virtual_server = "inner-tunnel" Sat Aug 17 18:20:38 2019 : Debug: soh = no Sat Aug 17 18:20:38 2019 : Debug: require_client_cert = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: tls: Using cached TLS configuration from previous invocation Sat Aug 17 18:20:38 2019 : Debug: Loading rlm_eap_mschapv2 with path: /usr/lib/freeradius/rlm_eap_mschapv2.so Sat Aug 17 18:20:38 2019 : Debug: # Linked to sub-module rlm_eap_mschapv2 Sat Aug 17 18:20:38 2019 : Debug: mschapv2 { Sat Aug 17 18:20:38 2019 : Debug: with_ntdomain_hack = no Sat Aug 17 18:20:38 2019 : Debug: send_error = no Sat Aug 17 18:20:38 2019 : Debug: identity = "daloradius.marszalkowscy.pl" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "expiration" from file /etc/freeradius/3.0/mods-enabled/expiration Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "files" from file /etc/freeradius/3.0/mods-enabled/files Sat Aug 17 18:20:38 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/files/authorize Sat Aug 17 18:20:38 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/files/accounting Sat Aug 17 18:20:38 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/files/pre-proxy Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "linelog" from file /etc/freeradius/3.0/mods-enabled/linelog Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "log_accounting" from file /etc/freeradius/3.0/mods-enabled/linelog Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "logintime" from file /etc/freeradius/3.0/mods-enabled/logintime Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "mschap" from file /etc/freeradius/3.0/mods-enabled/mschap Sat Aug 17 18:20:38 2019 : Debug: rlm_mschap (mschap): using internal authentication Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "pap" from file /etc/freeradius/3.0/mods-enabled/pap Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "etc_passwd" from file /etc/freeradius/3.0/mods-enabled/passwd Sat Aug 17 18:20:38 2019 : Debug: rlm_passwd: nfields: 3 keyfield 0(User-Name) listable: no Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "preprocess" from file /etc/freeradius/3.0/mods-enabled/preprocess Sat Aug 17 18:20:38 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/preprocess/huntgroups Sat Aug 17 18:20:38 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/preprocess/hints Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "IPASS" from file /etc/freeradius/3.0/mods-enabled/realm Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "suffix" from file /etc/freeradius/3.0/mods-enabled/realm Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "realmpercent" from file /etc/freeradius/3.0/mods-enabled/realm Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "ntdomain" from file /etc/freeradius/3.0/mods-enabled/realm Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "sql" from file /etc/freeradius/3.0/mods-enabled/sql Sat Aug 17 18:20:38 2019 : Info: rlm_sql_mysql: libmysql version: 5.7.27 Sat Aug 17 18:20:38 2019 : Debug: mysql { Sat Aug 17 18:20:38 2019 : Debug: tls { Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: warnings = "auto" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Info: rlm_sql (sql): Attempting to connect to database "radius" Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Using local pool section Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): No pool reference found for config item "sql.pool" Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Initialising connection pool Sat Aug 17 18:20:38 2019 : Debug: pool { Sat Aug 17 18:20:38 2019 : Debug: start = 5 Sat Aug 17 18:20:38 2019 : Debug: min = 3 Sat Aug 17 18:20:38 2019 : Debug: max = 32 Sat Aug 17 18:20:38 2019 : Debug: spare = 10 Sat Aug 17 18:20:38 2019 : Debug: uses = 0 Sat Aug 17 18:20:38 2019 : Debug: lifetime = 0 Sat Aug 17 18:20:38 2019 : Debug: cleanup_interval = 30 Sat Aug 17 18:20:38 2019 : Debug: idle_timeout = 60 Sat Aug 17 18:20:38 2019 : Debug: retry_delay = 30 Sat Aug 17 18:20:38 2019 : Debug: spread = no Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Info: rlm_sql (sql): Opening additional connection (0), 1 of 32 pending slots used Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Starting connect to MySQL server Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.7.27-0ubuntu0.18.04.1, protocol version 10 Sat Aug 17 18:20:38 2019 : Info: rlm_sql (sql): Opening additional connection (1), 1 of 31 pending slots used Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Starting connect to MySQL server Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.7.27-0ubuntu0.18.04.1, protocol version 10 Sat Aug 17 18:20:38 2019 : Info: rlm_sql (sql): Opening additional connection (2), 1 of 30 pending slots used Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Starting connect to MySQL server Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.7.27-0ubuntu0.18.04.1, protocol version 10 Sat Aug 17 18:20:38 2019 : Info: rlm_sql (sql): Opening additional connection (3), 1 of 29 pending slots used Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Starting connect to MySQL server Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.7.27-0ubuntu0.18.04.1, protocol version 10 Sat Aug 17 18:20:38 2019 : Info: rlm_sql (sql): Opening additional connection (4), 1 of 28 pending slots used Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Starting connect to MySQL server Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.7.27-0ubuntu0.18.04.1, protocol version 10 Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Adding pool reference 0x556e9959ea80 to config item "sql.pool" Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Processing generate_sql_clients Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql) in generate_sql_clients: query is SELECT id, nasname, shortname, type, secret, server FROM nas Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Reserved connection (0) Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Executing select query: SELECT id, nasname, shortname, type, secret, server FROM nas Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Adding client 172.16.0.1 (USG) to global clients list Sat Aug 17 18:20:38 2019 : Debug: Adding client 172.16.0.1/32 (172.16.0.1) to prefix tree 32 Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (172.16.0.1): Client "USG" (sql) added Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Adding client 172.16.0.2 (USW-16) to global clients list Sat Aug 17 18:20:38 2019 : Debug: Adding client 172.16.0.2/32 (172.16.0.2) to prefix tree 32 Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (172.16.0.2): Client "USW-16" (sql) added Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Adding client 172.16.0.3 (USW-8) to global clients list Sat Aug 17 18:20:38 2019 : Debug: Adding client 172.16.0.3/32 (172.16.0.3) to prefix tree 32 Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (172.16.0.3): Client "USW-8" (sql) added Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Adding client 172.16.0.4 (Pietro) to global clients list Sat Aug 17 18:20:38 2019 : Debug: Adding client 172.16.0.4/32 (172.16.0.4) to prefix tree 32 Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (172.16.0.4): Client "Pietro" (sql) added Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Adding client 172.16.0.5 (Parter) to global clients list Sat Aug 17 18:20:38 2019 : Debug: Adding client 172.16.0.5/32 (172.16.0.5) to prefix tree 32 Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (172.16.0.5): Client "Parter" (sql) added Sat Aug 17 18:20:38 2019 : Debug: rlm_sql (sql): Released connection (0) Sat Aug 17 18:20:38 2019 : Info: Need 5 more connections to reach 10 spares Sat Aug 17 18:20:38 2019 : Info: rlm_sql (sql): Opening additional connection (5), 1 of 27 pending slots used Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Starting connect to MySQL server Sat Aug 17 18:20:38 2019 : Debug: rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.7.27-0ubuntu0.18.04.1, protocol version 10 Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "monthlycounter" from file /etc/freeradius/3.0/mods-enabled/sqlcounter Sat Aug 17 18:20:38 2019 : Debug: rlm_sqlcounter: Current Time: 1566058838 [2019-08-17 18:20:38], Prev reset 1564610400 [2019-08-01 00:00:00] Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "noresetcounter" from file /etc/freeradius/3.0/mods-enabled/sqlcounter Sat Aug 17 18:20:38 2019 : Debug: rlm_sqlcounter: Current Time: 1566058838 [2019-08-17 18:20:38], Prev reset 0 [2019-08-17 18:00:00] Sat Aug 17 18:20:38 2019 : Debug: # Instantiating module "expire_on_login" from file /etc/freeradius/3.0/mods-enabled/sqlcounter Sat Aug 17 18:20:38 2019 : Debug: rlm_sqlcounter: Current Time: 1566058838 [2019-08-17 18:20:38], Prev reset 0 [2019-08-17 18:00:00] Sat Aug 17 18:20:38 2019 : Debug: } # modules Sat Aug 17 18:20:38 2019 : Debug: radiusd: #### Loading Virtual Servers #### Sat Aug 17 18:20:38 2019 : Debug: server { # from file /etc/freeradius/3.0/radiusd.conf Sat Aug 17 18:20:38 2019 : Debug: } # server Sat Aug 17 18:20:38 2019 : Debug: server DOM { # from file /etc/freeradius/3.0/sites-enabled/default Sat Aug 17 18:20:38 2019 : Debug: authenticate { Sat Aug 17 18:20:38 2019 : Debug: group { Sat Aug 17 18:20:38 2019 : Debug: pap Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: group { Sat Aug 17 18:20:38 2019 : Debug: mschap Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: mschap Sat Aug 17 18:20:38 2019 : Debug: eap Sat Aug 17 18:20:38 2019 : Debug: } # authenticate Sat Aug 17 18:20:38 2019 : Debug: authorize { Sat Aug 17 18:20:38 2019 : Debug: policy filter_username { Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name) { Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ / /) { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: User-Name contains whitespace' Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: reject Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ /@[^@]*@/) { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: Multiple @ in User-Name' Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: reject Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ /\.\./) { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: User-Name contains multiple ..s' Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: reject Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ /@/ && !&User-Name =~ /(a)(.+)\.(.+)$/) { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: Realm does not have at least one dot separator' Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: reject Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ /\.$/) { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: Realm ends with a dot' Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: reject Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ /(a)\./) { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: Realm begins with a dot' Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: reject Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: policy filter_password { Sat Aug 17 18:20:38 2019 : Debug: if (&User-Password && !&User-Password == "%{string:User-Password}") { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &Tmp-String-0 := "%{string:User-Password}" Sat Aug 17 18:20:38 2019 : Debug: &User-Password := "%{string:Tmp-String-0}" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: preprocess Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/sites-enabled/default[309]: Please change attribute reference to '&Huntgroup-Name := ...' Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &Huntgroup-Name := "%{sql:select groupname from radhuntgroup where nasipaddress=\"%{NAS-IP-Address}\"}" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: mschap Sat Aug 17 18:20:38 2019 : Debug: suffix Sat Aug 17 18:20:38 2019 : Debug: eap Sat Aug 17 18:20:38 2019 : Debug: sql Sat Aug 17 18:20:38 2019 : Debug: dailycounter Sat Aug 17 18:20:38 2019 : Debug: expiration Sat Aug 17 18:20:38 2019 : Debug: logintime Sat Aug 17 18:20:38 2019 : Debug: pap Sat Aug 17 18:20:38 2019 : Debug: group { Sat Aug 17 18:20:38 2019 : Debug: sql Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } # authorize Sat Aug 17 18:20:38 2019 : Debug: preacct { Sat Aug 17 18:20:38 2019 : Debug: preprocess Sat Aug 17 18:20:38 2019 : Debug: policy acct_counters64.preacct { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &Acct-Input-Octets64 = "%{expr:(&Acct-Input-Gigawords << 32) | &Acct-Input-Octets}" Sat Aug 17 18:20:38 2019 : Debug: &Acct-Output-Octets64 = "%{expr:(&Acct-Output-Gigawords << 32) | &Acct-Output-Octets}" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &FreeRADIUS-Acct-Session-Start-Time = "%{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}}" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: policy acct_unique { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &Tmp-String-9 := "ai:" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: if ("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/ && "%{string:&Class}" =~ /^ai:([0-9a-f]{32})/) { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &Acct-Unique-Session-Id := "%{md5:%{1},%{Acct-Session-ID}}" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: else { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &Acct-Unique-Session-Id := "%{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: suffix Sat Aug 17 18:20:38 2019 : Debug: } # preacct Sat Aug 17 18:20:38 2019 : Debug: accounting { Sat Aug 17 18:20:38 2019 : Debug: detail Sat Aug 17 18:20:38 2019 : Debug: sql Sat Aug 17 18:20:38 2019 : Debug: exec Sat Aug 17 18:20:38 2019 : Debug: attr_filter.accounting_response Sat Aug 17 18:20:38 2019 : Debug: group { Sat Aug 17 18:20:38 2019 : Debug: sql Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } # accounting Sat Aug 17 18:20:38 2019 : Debug: session { Sat Aug 17 18:20:38 2019 : Debug: sql Sat Aug 17 18:20:38 2019 : Debug: } # session Sat Aug 17 18:20:38 2019 : Debug: post-proxy { Sat Aug 17 18:20:38 2019 : Debug: eap Sat Aug 17 18:20:38 2019 : Debug: } # post-proxy Sat Aug 17 18:20:38 2019 : Debug: post-auth { Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/sites-enabled/default[706]: Please change attribute reference to '&State := ...' Sat Aug 17 18:20:38 2019 : Debug: if (!&reply:State) { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &reply:State := "0x%{randstr:16h}" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &reply:[*] += &session-state:[*] Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: sql Sat Aug 17 18:20:38 2019 : Debug: exec Sat Aug 17 18:20:38 2019 : Debug: policy insert_acct_class { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &reply:Class = "ai:%{md5:%t,%I,%{Packet-Src-Port},%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}},%{NAS-IP-Address},%{Calling-Station-ID},%{User-Name}}" Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/sites-enabled/default[822]: Please change attribute reference to '&EAP-Key-Name := ...' Sat Aug 17 18:20:38 2019 : Debug: if (&reply:EAP-Session-Id) { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &reply:EAP-Key-Name := &reply:EAP-Session-Id Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: policy remove_reply_message_if_eap { Sat Aug 17 18:20:38 2019 : Debug: if (&reply:EAP-Message && &reply:Reply-Message) { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &reply:Reply-Message !* ANY Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: else { Sat Aug 17 18:20:38 2019 : Debug: noop Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: group { Sat Aug 17 18:20:38 2019 : Debug: sql Sat Aug 17 18:20:38 2019 : Debug: attr_filter.access_reject Sat Aug 17 18:20:38 2019 : Debug: eap Sat Aug 17 18:20:38 2019 : Debug: policy remove_reply_message_if_eap { Sat Aug 17 18:20:38 2019 : Debug: if (&reply:EAP-Message && &reply:Reply-Message) { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &reply:Reply-Message !* ANY Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: else { Sat Aug 17 18:20:38 2019 : Debug: noop Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } # post-auth Sat Aug 17 18:20:38 2019 : Debug: } # server DOM Sat Aug 17 18:20:38 2019 : Debug: server inner-tunnel { # from file /etc/freeradius/3.0/sites-enabled/inner-tunnel Sat Aug 17 18:20:38 2019 : Debug: authenticate { Sat Aug 17 18:20:38 2019 : Debug: group { Sat Aug 17 18:20:38 2019 : Debug: pap Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: group { Sat Aug 17 18:20:38 2019 : Debug: mschap Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: mschap Sat Aug 17 18:20:38 2019 : Debug: eap Sat Aug 17 18:20:38 2019 : Debug: } # authenticate Sat Aug 17 18:20:38 2019 : Debug: authorize { Sat Aug 17 18:20:38 2019 : Debug: policy filter_username { Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name) { Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ / /) { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: User-Name contains whitespace' Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: reject Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ /@[^@]*@/) { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: Multiple @ in User-Name' Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: reject Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ /\.\./) { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: User-Name contains multiple ..s' Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: reject Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ /@/ && !&User-Name =~ /(a)(.+)\.(.+)$/) { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: Realm does not have at least one dot separator' Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: reject Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ /\.$/) { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: Realm ends with a dot' Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: reject Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: if (&User-Name =~ /(a)\./) { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &Module-Failure-Message += 'Rejected: Realm begins with a dot' Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: reject Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: mschap Sat Aug 17 18:20:38 2019 : Debug: suffix Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &control:Proxy-To-Realm := LOCAL Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: eap Sat Aug 17 18:20:38 2019 : Debug: sql Sat Aug 17 18:20:38 2019 : Debug: dailycounter Sat Aug 17 18:20:38 2019 : Debug: expiration Sat Aug 17 18:20:38 2019 : Debug: logintime Sat Aug 17 18:20:38 2019 : Debug: pap Sat Aug 17 18:20:38 2019 : Debug: } # authorize Sat Aug 17 18:20:38 2019 : Debug: session { Sat Aug 17 18:20:38 2019 : Debug: sql Sat Aug 17 18:20:38 2019 : Debug: } # session Sat Aug 17 18:20:38 2019 : Debug: post-proxy { Sat Aug 17 18:20:38 2019 : Debug: eap Sat Aug 17 18:20:38 2019 : Debug: } # post-proxy Sat Aug 17 18:20:38 2019 : Debug: post-auth { Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/sites-enabled/inner-tunnel[289]: Please change attribute reference to '&User-Name := ...' Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &reply:User-Name := &User-Name Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: sql Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/sites-enabled/inner-tunnel[343]: Please change attribute reference to '&Message-Authenticator !* ...' Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/sites-enabled/inner-tunnel[344]: Please change attribute reference to '&EAP-Message !* ...' Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/sites-enabled/inner-tunnel[345]: Please change attribute reference to '&Proxy-State !* ...' Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/sites-enabled/inner-tunnel[346]: Please change attribute reference to '&MS-MPPE-Encryption-Types !* ...' Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/sites-enabled/inner-tunnel[347]: Please change attribute reference to '&MS-MPPE-Encryption-Policy !* ...' Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/sites-enabled/inner-tunnel[348]: Please change attribute reference to '&MS-MPPE-Send-Key !* ...' Sat Aug 17 18:20:38 2019 : Warning: /etc/freeradius/3.0/sites-enabled/inner-tunnel[349]: Please change attribute reference to '&MS-MPPE-Recv-Key !* ...' Sat Aug 17 18:20:38 2019 : Debug: if (true) { Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &reply:Message-Authenticator !* ANY Sat Aug 17 18:20:38 2019 : Debug: &reply:EAP-Message !* ANY Sat Aug 17 18:20:38 2019 : Debug: &reply:Proxy-State !* ANY Sat Aug 17 18:20:38 2019 : Debug: &reply:MS-MPPE-Encryption-Types !* ANY Sat Aug 17 18:20:38 2019 : Debug: &reply:MS-MPPE-Encryption-Policy !* ANY Sat Aug 17 18:20:38 2019 : Debug: &reply:MS-MPPE-Send-Key !* ANY Sat Aug 17 18:20:38 2019 : Debug: &reply:MS-MPPE-Recv-Key !* ANY Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &outer.session-state:[*] += &reply:[*] Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: group { Sat Aug 17 18:20:38 2019 : Debug: sql Sat Aug 17 18:20:38 2019 : Debug: attr_filter.access_reject Sat Aug 17 18:20:38 2019 : Debug: update { Sat Aug 17 18:20:38 2019 : Debug: &outer.session-state:Module-Failure-Message := &Module-Failure-Message Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } # post-auth Sat Aug 17 18:20:38 2019 : Debug: } # server inner-tunnel Sat Aug 17 18:20:38 2019 : Debug: server radius-status { # from file /etc/freeradius/3.0/sites-enabled/status Sat Aug 17 18:20:38 2019 : Debug: authorize { Sat Aug 17 18:20:38 2019 : Debug: ok Sat Aug 17 18:20:38 2019 : Debug: group { Sat Aug 17 18:20:38 2019 : Debug: ok Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } # authorize Sat Aug 17 18:20:38 2019 : Debug: accounting { Sat Aug 17 18:20:38 2019 : Debug: ok Sat Aug 17 18:20:38 2019 : Debug: group { Sat Aug 17 18:20:38 2019 : Debug: ok Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } # accounting Sat Aug 17 18:20:38 2019 : Debug: } # server radius-status Sat Aug 17 18:20:38 2019 : Debug: Created signal pipe. Read end FD 13, write end FD 14 Sat Aug 17 18:20:38 2019 : Debug: radiusd: #### Opening IP addresses and Ports #### Sat Aug 17 18:20:38 2019 : Debug: Loading proto_auth with path: /usr/lib/freeradius/proto_auth.so Sat Aug 17 18:20:38 2019 : Debug: Loading proto_auth failed: /usr/lib/freeradius/proto_auth.so: cannot open shared object file: No such file or directory - No such file or directory Sat Aug 17 18:20:38 2019 : Debug: Loading library using linker search path(s) Sat Aug 17 18:20:38 2019 : Debug: Defaults : /lib:/usr/lib Sat Aug 17 18:20:38 2019 : Debug: Failed with error: proto_auth.so: cannot open shared object file: No such file or directory Sat Aug 17 18:20:38 2019 : Debug: listen { Sat Aug 17 18:20:38 2019 : Debug: type = "auth" Sat Aug 17 18:20:38 2019 : Debug: ipaddr = 172.16.0.12 Sat Aug 17 18:20:38 2019 : Debug: port = 1812 Sat Aug 17 18:20:38 2019 : Debug: limit { Sat Aug 17 18:20:38 2019 : Debug: max_connections = 16 Sat Aug 17 18:20:38 2019 : Debug: lifetime = 0 Sat Aug 17 18:20:38 2019 : Debug: idle_timeout = 30 Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Loading proto_acct with path: /usr/lib/freeradius/proto_acct.so Sat Aug 17 18:20:38 2019 : Debug: Loading proto_acct failed: /usr/lib/freeradius/proto_acct.so: cannot open shared object file: No such file or directory - No such file or directory Sat Aug 17 18:20:38 2019 : Debug: Loading library using linker search path(s) Sat Aug 17 18:20:38 2019 : Debug: Defaults : /lib:/usr/lib Sat Aug 17 18:20:38 2019 : Debug: Failed with error: proto_acct.so: cannot open shared object file: No such file or directory Sat Aug 17 18:20:38 2019 : Debug: listen { Sat Aug 17 18:20:38 2019 : Debug: type = "acct" Sat Aug 17 18:20:38 2019 : Debug: ipaddr = 172.16.0.12 Sat Aug 17 18:20:38 2019 : Debug: port = 1813 Sat Aug 17 18:20:38 2019 : Debug: limit { Sat Aug 17 18:20:38 2019 : Debug: max_connections = 16 Sat Aug 17 18:20:38 2019 : Debug: lifetime = 0 Sat Aug 17 18:20:38 2019 : Debug: idle_timeout = 30 Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Loading proto_auth with path: /usr/lib/freeradius/proto_auth.so Sat Aug 17 18:20:38 2019 : Debug: Loading proto_auth failed: /usr/lib/freeradius/proto_auth.so: cannot open shared object file: No such file or directory - No such file or directory Sat Aug 17 18:20:38 2019 : Debug: Loading library using linker search path(s) Sat Aug 17 18:20:38 2019 : Debug: Defaults : /lib:/usr/lib Sat Aug 17 18:20:38 2019 : Debug: Failed with error: proto_auth.so: cannot open shared object file: No such file or directory Sat Aug 17 18:20:38 2019 : Debug: listen { Sat Aug 17 18:20:38 2019 : Debug: type = "auth" Sat Aug 17 18:20:38 2019 : Debug: ipaddr = 127.0.0.1 Sat Aug 17 18:20:38 2019 : Debug: port = 18120 Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Loading proto_status with path: /usr/lib/freeradius/proto_status.so Sat Aug 17 18:20:38 2019 : Debug: Loading proto_status failed: /usr/lib/freeradius/proto_status.so: cannot open shared object file: No such file or directory - No such file or directory Sat Aug 17 18:20:38 2019 : Debug: Loading library using linker search path(s) Sat Aug 17 18:20:38 2019 : Debug: Defaults : /lib:/usr/lib Sat Aug 17 18:20:38 2019 : Debug: Failed with error: proto_status.so: cannot open shared object file: No such file or directory Sat Aug 17 18:20:38 2019 : Debug: listen { Sat Aug 17 18:20:38 2019 : Debug: type = "status" Sat Aug 17 18:20:38 2019 : Debug: ipaddr = 127.0.0.1 Sat Aug 17 18:20:38 2019 : Debug: port = 18121 Sat Aug 17 18:20:38 2019 : Debug: client admin { Sat Aug 17 18:20:38 2019 : Debug: ipaddr = 127.0.0.1 Sat Aug 17 18:20:38 2019 : Debug: require_message_authenticator = no Sat Aug 17 18:20:38 2019 : Debug: secret = "Ametyst3" Sat Aug 17 18:20:38 2019 : Debug: limit { Sat Aug 17 18:20:38 2019 : Debug: max_connections = 16 Sat Aug 17 18:20:38 2019 : Debug: lifetime = 0 Sat Aug 17 18:20:38 2019 : Debug: idle_timeout = 30 Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Adding client 127.0.0.1/32 (127.0.0.1) to prefix tree 32 Sat Aug 17 18:20:38 2019 : Debug: client router { Sat Aug 17 18:20:38 2019 : Debug: ipaddr = 172.16.0.1 Sat Aug 17 18:20:38 2019 : Debug: require_message_authenticator = no Sat Aug 17 18:20:38 2019 : Debug: secret = "Ametyst3" Sat Aug 17 18:20:38 2019 : Debug: limit { Sat Aug 17 18:20:38 2019 : Debug: max_connections = 16 Sat Aug 17 18:20:38 2019 : Debug: lifetime = 0 Sat Aug 17 18:20:38 2019 : Debug: idle_timeout = 30 Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Adding client 172.16.0.1/32 (172.16.0.1) to prefix tree 32 Sat Aug 17 18:20:38 2019 : Debug: client switch { Sat Aug 17 18:20:38 2019 : Debug: ipaddr = 172.16.0.2 Sat Aug 17 18:20:38 2019 : Debug: require_message_authenticator = no Sat Aug 17 18:20:38 2019 : Debug: secret = "Ametyst3" Sat Aug 17 18:20:38 2019 : Debug: limit { Sat Aug 17 18:20:38 2019 : Debug: max_connections = 16 Sat Aug 17 18:20:38 2019 : Debug: lifetime = 0 Sat Aug 17 18:20:38 2019 : Debug: idle_timeout = 30 Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Adding client 172.16.0.2/32 (172.16.0.2) to prefix tree 32 Sat Aug 17 18:20:38 2019 : Debug: } Sat Aug 17 18:20:38 2019 : Debug: Listening on auth address 172.16.0.12 port 1812 bound to server DOM Sat Aug 17 18:20:38 2019 : Debug: Listening on acct address 172.16.0.12 port 1813 bound to server DOM Sat Aug 17 18:20:38 2019 : Debug: Listening on auth address 127.0.0.1 port 18120 bound to server inner-tunnel Sat Aug 17 18:20:38 2019 : Debug: Listening on status address 127.0.0.1 port 18121 bound to server radius-status Sat Aug 17 18:20:38 2019 : Debug: Opened new proxy socket 'proxy address * port 44003' Sat Aug 17 18:20:38 2019 : Debug: Listening on proxy address * port 44003 Sat Aug 17 18:20:38 2019 : Info: Ready to process requests ————————————— On top of that I have a problems with accounting, it seems like NAS doesn’t like Gigawords - quite often reports 4GB up and down. More often it happens when session is longer than shorter. Is there any any fix available on Freeradius side? Ubiquiti claims https://help.ubnt.com/hc/en-us/articles/115005255907-UniFi-Hotspot-RADIUS-A… their APs should be working with this attribute. NAS it is Unifi AP AC Pro. So, where do I need to troubleshoot, Freeradius or NAS? While looking at tcpdump on port 1812 I can see lengthy negotiation: multiple access requests and access challenges (12 times) followed finally by access accept... I don't know how many requests and challenges should be there. Thanks in advance!

3 7

Migrating FR 3.0.19 from using WINBIND to LDAP for AD auth
by WAGHORN, Jason (NHS BORDERS) 19 Aug '19

19 Aug '19

Hello all I'm planning to migrate the AD authentication method we use from WINBIND/NTLM_AUTH to LDAP to be able to control who has access to use devices. I'm sensing that the way to do this is to disable the ntlm_auth module, configure the ldap module, enable the ldap module and then modify the site config to use ldap instead of ntlm_auth? Has anyone else done it and have a set of steps to follow that they are willing to share? Just trying to avoid reinventing the wheel. Thanks in advance ******************************************************************************************************************** This message may contain confidential information. If you are not the intended recipient please inform the sender that you have received the message in error before deleting it. Please do not disclose, copy or distribute information in this e-mail or take any action in relation to its contents. To do so is strictly prohibited and may be unlawful. Thank you for your co-operation. NHSmail is the secure email and directory service available for all NHS staff in England and Scotland. NHSmail is approved for exchanging patient data and other sensitive information with NHSmail and other accredited email services. For more information and to find out how you can switch, https://portal.nhs.net/help/joiningnhsmail

3 5

eapol_test to windows NPS server
by Munroe Sollog 16 Aug '19

16 Aug '19

I am trying to do benchmarking between windows NPS and FreeRADIUS. I want to use eapol_test to compare response times. Here is the eapol_test command I run: eapol_test -c eapoltest.conf -a 128.180.0.201 -scisco99 -M00:0a:cd:31:6c:b4 -N4:x:0x80B40A0A -o radiuscert.out And here is the output I get from eapol_test. The windows NPS server is currently production and is configured to support PEAP and MSCHAPv2, but I don't know why eapol_test won't succeed. Here is the output from eapol_test: Reading configuration file 'eapoltest.conf' Line: 1 - start of a new network block ssid - hexdump_ascii(len=6): 6c 65 68 69 67 68 lehigh key_mgmt: 0x1 eap methods - hexdump(len=16): 00 00 00 00 19 00 00 00 00 00 00 00 00 00 00 00 identity - hexdump_ascii(len=6): 78 31 39 61 31 39 x19a19 password - hexdump_ascii(len=8): ** ** ** ** ** ** ** ** ********* phase2 - hexdump_ascii(len=16): 61 75 74 68 65 61 70 3d 4d 53 43 48 41 50 56 32 autheap=MSCHAPV2 Priority group 0 id=0 ssid='lehigh' Authentication server 128.180.0.201:1812 RADIUS local address: 128.180.10.10:33379 ENGINE: Loading dynamic engine ENGINE: Loading dynamic engine EAPOL: SUPP_PAE entering state DISCONNECTED EAPOL: KEY_RX entering state NO_KEY_RECEIVE EAPOL: SUPP_BE entering state INITIALIZE EAP: EAP entering state DISABLED EAPOL: External notification - portValid=0 EAPOL: External notification - portEnabled=1 EAPOL: SUPP_PAE entering state CONNECTING EAPOL: SUPP_BE entering state IDLE EAP: EAP entering state INITIALIZE EAP: EAP entering state IDLE Sending fake EAP-Request-Identity EAPOL: Received EAP-Packet frame EAPOL: SUPP_PAE entering state RESTART EAP: EAP entering state INITIALIZE EAP: EAP entering state IDLE EAPOL: SUPP_PAE entering state AUTHENTICATING EAPOL: SUPP_BE entering state REQUEST EAPOL: getSuppRsp EAP: EAP entering state RECEIVED EAP: Received EAP-Request id=112 method=1 vendor=0 vendorMethod=0 EAP: EAP entering state IDENTITY CTRL-EVENT-EAP-STARTED EAP authentication started EAP: Status notification: started (param=) EAP: EAP-Request Identity data - hexdump_ascii(len=0): EAP: using real identity - hexdump_ascii(len=6): 78 31 39 61 31 39 x19a19 EAP: EAP entering state SEND_RESPONSE EAP: EAP entering state IDLE EAPOL: SUPP_BE entering state RESPONSE EAPOL: txSuppRsp WPA: eapol_test_eapol_send(type=0 len=11) TX EAP -> RADIUS - hexdump(len=11): 02 70 00 0b 01 78 31 39 61 31 39 Encapsulating EAP message into a RADIUS packet Learned identity from EAP-Response-Identity - hexdump(len=6): 78 31 39 61 31 39 Sending RADIUS message to authentication server RADIUS message: code=1 (Access-Request) identifier=0 length=126 Attribute 1 (User-Name) length=8 Value: 'x19a19' Attribute 31 (Calling-Station-Id) length=19 Value: '00-0A-CD-31-6C-B4' Attribute 12 (Framed-MTU) length=6 Value: 1400 Attribute 61 (NAS-Port-Type) length=6 Value: 19 Attribute 6 (Service-Type) length=6 Value: 2 Attribute 77 (Connect-Info) length=24 Value: 'CONNECT 11Mbps 802.11b' Attribute 4 (NAS-IP-Address) length=6 Value: 128.180.10.10 Attribute 79 (EAP-Message) length=13 Value: 0270000b01783139613139 Attribute 80 (Message-Authenticator) length=18 Value: 2cb6acbe8e4307370336c32d6317e232 Next RADIUS client retransmit in 3 seconds EAPOL: SUPP_BE entering state RECEIVE Received 90 bytes from RADIUS server Received RADIUS message RADIUS message: code=11 (Access-Challenge) identifier=0 length=90 Attribute 27 (Session-Timeout) length=6 Value: 30 Attribute 79 (EAP-Message) length=8 Value: 017100061920 Attribute 24 (State) length=38 Value: 375c0381000001370001020080b400c9000000000000000000000000000000047a7d2b22 Attribute 80 (Message-Authenticator) length=18 Value: a4b113411c1213c4c4aac3932f16ed43 STA 00:0a:cd:31:6c:b4: Received RADIUS packet matched with a pending request, round trip time 0.00 sec RADIUS packet matching with station decapsulated EAP packet (code=1 id=113 len=6) from RADIUS server: EAP-Request-PEAP (25) EAPOL: Received EAP-Packet frame EAPOL: SUPP_BE entering state REQUEST EAPOL: getSuppRsp EAP: EAP entering state RECEIVED EAP: Received EAP-Request id=113 method=25 vendor=0 vendorMethod=0 EAP: EAP entering state GET_METHOD CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=25 EAP: Status notification: accept proposed method (param=PEAP) EAP: Initialize selected EAP method: vendor 0 method 25 (PEAP) TLS: Phase2 EAP types - hexdump(len=128): 00 00 00 00 04 00 00 00 00 00 00 00 1a 00 00 00 00 00 00 00 06 00 00 00 00 00 00 00 05 00 00 00 00 00 00 00 12 00 00 00 00 00 00 00 11 00 00 00 00 00 00 00 2f 00 00 00 00 00 00 00 17 00 00 00 00 00 00 00 32 00 00 00 00 00 00 00 2e 00 00 00 00 00 00 00 30 00 00 00 00 00 00 00 33 00 00 00 00 00 00 00 31 00 00 00 00 00 00 00 26 00 00 00 00 00 00 00 34 00 00 00 00 00 00 00 35 00 00 00 TLS: using phase1 config options CTRL-EVENT-EAP-METHOD EAP vendor 0 method 25 (PEAP) selected EAP: EAP entering state METHOD SSL: Received packet(len=6) - Flags 0x20 EAP-PEAP: Start (server ver=0, own ver=1) EAP-PEAP: Using PEAP version 0 SSL: (where=0x10 ret=0x1) SSL: (where=0x1001 ret=0x1) SSL: SSL_connect:before SSL initialization OpenSSL: TX ver=0x0 content_type=256 (TLS header info/) OpenSSL: Message - hexdump(len=5): 16 03 01 00 b3 OpenSSL: TX ver=0x303 content_type=22 (handshake/client hello) OpenSSL: Message - hexdump(len=179): 01 00 00 af 03 03 0f 09 6c 9f 91 c0 23 81 53 11 27 f5 91 6c 3e c2 ce 09 b2 96 6c 74 09 dc d2 ea 60 9b 80 04 01 6e 00 00 38 c0 2c c0 30 00 9f cc a9 cc a8 cc aa c0 2b c0 2f 00 9e c0 24 c0 28 00 6b c0 23 c0 27 00 67 c0 0a c0 14 00 39 c0 09 c0 13 00 33 00 9d 00 9c 00 3d 00 3c 00 35 00 2f 00 ff 01 00 00 4e 00 0b 00 04 03 00 01 02 00 0a 00 0c 00 0a 00 1d 00 17 00 1e 00 19 00 18 00 16 00 00 00 17 00 00 00 0d 00 2a 00 28 04 03 05 03 06 03 08 07 08 08 08 09 08 0a 08 0b 08 04 08 05 08 06 04 01 05 01 06 01 03 03 03 01 03 02 04 02 05 02 06 02 SSL: (where=0x1001 ret=0x1) SSL: SSL_connect:SSLv3/TLS write client hello SSL: (where=0x1002 ret=0xffffffff) SSL: SSL_connect:error in SSLv3/TLS write client hello SSL: SSL_connect - want more data SSL: 184 bytes pending from ssl_out SSL: Using TLS version TLSv1.2 SSL: 184 bytes left to be sent out (of total 184 bytes) EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x557648f9d820 EAP: EAP entering state SEND_RESPONSE EAP: EAP entering state IDLE EAPOL: SUPP_BE entering state RESPONSE EAPOL: txSuppRsp WPA: eapol_test_eapol_send(type=0 len=194) TX EAP -> RADIUS - hexdump(len=194): 02 71 00 c2 19 80 00 00 00 b8 16 03 01 00 b3 01 00 00 af 03 03 0f 09 6c 9f 91 c0 23 81 53 11 27 f5 91 6c 3e c2 ce 09 b2 96 6c 74 09 dc d2 ea 60 9b 80 04 01 6e 00 00 38 c0 2c c0 30 00 9f cc a9 cc a8 cc aa c0 2b c0 2f 00 9e c0 24 c0 28 00 6b c0 23 c0 27 00 67 c0 0a c0 14 00 39 c0 09 c0 13 00 33 00 9d 00 9c 00 3d 00 3c 00 35 00 2f 00 ff 01 00 00 4e 00 0b 00 04 03 00 01 02 00 0a 00 0c 00 0a 00 1d 00 17 00 1e 00 19 00 18 00 16 00 00 00 17 00 00 00 0d 00 2a 00 28 04 03 05 03 06 03 08 07 08 08 08 09 08 0a 08 0b 08 04 08 05 08 06 04 01 05 01 06 01 03 03 03 01 03 02 04 02 05 02 06 02 Encapsulating EAP message into a RADIUS packet Copied RADIUS State Attribute Sending RADIUS message to authentication server RADIUS message: code=1 (Access-Request) identifier=1 length=347 Attribute 1 (User-Name) length=8 Value: 'x19a19' Attribute 31 (Calling-Station-Id) length=19 Value: '00-0A-CD-31-6C-B4' Attribute 12 (Framed-MTU) length=6 Value: 1400 Attribute 61 (NAS-Port-Type) length=6 Value: 19 Attribute 6 (Service-Type) length=6 Value: 2 Attribute 77 (Connect-Info) length=24 Value: 'CONNECT 11Mbps 802.11b' Attribute 4 (NAS-IP-Address) length=6 Value: 128.180.10.10 Attribute 79 (EAP-Message) length=196 Value: 027100c21980000000b816030100b3010000af03030f096c9f91c02381531127f5916c3ec2ce09b2966c7409dcd2ea609b8004016e000038c02cc030009fcca9cca8ccaac02bc02f009ec024c028006bc023c0270067c00ac0140039c009c0130033009d009c003d003c0035002f00ff0100004e000b000403000102000a000c000a001d0017001e001900180016000000170000000d002a0028040305030603080708080809080a080b080408050806040105010601030303010302040205020602 Attribute 24 (State) length=38 Value: 375c0381000001370001020080b400c9000000000000000000000000000000047a7d2b22 Attribute 80 (Message-Authenticator) length=18 Value: 8ef1902078ef0fe0e80ba5f6043c626f Next RADIUS client retransmit in 3 seconds EAPOL: SUPP_BE entering state RECEIVE Received 1490 bytes from RADIUS server Received RADIUS message RADIUS message: code=11 (Access-Challenge) identifier=1 length=1490 Attribute 27 (Session-Timeout) length=6 Value: 30 Attribute 79 (EAP-Message) length=255 Value: 0172057419c000000d651603010d600200005103015d56e120e60c72bdb7acc0194d9151d8bb5ddf3a82da654a33d81d75be0abf5220343700008de6f94e11d5f0b4c49eb6e2a665b943043e52a5914d94e81d06c935c01400000900170000ff010001000b000bae000bab0006d1308206cd308205b5a003020102020900db1a19314917ce76300d06092a864886f70d01010b05003081b4310b30090603550406130255533110300e060355040813074172697a6f6e61311330110603550407130a53636f74747364616c65311a3018060355040a1311476f44616464792e636f6d2c20496e632e312d302b060355040b1324687474703a2f2f636572 Attribute 79 (EAP-Message) length=255 Value: 74732e676f64616464792e636f6d2f7265706f7369746f72792f313330310603550403132a476f2044616464792053656375726520436572746966696361746520417574686f72697479202d204732301e170d3139303730383135313033355a170d3231303730383135313033355a30433121301f060355040b1318446f6d61696e20436f6e74726f6c2056616c696461746564311e301c06035504031315726164697573322e63632e6c65686967682e65647530820122300d06092a864886f70d01010105000382010f003082010a0282010100c9408040cf62e327123e2664416a14df9cc3c8f11c1e0d513d14af37e490fe0135616f542f6e1f31 Attribute 79 (EAP-Message) length=255 Value: 57f55eb00549515e1dcd22bff3e4584bf7f38dece2f37764a801deeb1edeac623ad6b9991a89acda55584ffc03327bc03c5fa0bea7a68f25535c6fefddf8c396ce4899d62eb626478bace12899b66d18660bd403f808545b4925f19c1d2fe6c8b6fc7a5d79cb49d9008dd8de5e84015fcda755e17d34c0c0a5610d62640d218c122d56a7ff60e0bc954b9576f9010483daee9ee85545cbe25068e5465e4e62461d573cbee2f167c2b4c03b093610b7719136f332701cacd981c1ce8e637b5fc79fdd4f33d9966c0408f56e17daf617678185f18b37d49ef30203010001a38203503082034c300c0603551d130101ff04023000301d0603551d25041630 Attribute 79 (EAP-Message) length=255 Value: 1406082b0601050507030106082b06010505070302300e0603551d0f0101ff0404030205a030380603551d1f0431302f302da02ba0298627687474703a2f2f63726c2e676f64616464792e636f6d2f676469673273312d313232322e63726c305d0603551d20045630543048060b6086480186fd6d010717013039303706082b06010505070201162b687474703a2f2f6365727469666963617465732e676f64616464792e636f6d2f7265706f7369746f72792f3008060667810c010201307606082b06010505070101046a3068302406082b060105050730018618687474703a2f2f6f6373702e676f64616464792e636f6d2f304006082b06010505 Attribute 79 (EAP-Message) length=255 Value: 0730028634687474703a2f2f6365727469666963617465732e676f64616464792e636f6d2f7265706f7369746f72792f67646967322e637274301f0603551d2304183016801440c2bd278ecc348330a233d7fb6cb3f0b42c80ce303b0603551d11043430328215726164697573322e63632e6c65686967682e65647582197777772e726164697573322e63632e6c65686967682e656475301d0603551d0e04160414847ddc2ce7a9ad4595209491a1bb48a2691031123082017d060a2b06010401d6790204020482016d048201690167007600a4b90990b418581487bb13a2cc67700a3c359804f91bdfb8e377cd0ec80ddc100000016bd222fc1e0000 Attribute 79 (EAP-Message) length=133 Value: 040300473045022100d9b721a659b1c9814364e1e4925044630ad56e8e5a1f19745f5fdee4c89453320220172d5b5271f2bb0411c80e9f8ed181f146609260b2701236936a26c41549e7e5007600ee4bbdb775ce60bae142691fabe19e66a30f7e5fb072d88300c47b897aa8fdcb0000016bd22301f100000403004730450221009eb2 Attribute 24 (State) length=38 Value: 375c0381000001370001020080b400c9000000000000000000000000000000047a7d2b22 Attribute 80 (Message-Authenticator) length=18 Value: 2103eb7edcd69a5da7c7dfdc5fc4df10 STA 00:0a:cd:31:6c:b4: Received RADIUS packet matched with a pending request, round trip time 0.00 sec RADIUS packet matching with station decapsulated EAP packet (code=1 id=114 len=1396) from RADIUS server: EAP-Request-PEAP (25) EAPOL: Received EAP-Packet frame EAPOL: SUPP_BE entering state REQUEST EAPOL: getSuppRsp EAP: EAP entering state RECEIVED EAP: Received EAP-Request id=114 method=25 vendor=0 vendorMethod=0 EAP: EAP entering state METHOD SSL: Received packet(len=1396) - Flags 0xc0 SSL: TLS Message Length: 3429 SSL: Need 2043 bytes more input data SSL: Building ACK (type=25 id=114 ver=0) EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x557648f8b1d0 EAP: EAP entering state SEND_RESPONSE EAP: EAP entering state IDLE EAPOL: SUPP_BE entering state RESPONSE EAPOL: txSuppRsp WPA: eapol_test_eapol_send(type=0 len=6) TX EAP -> RADIUS - hexdump(len=6): 02 72 00 06 19 00 Encapsulating EAP message into a RADIUS packet Copied RADIUS State Attribute Sending RADIUS message to authentication server RADIUS message: code=1 (Access-Request) identifier=2 length=159 Attribute 1 (User-Name) length=8 Value: 'x19a19' Attribute 31 (Calling-Station-Id) length=19 Value: '00-0A-CD-31-6C-B4' Attribute 12 (Framed-MTU) length=6 Value: 1400 Attribute 61 (NAS-Port-Type) length=6 Value: 19 Attribute 6 (Service-Type) length=6 Value: 2 Attribute 77 (Connect-Info) length=24 Value: 'CONNECT 11Mbps 802.11b' Attribute 4 (NAS-IP-Address) length=6 Value: 128.180.10.10 Attribute 79 (EAP-Message) length=8 Value: 027200061900 Attribute 24 (State) length=38 Value: 375c0381000001370001020080b400c9000000000000000000000000000000047a7d2b22 Attribute 80 (Message-Authenticator) length=18 Value: 1d80fce9f3c7b0301b3c786f0be6911f Next RADIUS client retransmit in 3 seconds EAPOL: SUPP_BE entering state RECEIVE Received 1490 bytes from RADIUS server Received RADIUS message RADIUS message: code=11 (Access-Challenge) identifier=2 length=1490 Attribute 27 (Session-Timeout) length=6 Value: 30 Attribute 79 (EAP-Message) length=255 Value: 017305741940b52c901b66f2d9c920718f5f912326aa49501111291c82967c022baec34f022010edd6a465d62d5c897ee16abdbe3b6e0afa95de34d5b59370f4f279593503710075004494652eb0eeceafc44007d8a8fe28c0dae682bed8cb31b53fd33396b5b681a80000016bd22306cb0000040300463044022047a3daf3f686baf1d5788b2dc97cbf2894675bbb2bf5c839f56a7d06b2a6c630022003b93b96a997d3ddedd0a12f556962df88cc0eb12c75a7502dabf7cccb51fb64300d06092a864886f70d01010b0500038201010069c9c7d22bd68c0b555ba812f31bec37387304905cbdf2cd4e4c1986f7de5fe0f4ecbf8f5101bca7570966b7 Attribute 79 (EAP-Message) length=255 Value: b235c5b65f067351749998e6de7a0e1c783bf2dc264e663671f727e3695236802be428bfde7f53e12550fc747f3b98a5a14ec51d1f404cb39b58f9951d4d796a66647ea3c2a9e6c6ddd9db775964157946128074d0a99d10f645b6bfb48558213ab50e82064f8966a6288d00881d7156b04636ce248d3131357169bed8c3b431e91690373816c6681e8c35963577052f0c767b6001d4ee682dc508c4fe9a716041349227a9dbf403415cc71a0cc567c25b9fd9ac9957a8725c441e5f8d91282a4ffb67ca9a40d6ff57ec05266aadefb406fcff250004d4308204d0308203b8a003020102020107300d06092a864886f70d01010b0500308183310b3009 Attribute 79 (EAP-Message) length=255 Value: 0603550406130255533110300e060355040813074172697a6f6e61311330110603550407130a53636f74747364616c65311a3018060355040a1311476f44616464792e636f6d2c20496e632e3131302f06035504031328476f20446164647920526f6f7420436572746966696361746520417574686f72697479202d204732301e170d3131303530333037303030305a170d3331303530333037303030305a3081b4310b30090603550406130255533110300e060355040813074172697a6f6e61311330110603550407130a53636f74747364616c65311a3018060355040a1311476f44616464792e636f6d2c20496e632e312d302b060355040b1324 Attribute 79 (EAP-Message) length=255 Value: 687474703a2f2f63657274732e676f64616464792e636f6d2f7265706f7369746f72792f313330310603550403132a476f2044616464792053656375726520436572746966696361746520417574686f72697479202d20473230820122300d06092a864886f70d01010105000382010f003082010a0282010100b9e0cb10d4af76bdd49362eb3064b881086cc304d962178e2fff3e65cf8fce62e63c521cda16454b55ab786b63836290ce0f696c99c81a148b4ccc4533ea88dc9ea3af2bfe80619d7957c4cf2ef43f303c5d47fc9a16bcc3379641518e114b54f828bed08cbef030381ef3b026f86647636dde7126478f384753d1461db4e3dc00ea45 Attribute 79 (EAP-Message) length=255 Value: acbdbc71d9aa6f00dbdbcd303a794f5f4c47f81def5bc2c49d603bb1b24391d8a4334eeab3d6274fad258aa5c6f4d5d0a6ae7405645788b54455d42d2a3a3ef8b8bde9320a029464c4163a50f14aaee77933af0c20077fe8df0439c269026c6352fa77c11bc87487c8b993185054354b694ebc3bd3492e1fdcc1d252fb0203010001a382011a30820116300f0603551d130101ff040530030101ff300e0603551d0f0101ff040403020106301d0603551d0e0416041440c2bd278ecc348330a233d7fb6cb3f0b42c80ce301f0603551d230418301680143a9a8507106728b6eff6bd05416e20c194da0fde303406082b06010505070101042830263024 Attribute 79 (EAP-Message) length=133 Value: 06082b060105050730018618687474703a2f2f6f6373702e676f64616464792e636f6d2f30350603551d1f042e302c302aa028a0268624687474703a2f2f63726c2e676f64616464792e636f6d2f6764726f6f742d67322e63726c30460603551d20043f303d303b0604551d20003033303106082b0601050507020116256874747073 Attribute 24 (State) length=38 Value: 375c0381000001370001020080b400c9000000000000000000000000000000047a7d2b22 Attribute 80 (Message-Authenticator) length=18 Value: 9b73dee8d8442c870905f76592671b56 STA 00:0a:cd:31:6c:b4: Received RADIUS packet matched with a pending request, round trip time 0.00 sec RADIUS packet matching with station decapsulated EAP packet (code=1 id=115 len=1396) from RADIUS server: EAP-Request-PEAP (25) EAPOL: Received EAP-Packet frame EAPOL: SUPP_BE entering state REQUEST EAPOL: getSuppRsp EAP: EAP entering state RECEIVED EAP: Received EAP-Request id=115 method=25 vendor=0 vendorMethod=0 EAP: EAP entering state METHOD SSL: Received packet(len=1396) - Flags 0x40 SSL: Need 653 bytes more input data SSL: Building ACK (type=25 id=115 ver=0) EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x557648f8b1d0 EAP: EAP entering state SEND_RESPONSE EAP: EAP entering state IDLE EAPOL: SUPP_BE entering state RESPONSE EAPOL: txSuppRsp WPA: eapol_test_eapol_send(type=0 len=6) TX EAP -> RADIUS - hexdump(len=6): 02 73 00 06 19 00 Encapsulating EAP message into a RADIUS packet Copied RADIUS State Attribute Sending RADIUS message to authentication server RADIUS message: code=1 (Access-Request) identifier=3 length=159 Attribute 1 (User-Name) length=8 Value: 'x19a19' Attribute 31 (Calling-Station-Id) length=19 Value: '00-0A-CD-31-6C-B4' Attribute 12 (Framed-MTU) length=6 Value: 1400 Attribute 61 (NAS-Port-Type) length=6 Value: 19 Attribute 6 (Service-Type) length=6 Value: 2 Attribute 77 (Connect-Info) length=24 Value: 'CONNECT 11Mbps 802.11b' Attribute 4 (NAS-IP-Address) length=6 Value: 128.180.10.10 Attribute 79 (EAP-Message) length=8 Value: 027300061900 Attribute 24 (State) length=38 Value: 375c0381000001370001020080b400c9000000000000000000000000000000047a7d2b22 Attribute 80 (Message-Authenticator) length=18 Value: 023c8597c71c082a795527eeb03816b0 Next RADIUS client retransmit in 3 seconds EAPOL: SUPP_BE entering state RECEIVE Received 747 bytes from RADIUS server Received RADIUS message RADIUS message: code=11 (Access-Challenge) identifier=3 length=747 Attribute 27 (Session-Timeout) length=6 Value: 30 Attribute 79 (EAP-Message) length=255 Value: 0174029319003a2f2f63657274732e676f64616464792e636f6d2f7265706f7369746f72792f300d06092a864886f70d01010b05000382010100087e6c9310c838b896a9904bffa15f4f04ef6c3e9c8806c9508fa673f757311bbebce42fdbf8bad35be0b4e7e679620e0ca2d76a637331b5f5a848a43b082da25d90d7b47c254f115630c4b6449d7b2c9de55ee6ef0c61aabfe42a1bee849eb8837dc143ce44a713700d911ff4c813ad8360d9d872a873241eb5ac220eca17896258441bab892501000fcdc41b62db51b4d30f512a9bf4bc73fc76ce36a4cdd9d82ceaae9bf52ab290d14d75188a3f8a4190237d5b4bfea403589b46b2c3606083f87d Attribute 79 (EAP-Message) length=255 Value: 5041cec2a190c3bbef022fd21554ee4415d90aaea78a33edb12d763626dc04eb9ff7611f15dc876fee469628ada1267d0a09a72e04a38dbcf8bc0430010c00014703001741048e3db331e536504aec9207f9a32799a86cf01092f7cf39ae0f315fe4a629677164d32f1bb19f4a53e039fb49959dcdec612f8e601a959c5de7b65edee9ac3ccc0100a1aa947ff0002fc9a8e89c6d66d9f94c9123ff13e5fd9d273cc63aa734e0f9b4d10da2108dc993b979c01ee44c217c99d7e5ef34e0fcb1a972e158f8adac61669fc71e54c664274a67368aa750aac42d22fc48b0208b08c84d1894f785d6088b0fc2ec151a53b0366ebbe9aa87c6d34ebe81ab63d8 Attribute 79 (EAP-Message) length=155 Value: a39b7e2b3cef1b12bdbd3ab4a44eeab2eec6ab00a923eb6579931a68dad9accaf188660b6c242bdaeb9359c4d3dc2d45f0f6693a8d8ff4c407779cfe4dbf20d6a3a9f63249326e36a6e84bc1a1b6e710c26de0ea22dfc77482249c4183826dd9b83bf0b03ca91e008d67fed62b824b75f665269cface044320f3835ab6b717076ebe0add91329942c264d10d0000060301024000000e000000 Attribute 24 (State) length=38 Value: 375c0381000001370001020080b400c9000000000000000000000000000000047a7d2b22 Attribute 80 (Message-Authenticator) length=18 Value: b0baa8d2a81b7522920e43e349afaeaf STA 00:0a:cd:31:6c:b4: Received RADIUS packet matched with a pending request, round trip time 0.00 sec RADIUS packet matching with station decapsulated EAP packet (code=1 id=116 len=659) from RADIUS server: EAP-Request-PEAP (25) EAPOL: Received EAP-Packet frame EAPOL: SUPP_BE entering state REQUEST EAPOL: getSuppRsp EAP: EAP entering state RECEIVED EAP: Received EAP-Request id=116 method=25 vendor=0 vendorMethod=0 EAP: EAP entering state METHOD SSL: Received packet(len=659) - Flags 0x00 OpenSSL: RX ver=0x0 content_type=256 (TLS header info/) OpenSSL: Message - hexdump(len=5): 16 03 01 0d 60 SSL: (where=0x1001 ret=0x1) SSL: SSL_connect:SSLv3/TLS write client hello OpenSSL: RX ver=0x303 content_type=22 (handshake/server hello) OpenSSL: Message - hexdump(len=85): 02 00 00 51 03 01 5d 56 e1 20 e6 0c 72 bd b7 ac c0 19 4d 91 51 d8 bb 5d df 3a 82 da 65 4a 33 d8 1d 75 be 0a bf 52 20 34 37 00 00 8d e6 f9 4e 11 d5 f0 b4 c4 9e b6 e2 a6 65 b9 43 04 3e 52 a5 91 4d 94 e8 1d 06 c9 35 c0 14 00 00 09 00 17 00 00 ff 01 00 01 00 OpenSSL: TX ver=0x0 content_type=256 (TLS header info/) OpenSSL: Message - hexdump(len=5): 15 03 03 00 02 OpenSSL: TX ver=0x303 content_type=21 (alert/) OpenSSL: Message - hexdump(len=2): 02 46 SSL: (where=0x4008 ret=0x246) SSL: SSL3 alert: write (local SSL3 detected an error):fatal:protocol version EAP: Status notification: local TLS alert (param=protocol version) SSL: (where=0x1002 ret=0xffffffff) SSL: SSL_connect:error in error OpenSSL: openssl_handshake - SSL_connect error:1425F102:SSL routines:ssl_choose_client_version:unsupported protocol SSL: 7 bytes pending from ssl_out SSL: Using TLS version TLSv1.2 SSL: Failed - tls_out available to report error (len=7) SSL: 7 bytes left to be sent out (of total 7 bytes) EAP-PEAP: TLS processing failed EAP: method process -> ignore=FALSE methodState=DONE decision=FAIL eapRespData=0x557648f9e7b0 EAP: EAP entering state SEND_RESPONSE EAP: EAP entering state IDLE EAPOL: SUPP_BE entering state RESPONSE EAPOL: txSuppRsp WPA: eapol_test_eapol_send(type=0 len=17) TX EAP -> RADIUS - hexdump(len=17): 02 74 00 11 19 80 00 00 00 07 15 03 03 00 02 02 46 Encapsulating EAP message into a RADIUS packet Copied RADIUS State Attribute Sending RADIUS message to authentication server RADIUS message: code=1 (Access-Request) identifier=4 length=170 Attribute 1 (User-Name) length=8 Value: 'x19a19' Attribute 31 (Calling-Station-Id) length=19 Value: '00-0A-CD-31-6C-B4' Attribute 12 (Framed-MTU) length=6 Value: 1400 Attribute 61 (NAS-Port-Type) length=6 Value: 19 Attribute 6 (Service-Type) length=6 Value: 2 Attribute 77 (Connect-Info) length=24 Value: 'CONNECT 11Mbps 802.11b' Attribute 4 (NAS-IP-Address) length=6 Value: 128.180.10.10 Attribute 79 (EAP-Message) length=19 Value: 0274001119800000000715030300020246 Attribute 24 (State) length=38 Value: 375c0381000001370001020080b400c9000000000000000000000000000000047a7d2b22 Attribute 80 (Message-Authenticator) length=18 Value: c826882f085d2a5983dc4e4fd5a9e419 Next RADIUS client retransmit in 3 seconds EAPOL: SUPP_BE entering state RECEIVE Received 44 bytes from RADIUS server Received RADIUS message RADIUS message: code=3 (Access-Reject) identifier=4 length=44 Attribute 79 (EAP-Message) length=6 Value: 04740004 Attribute 80 (Message-Authenticator) length=18 Value: 02902649d29f2e66e84dc0142a3e2e71 STA 00:0a:cd:31:6c:b4: Received RADIUS packet matched with a pending request, round trip time 0.00 sec RADIUS packet matching with station decapsulated EAP packet (code=4 id=116 len=4) from RADIUS server: EAP Failure EAPOL: Received EAP-Packet frame EAPOL: SUPP_BE entering state REQUEST EAPOL: getSuppRsp EAP: EAP entering state RECEIVED EAP: Received EAP-Failure EAP: Status notification: completion (param=failure) EAP: EAP entering state FAILURE CTRL-EVENT-EAP-FAILURE EAP authentication failed EAPOL: SUPP_PAE entering state HELD EAPOL: SUPP_BE entering state RECEIVE EAPOL: SUPP_BE entering state FAIL EAPOL: SUPP_BE entering state IDLE eapol_sm_cb: result=0 EAPOL: EAP key not available EAPOL: EAP Session-Id not available WPA: Clear old PMK and PTK EAP: deinitialize previously used EAP method (25, PEAP) at EAP deinit ENGINE: engine deinit MPPE keys OK: 0 mismatch: 1 FAILURE -- Munroe Sollog Senior Network Engineer munroe(a)lehigh.edu

2 2