Eap in v4
Aleksandr Stepanov
alex-eri at ya.ru
Tue Mar 20 20:17:03 CET 2018
solution comes faster if asked)
authenticate mschap {
mschap
}
--
Best regards, Aleksandr Stepanov.
20.03.2018, 21:47, "Aleksandr Stepanov" <alex-eri at ya.ru>:
> I lost somethinng again
>
> Debug : (8.0) authenticate eap {
> Debug : (8.0) eap-inner - Peer sent packet with EAP method MSCHAPv2 (26)
> Debug : (8.0) eap-inner - Calling submodule eap_mschapv2
> Debug : (8.0) eap-inner - Empty authenticate section in virtual server "peap-tunnel". Using default return value (reject)
> Debug : (8.0) eap-inner - Submodule eap_mschapv2 returned
> Debug : (8.0) eap-inner - Sending EAP Failure (code 4) ID 8 length 4
> Debug : (8.0) eap-inner - Cleaning up EAP session
> Debug : (8.0) eap-inner (reject)
> Debug : (8.0) } # authenticate eap (reject)
>
> peap with inner tunnel not working
>
> Info : FreeRADIUS Version 4.0.0
> Info : Copyright (C) 1999-2017 The FreeRADIUS server project and contributors
> Info : There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
> Info : PARTICULAR PURPOSE
> Info : You may redistribute copies of FreeRADIUS under the terms of the
> Info : GNU General Public License
> Info : For more information about these matters, see the file named COPYRIGHT
> Getting debug state failed: ptrace capability not set. If debugger detection is required run as root or: setcap cap_sys_ptrace+ep <path_to_radiusd>
> Info : Starting - reading configuration files ...
> Debug : Including dictionary file "/opt/freeradius/share/freeradius/dictionary"
> Debug : Including configuration file "/opt/freeradius/etc/raddb/radiusd.conf"
> Debug : Including files in directory "/opt/freeradius/etc/raddb/mods-enabled/"
> Debug : Including configuration file "/opt/freeradius/etc/raddb/mods-enabled/always"
> Debug : Including configuration file "/opt/freeradius/etc/raddb/mods-enabled/pap"
> Debug : Including configuration file "/opt/freeradius/etc/raddb/mods-enabled/expr"
> Debug : Including configuration file "/opt/freeradius/etc/raddb/mods-enabled/eap"
> Debug : Including configuration file "/opt/freeradius/etc/raddb/mods-enabled/sql"
> Debug : Including configuration file "/opt/freeradius/etc/raddb/sql/driver.conf"
> Debug : Including configuration file "/opt/freeradius/etc/raddb/sql/queries.conf"
> Debug : Including configuration file "/opt/freeradius/etc/raddb/sql/auth.conf"
> Debug : Including configuration file "/opt/freeradius/etc/raddb/sql/acct.conf"
> Debug : Including configuration file "/opt/freeradius/etc/raddb/mods-enabled/eap-inner"
> Debug : Including files in directory "/opt/freeradius/etc/raddb/policy.d/"
> Debug : Including configuration file "/opt/freeradius/etc/raddb/policy.d/eap"
> Debug : Including configuration file "/opt/freeradius/etc/raddb/server.conf"
> Debug : Including configuration file "/opt/freeradius/etc/raddb/clients.conf"
> Debug : Including configuration file "/opt/freeradius/etc/raddb/auth.conf"
> Debug : Parsing security rules to bootstrap UID / GID / chroot / etc.
> Debug : main {
> Debug : security {
> Debug : allow_core_dumps = no
> Debug : reject_delay = 1.000000
> Debug : status_server = yes
> Debug : allow_vulnerable_openssl = "yes"
> Debug : }
> Debug : prefix = "/usr/local"
> Debug : run_dir = "/var//run/radiusd"
> Debug : }
> Debug : Parsing main configuration.
> Debug : main {
> Debug : security {
> Debug : }
> Debug : sbindir = "/usr/local/sbin"
> Debug : logdir = "/var//log"
> Debug : libdir = "/usr/lib/"
> Debug : radacctdir = "/var//log/radacct"
> Debug : hostname_lookups = no
> Debug : max_request_time = 30
> Debug : cleanup_delay = 5
> Debug : continuation_timeout = 15
> Debug : max_requests = 256
> Debug : pidfile = "/var//run/radiusd/radiusd.pid"
> Debug : debug_level = 0
> Debug : proxy_requests = yes
> Debug : log {
> Debug : stripped_names = no
> Debug : auth = yes
> Debug : auth_badpass = no
> Debug : auth_goodpass = no
> Debug : colourise = yes
> Debug : msg_denied = "You are already logged in - access denied"
> Debug : }
> Debug : resources {
> Debug : }
> Debug : thread {
> Debug : num_networks = 1
> Debug : num_workers = 4
> Debug : }
> Debug : server internet {
> Debug : namespace = "radius"
> Info : Loaded module "proto_radius"
> Debug : listen {
> Debug : type = Access-Request
> Info : Loaded module "proto_radius_auth"
> Debug : type = Status-Server
> Info : Loaded module "proto_radius_status"
> Debug : type = Accounting-Request
> Info : Loaded module "proto_radius_acct"
> Debug : transport = udp
> Info : Loaded module "proto_radius_udp"
> Debug : udp {
> Debug : ipaddr = *
> Debug : port = 1812
> Debug : cleanup_delay = 5
> Debug : connected = no
> Debug : dynamic_clients {
> Debug : network = 0.0.0.0/0
> Debug : max_clients = 65536
> Debug : max_pending_clients = 256
> Debug : max_pending_packets = 4096
> Debug : lifetime = 3600
> Debug : }
> Debug : }
> Debug : max_attributes = 255
> Debug : }
> Debug : }
> Debug : server peap-tunnel {
> Debug : namespace = "radius"
> Debug : listen {
> Debug : type = Access-Request
> Debug : transport = udp
> Debug : udp {
> Debug : ipaddr = 127.0.0.1
> Debug : port = 18120
> Debug : cleanup_delay = 5
> Debug : connected = no
> Debug : }
> Debug : max_attributes = 255
> Debug : }
> Debug : }
> Debug : }
> Info : Switching to configured log settings
> Debug : radiusd: #### Loading Clients ####
> Info : Debug state unknown (cap_sys_ptrace capability not set)
> Info : systemd watchdog is disabled
> Debug : #### Bootstrapping listeners ####
> Debug : Creating Auth-Type = pap
> Debug : Creating Auth-Type = chap
> Debug : Creating Auth-Type = mschap
> Debug : Creating Auth-Type = digest
> Debug : Creating Auth-Type = eap
> Info : Loaded module "proto_radius_dynamic_client"
> Debug : #### Bootstrapping modules ####
> Debug : modules {
> Info : Loaded module "rlm_always"
> Debug : always reject {
> Debug : rcode = "reject"
> Debug : simulcount = 0
> Debug : mpp = no
> Debug : }
> Debug : always fail {
> Debug : rcode = "fail"
> Debug : simulcount = 0
> Debug : mpp = no
> Debug : }
> Debug : always ok {
> Debug : rcode = "ok"
> Debug : simulcount = 0
> Debug : mpp = no
> Debug : }
> Debug : always handled {
> Debug : rcode = "handled"
> Debug : simulcount = 0
> Debug : mpp = no
> Debug : }
> Debug : always invalid {
> Debug : rcode = "invalid"
> Debug : simulcount = 0
> Debug : mpp = no
> Debug : }
> Debug : always userlock {
> Debug : rcode = "userlock"
> Debug : simulcount = 0
> Debug : mpp = no
> Debug : }
> Debug : always notfound {
> Debug : rcode = "notfound"
> Debug : simulcount = 0
> Debug : mpp = no
> Debug : }
> Debug : always noop {
> Debug : rcode = "noop"
> Debug : simulcount = 0
> Debug : mpp = no
> Debug : }
> Debug : always updated {
> Debug : rcode = "updated"
> Debug : simulcount = 0
> Debug : mpp = no
> Debug : }
> Info : Loaded module "rlm_pap"
> Debug : pap {
> Debug : normalise = yes
> Debug : }
> Info : Loaded module "rlm_chap"
> Info : Loaded module "rlm_mschap"
> Debug : mschap {
> Debug : use_mppe = yes
> Debug : require_encryption = no
> Debug : require_strong = no
> Debug : with_ntdomain_hack = yes
> Debug : passchange {
> Debug : }
> Debug : allow_retry = yes
> Debug : winbind_retry_with_normalised_username = no
> Debug : }
> Info : Loaded module "rlm_digest"
> Info : Loaded module "rlm_expr"
> Debug : expr {
> Debug : safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
> Debug : }
> Info : Loaded module "rlm_eap"
> Debug : eap {
> Debug : default_eap_type = peap
> Debug : type = md5
> Info : Loaded module "rlm_eap_md5"
> Debug : type = mschapv2
> Info : Loaded module "rlm_eap_mschapv2"
> Debug : mschapv2 {
> Debug : with_ntdomain_hack = no
> Debug : send_error = no
> Debug : identity = "UNA"
> Debug : }
> Debug : type = peap
> Info : Loaded module "rlm_eap_peap"
> Debug : peap {
> Debug : tls = "tls-common"
> Debug : proxy_tunneled_request_as_eap = yes
> Debug : virtual_server = "peap-tunnel"
> Debug : soh = no
> Debug : require_client_cert = no
> Debug : }
> Debug : ignore_unknown_eap_types = yes
> Debug : cisco_accounting_username_bug = no
> Debug : }
> Info : Loaded module "rlm_sql"
> Debug : sql {
> Debug : driver = "rlm_sql_postgresql"
> Debug : server = ""
> Debug : port = 0
> Debug : login = ""
> Debug : password = <<< secret >>>
> Debug : radius_db = "host=postgres port=5432 dbname=billing user=radius password=raddpass"
> Debug : read_groups = yes
> Debug : read_profiles = yes
> Debug : sql_user_name = "%{User-Name}"
> Debug : default_user_profile = ""
> Debug : authorize_check_query = "SELECT uuid as id, login as UserName, 'Cleartext-Password' as Attribute, password as Value , ':=' as Op FROM login WHERE login = 'root' ORDER BY uuid"
> Debug : safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
> Debug : accounting {
> Debug : reference = "%{tolower:type.%{%{Acct-Status-Type}:-none}.query}"
> Debug : type {
> Debug : accounting-on {
> Debug : }
> Debug : accounting-off {
> Debug : query = "UPDATE radacct SET AcctStopTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctSessionTime = (%{integer:Event-Timestamp} - EXTRACT(EPOCH FROM(AcctStartTime))), AcctTerminateCause = '%{%{Acct-Terminate-Cause}:-NAS-Reboot}' WHERE AcctStopTime IS NULL AND NASIPAddress= '%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}}' AND AcctStartTime <= '%S'::timestamp"
> Debug : }
> Debug : start {
> Debug : query = "INSERT INTO radacct (AcctSessionId, AcctUniqueId, UserName, account_id, 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}', NULLIF('%{Chargeable-User-Identity}', ''),NULLIF('%{Realm}', ''), '%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}}', NULLIF('%{%{NAS-Port-ID}:-%{NAS-Port}}', ''), '%{NAS-Port-Type}', TO_TIMESTAMP(%{integer:Event-Timestamp}), TO_TIMESTAMP(%{integer:Event-Timestamp}), NULL, 0, '%{Acct-Authentic}', '%{Connect-Info}', NULL, 0, 0, '%{Called-Station-Id}', '%{Calling-Station-Id}', NULL, '%{Service-Type}', '%{Framed-Protocol}', NULLIF('%{Framed-IP-Address}', '')::inet)"
> Debug : query = "UPDATE radacct SET AcctStartTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), ConnectInfo_start = '%{Connect-Info}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}' AND AcctStopTime IS NULL"
> Debug : query = "UPDATE radacct SET AcctStartTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), ConnectInfo_start = '%{Connect-Info}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}'"
> Debug : }
> Debug : interim-update {
> Debug : query = "UPDATE radacct SET FramedIPAddress = NULLIF('%{Framed-IP-Address}', '')::inet, AcctSessionTime = %{%{Acct-Session-Time}:-NULL}, AcctInterval = (%{integer:Event-Timestamp} - EXTRACT(EPOCH FROM (COALESCE(AcctUpdateTime, AcctStartTime)))), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctInputOctets = (('%{%{Acct-Input-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Input-Octets}:-0}'::bigint), AcctOutputOctets = (('%{%{Acct-Output-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Output-Octets}:-0}'::bigint) WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}' AND AcctStopTime IS NULL"
> Debug : query = "INSERT INTO radacct (AcctSessionId, AcctUniqueId, UserName, account_id, 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}', NULLIF('%{Chargeable-User-Identity}', ''),NULLIF('%{Realm}', ''), '%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}}', NULLIF('%{%{NAS-Port-ID}:-%{NAS-Port}}', ''), '%{NAS-Port-Type}', TO_TIMESTAMP(%{integer:Event-Timestamp}), TO_TIMESTAMP(%{integer:Event-Timestamp}), NULL, %{%{Acct-Session-Time}:-NULL}, '%{Acct-Authentic}', '%{Connect-Info}', NULL, (('%{%{Acct-Input-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Input-Octets}:-0}'::bigint), (('%{%{Acct-Output-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Output-Octets}:-0}'::bigint), '%{Called-Station-Id}', '%{Calling-Station-Id}', NULL, '%{Service-Type}', '%{Framed-Protocol}', NULLIF('%{Framed-IP-Address}', '')::inet)"
> Debug : }
> Debug : stop {
> Debug : query = "UPDATE radacct SET AcctStopTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctSessionTime = COALESCE(%{%{Acct-Session-Time}:-NULL}, (%{integer:Event-Timestamp} - EXTRACT(EPOCH FROM(AcctStartTime)))), AcctInputOctets = (('%{%{Acct-Input-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Input-Octets}:-0}'::bigint), AcctOutputOctets = (('%{%{Acct-Output-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Output-Octets}:-0}'::bigint), AcctTerminateCause = '%{Acct-Terminate-Cause}', FramedIPAddress = NULLIF('%{Framed-IP-Address}', '')::inet, ConnectInfo_stop = '%{Connect-Info}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}' AND AcctStopTime IS NULL"
> Debug : query = "INSERT INTO radacct (AcctSessionId, AcctUniqueId, UserName, account_id, 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}', NULLIF('%{Chargeable-User-Identity}', ''),NULLIF('%{Realm}', ''), '%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}}', NULLIF('%{%{NAS-Port-ID}:-%{NAS-Port}}', ''), '%{NAS-Port-Type}', TO_TIMESTAMP(%{integer:Event-Timestamp} - %{%{Acct-Session-Time}:-0}), TO_TIMESTAMP(%{integer:Event-Timestamp}), TO_TIMESTAMP(%{integer:Event-Timestamp}), NULLIF('%{Acct-Session-Time}', '')::bigint, '%{Acct-Authentic}', '%{Connect-Info}', NULL, (('%{%{Acct-Input-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Input-Octets}:-0}'::bigint), (('%{%{Acct-Output-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Output-Octets}:-0}'::bigint), '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Acct-Terminate-Cause}', '%{Service-Type}', '%{Framed-Protocol}', NULLIF('%{Framed-IP-Address}', '')::inet)"
> Debug : query = "UPDATE radacct SET AcctStopTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctSessionTime = COALESCE(%{%{Acct-Session-Time}:-NULL}, (%{integer:Event-Timestamp} - EXTRACT(EPOCH FROM(AcctStartTime)))), AcctInputOctets = (('%{%{Acct-Input-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Input-Octets}:-0}'::bigint), AcctOutputOctets = (('%{%{Acct-Output-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Output-Octets}:-0}'::bigint), AcctTerminateCause = '%{Acct-Terminate-Cause}', FramedIPAddress = NULLIF('%{Framed-IP-Address}', '')::inet, ConnectInfo_stop = '%{Connect-Info}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}'"
> Debug : }
> Debug : }
> Debug : }
> Debug : post-auth {
> Debug : reference = ".query"
> Debug : }
> Debug : }
> Info : Loaded module "rlm_sql_postgresql"
> Debug : postgresql {
> Debug : send_application_name = yes
> Debug : }
> Debug : eap eap-inner {
> Debug : default_eap_type = md5
> Debug : type = md5
> Debug : type = mschapv2
> Debug : mschapv2 {
> Debug : with_ntdomain_hack = no
> Debug : send_error = no
> Debug : identity = "UNA"
> Debug : }
> Debug : ignore_unknown_eap_types = yes
> Debug : cisco_accounting_username_bug = no
> Debug : }
> Debug : instantiate {
> Warn : /opt/freeradius/etc/raddb/radiusd.conf[45]: Only virtual modules can be instantiated with the instantiate section
> Debug : }
> Debug : } # modules
> Debug : #### Instantiating listeners ####
> Debug : Compiling policies in server internet { ... }
> Debug : Compiling policies - new client {...}
> Debug : Compiling policies - add client {...}
> Debug : Compiling policies - deny client {...}
> Debug : compiling - recv Access-Request {...}
> Debug : compiling - recv Status-Server {...}
> Debug : compiling - recv Accounting-Request {...}
> Error : /opt/freeradius/etc/raddb/auth.conf[16]: "sql" modules aren't allowed in 'recv Accounting-Request { ... }' sections -- they have no such method.
> Warn : /opt/freeradius/etc/raddb/auth.conf[16]: Ignoring "sql" (see raddb/mods-available/README.rst)
> Debug : compiling - send Access-Challenge {...}
> Debug : compiling - send Access-Accept {...}
> Debug : Compiling policies - authenticate pap {...}
> Debug : Compiling policies - authenticate chap {...}
> Debug : Compiling policies - authenticate mschap {...}
> Debug : Compiling policies - authenticate digest {...}
> Debug : Compiling policies - authenticate eap {...}
> Debug : Compiling policies in server peap-tunnel { ... }
> Debug : compiling - recv Access-Request {...}
> Debug : compiling - send Access-Accept {...}
> Debug : Compiling policies - authenticate eap {...}
> Debug : Compiling policies - authenticate pap {...}
> Debug : #### Instantiating modules ####
> Debug : Instantiating module "eap"
> Debug : tls-config tls-common {
> Debug : auto_chain = yes
> Debug : chain {
> Debug : format = pem
> Debug : certificate_file = "/opt/freeradius/etc/raddb/certs/server.pem"
> Debug : private_key_file = "/opt/freeradius/etc/raddb/certs/server.pem"
> Debug : verify_mode = hard
> Debug : include_root_ca = no
> Debug : }
> Debug : verify_depth = 0
> Debug : fragment_size = 1024
> Debug : check_crl = no
> Debug : cipher_list = "DEFAULT"
> Debug : cipher_server_preference = yes
> Debug : allow_renegotiation = no
> Debug : ecdh_curve = "prime256v1"
> Debug : tls_min_version = 1.000000
> Debug : cache {
> Debug : lifetime = 86400
> Debug : verify = no
> Debug : require_extended_master_secret = yes
> Debug : require_perfect_forward_secrecy = no
> Debug : }
> Debug : verify {
> Debug : }
> Debug : ocsp {
> Debug : enable = no
> Debug : override_cert_url = no
> Debug : use_nonce = yes
> Debug : timeout = 0
> Debug : softfail = no
> Debug : }
> Debug : staple {
> Debug : enable = no
> Debug : override_cert_url = no
> Debug : use_nonce = yes
> Debug : timeout = 0
> Debug : softfail = no
> Debug : }
> Debug : }
> Debug : Instantiating module "eap-inner"
> Debug : Instantiating module "fail"
> Debug : Instantiating module "handled"
> Debug : Instantiating module "invalid"
> Debug : Instantiating module "mschap"
> Debug : mschap: using internal authentication
> Debug : Instantiating module "noop"
> Debug : Instantiating module "notfound"
> Debug : Instantiating module "ok"
> Debug : Instantiating module "pap"
> Debug : Instantiating module "reject"
> Debug : Instantiating module "sql"
> Info : rlm_sql (sql) - Attempting to connect to database "host=postgres port=5432 dbname=billing user=radius password=raddpass"
> Debug : rlm_sql (sql) - Initialising connection pool
> Debug : pool {
> Debug : start = 5
> Debug : min = 3
> Debug : max = 32
> Debug : max_pending = 0
> Debug : spare = 10
> Debug : uses = 0
> Debug : lifetime = 0
> Debug : cleanup_interval = 30
> Debug : idle_timeout = 60
> Debug : connect_timeout = 3.000000
> Debug : held_trigger_min = 0.000000
> Debug : held_trigger_max = 0.500000
> Debug : retry_delay = 30
> Debug : spread = no
> Debug : }
> Debug : rlm_sql (sql) - Opening additional connection (0), 1 of 32 pending slots used
> Debug : rlm_sql_postgresql - Connecting using parameters: host=postgres port=5432 dbname=billing user=radius password=raddpass application_name='FreeRADIUS 4.0.0 - radiusd (sql)'
> Debug : rlm_sql_postgresql - Connected to database 'billing' on 'postgres' server version 100003, protocol version 3, backend PID 672
> Debug : rlm_sql (sql) - Opening additional connection (1), 1 of 31 pending slots used
> Debug : rlm_sql_postgresql - Connecting using parameters: host=postgres port=5432 dbname=billing user=radius password=raddpass application_name='FreeRADIUS 4.0.0 - radiusd (sql)'
> Debug : rlm_sql_postgresql - Connected to database 'billing' on 'postgres' server version 100003, protocol version 3, backend PID 673
> Debug : rlm_sql (sql) - Opening additional connection (2), 1 of 30 pending slots used
> Debug : rlm_sql_postgresql - Connecting using parameters: host=postgres port=5432 dbname=billing user=radius password=raddpass application_name='FreeRADIUS 4.0.0 - radiusd (sql)'
> Debug : rlm_sql_postgresql - Connected to database 'billing' on 'postgres' server version 100003, protocol version 3, backend PID 674
> Debug : rlm_sql (sql) - Opening additional connection (3), 1 of 29 pending slots used
> Debug : rlm_sql_postgresql - Connecting using parameters: host=postgres port=5432 dbname=billing user=radius password=raddpass application_name='FreeRADIUS 4.0.0 - radiusd (sql)'
> Debug : rlm_sql_postgresql - Connected to database 'billing' on 'postgres' server version 100003, protocol version 3, backend PID 675
> Debug : rlm_sql (sql) - Opening additional connection (4), 1 of 28 pending slots used
> Debug : rlm_sql_postgresql - Connecting using parameters: host=postgres port=5432 dbname=billing user=radius password=raddpass application_name='FreeRADIUS 4.0.0 - radiusd (sql)'
> Debug : rlm_sql_postgresql - Connected to database 'billing' on 'postgres' server version 100003, protocol version 3, backend PID 676
> Debug : Instantiating module "updated"
> Debug : Instantiating module "userlock"
> Debug : Scheduler created in single-threaded mode
> Debug : #### Opening listener interfaces ####
> Debug : Listening on radius address proto udp address * port 1812 bound to virtual server internet
> Debug : Listening on radius address proto udp address 127.0.0.1 port 18120 bound to virtual server peap-tunnel
> Info : Ready to process requests
> Info : Ready to process requests
> Info : Ready to process requests
> Debug : Found matching network. Checking for dynamic client definition.
> Debug : Network received packet size 128
> Info : Ready to process requests
> Debug : Resetting worker cleanup timer to +30s
> Debug : (0) running request
> Debug : (0) Received Access-Request ID 136
> Debug : (0) User-Name = "root"
> Debug : (0) NAS-IP-Address = 192.168.117.1
> Debug : (0) NAS-Identifier = "RalinkAP0"
> Debug : (0) NAS-Port = 0
> Debug : (0) Called-Station-Id = "C0-25-E9-4C-71-36"
> Debug : (0) Calling-Station-Id = "7C-B0-C2-74-6C-CE"
> Debug : (0) Framed-MTU = 1400
> Debug : (0) NAS-Port-Type = Wireless-802.11
> Debug : (0) EAP-Message = 0x0201000901726f6f74
> Debug : (0) Message-Authenticator = 0x0a89466ca425ba15608ae5910e409384
> Debug : (0) Running 'new client' from file /opt/freeradius/etc/raddb/clients.conf
> Debug : (0) new client {
> Debug : (0) EXPAND %{NAS-Identifier}
> Debug : (0) --> RalinkAP0
> Debug : (0) MAP sql "SELECT type,secret,server FROM nas WHERE shortname = 'RalinkAP0'"
> Debug : (0) EXPAND %{User-Name}
> Debug : (0) --> root
> Debug : (0) SQL-User-Name set to 'root'
> Debug : (0) Reserved connection (4)
> Debug : (0) Executing select query: SELECT type,secret,server FROM nas WHERE shortname = 'RalinkAP0'
> Debug : rlm_sql_postgresql - Status: PGRES_TUPLES_OK
> Debug : rlm_sql_postgresql - query affected rows = 1 , fields = 3
> Debug : (0) &control:FreeRADIUS-Client-NAS-Type = other
> Debug : (0) &control:FreeRADIUS-Client-Secret = secret
> Debug : (0) &control:FreeRADIUS-Client-Virtual-Server = internet
> Debug : (0) Released connection (4)
> Info : (0) Need 5 more connections to reach 10 spares
> Debug : (0) Opening additional connection (5), 1 of 27 pending slots used
> Debug : rlm_sql_postgresql - Connecting using parameters: host=postgres port=5432 dbname=billing user=radius password=raddpass application_name='FreeRADIUS 4.0.0 - radiusd (sql)'
> Debug : rlm_sql_postgresql - Connected to database 'billing' on 'postgres' server version 100003, protocol version 3, backend PID 678
> Debug : (0) Closing expired connection (4): Needs reconnecting
> Debug : rlm_sql_postgresql - Socket destructor called, closing socket
> Debug : (0) Closing expired connection (3): Needs reconnecting
> Debug : rlm_sql_postgresql - Socket destructor called, closing socket
> Debug : (0) Closing expired connection (2): Needs reconnecting
> Debug : rlm_sql_postgresql - Socket destructor called, closing socket
> Debug : (0) Closing expired connection (1): Needs reconnecting
> Debug : (0) You probably need to lower "min"
> Debug : rlm_sql_postgresql - Socket destructor called, closing socket
> Debug : (0) Closing expired connection (0): Needs reconnecting
> Debug : (0) You probably need to lower "min"
> Debug : rlm_sql_postgresql - Socket destructor called, closing socket
> Debug : (0) update control {
> Debug : (0) EXPAND %{Packet-Src-IP-Address}
> Debug : (0) --> 192.168.117.1
> Debug : (0) EXPAND %{NAS-Identifier}
> Debug : (0) --> RalinkAP0
> Debug : (0) &FreeRADIUS-Client-IP-Address = 192.168.117.1
> Debug : (0) &FreeRADIUS-Client-Shortname = "RalinkAP0"
> Debug : (0) } # update control (noop)
> Debug : (0) } # new client (updated)
> Debug : (0) Running 'add client' from file /opt/freeradius/etc/raddb/clients.conf
> Debug : (0) add client {
> Debug : (0) ok (ok)
> Debug : (0) } # add client (ok)
> Debug : (0) Adding client
> Debug : (0) done request
> Debug : (0) Converting &request:control to client {...} section
> Debug : (0) nas_type = other
> Debug : (0) secret = secret
> Debug : (0) ipv4addr = 192.168.117.1
> Debug : (0) shortname = RalinkAP0
> Debug : client dynamic0 {
> Debug : ipv4addr = 192.168.117.1
> Debug : require_message_authenticator = no
> Debug : secret = <<< secret >>>
> Debug : shortname = "RalinkAP0"
> Debug : nas_type = "other"
> Debug : limit {
> Debug : max_connections = 16
> Debug : lifetime = 0
> Debug : idle_timeout = 30
> Debug : }
> Debug : }
> Debug : (0) finished request.
> Debug : Waking up in 28.6 seconds.
> Debug : proto udp address * port 1812 - Defining new client
> Debug : Waking up in 28.6 seconds.
> Debug : Waking up in 28.6 seconds.
> Debug : Network received packet size 128
> Debug : Waking up in 27.6 seconds.
> Debug : (1) running request
> Debug : (1) Received Access-Request ID 136
> Debug : (1) User-Name = "root"
> Debug : (1) NAS-IP-Address = 192.168.117.1
> Debug : (1) NAS-Identifier = "RalinkAP0"
> Debug : (1) NAS-Port = 0
> Debug : (1) Called-Station-Id = "C0-25-E9-4C-71-36"
> Debug : (1) Calling-Station-Id = "7C-B0-C2-74-6C-CE"
> Debug : (1) Framed-MTU = 1400
> Debug : (1) NAS-Port-Type = Wireless-802.11
> Debug : (1) EAP-Message = 0x0201000901726f6f74
> Debug : (1) Message-Authenticator = 0x0a89466ca425ba15608ae5910e409384
> Debug : (1) Running 'recv Access-Request' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (1) recv Access-Request {
> Debug : (1) chap (noop)
> Debug : (1) mschap (noop)
> Debug : (1) eap - Peer sent EAP Response (code 2) ID 1 length 9
> Debug : (1) eap - Peer sent EAP-Identity. Returning 'ok' so we can short-circuit the rest of authorize
> Debug : (1) eap (ok)
> Debug : (1) } # recv Access-Request (ok)
> Debug : (1) Running 'authenticate eap' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (1) authenticate eap {
> Debug : (1) eap - Peer sent packet with EAP method Identity (1)
> Debug : (1) eap - Calling submodule eap_peap
> Debug : (1) eap - Initiating new TLS session
> Debug : (1) eap - EXPAND %{EAP-Type}%{Virtual-Server}
> Debug : (1) eap - --> Identityinternet
> Debug : (1) eap - Submodule eap_peap returned
> Debug : (1) eap - Sending EAP Request (code 1) ID 2 length 6
> Debug : (1) eap (handled)
> Debug : (1) } # authenticate eap (handled)
> Debug : (1) Running 'send Access-Challenge' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (1) send Access-Challenge {
> Debug : (1) handled (handled)
> Debug : (1) } # send Access-Challenge (handled)
> Debug : (1) Sent code 11 Id 136 from 172.18.0.3:1812 to 192.168.117.1:38107 via eth0 length 0
> Debug : (1) EAP-Message = 0x010200061920
> Debug : (1) Message-Authenticator = 0x00000000000000000000000000000000
> Debug : (1) State = 0x9582b11402620f2da3373c745f8886f0
> Debug : (1) done request
> Debug : (1) finished request.
> Debug : Waking up in 27.6 seconds.
> Debug : Waking up in 4.9 seconds.
> Debug : Waking up in 4.9 seconds.
> Debug : Network received packet size 452
> Debug : Waking up in 4.9 seconds.
> Debug : Resetting worker cleanup timer to +30s
> Debug : (2) running request
> Debug : (2) Received Access-Request ID 137
> Debug : (2) User-Name = "root"
> Debug : (2) NAS-IP-Address = 192.168.117.1
> Debug : (2) NAS-Identifier = "RalinkAP0"
> Debug : (2) NAS-Port = 0
> Debug : (2) Called-Station-Id = "C0-25-E9-4C-71-36"
> Debug : (2) Calling-Station-Id = "7C-B0-C2-74-6C-CE"
> Debug : (2) Framed-MTU = 1400
> Debug : (2) NAS-Port-Type = Wireless-802.11
> Debug : (2) EAP-Message = 0x0202013919800000012f160301012a01000126030344df9cd20fc70a21a4c1157d9cbc6653022e9de7d98aabd2a1bc6b80f5bccd970000acc030c02cc028c024c014c00a00a500a300a1009f006b006a0069006800390038003700360088008700860085c032c02ec02ac026c00fc005009d003d00350084c02fc02bc027c023c013c00900a400a200a0009e00670040003f003e0033003200310030009a0099009800970045004400430042c031c02dc029c025c00ec004009c003c002f009600410007c011c007c00cc00200050004c012c008001600130010000dc00dc003000a00ff01000051000b000403000102000a001c001a00170019001c001b0018001a0016000e000d000b000c0009000a000d0020001e060106020603050105020503040104020403030103020303020102020203000f000101
> Debug : (2) State = 0x9582b11402620f2da3373c745f8886f0
> Debug : (2) Message-Authenticator = 0xd5652f41458e9052701f8635bb625ef6
> Debug : (2,1) Running 'recv Access-Request' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (2,1) recv Access-Request {
> Debug : (2,1) chap (noop)
> Debug : (2,1) mschap (noop)
> Debug : (2,1) eap - Peer sent EAP Response (code 2) ID 2 length 313
> Debug : (2,1) eap - Continuing tunnel setup
> Debug : (2,1) eap (ok)
> Debug : (2,1) } # recv Access-Request (ok)
> Debug : (2,1) Running 'authenticate eap' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (2,1) authenticate eap {
> Debug : (2,1) eap - Peer sent packet with EAP method PEAP (25)
> Debug : (2,1) eap - Calling submodule eap_peap
> Debug : (2,1) eap - Continuing EAP-TLS
> Debug : (2,1) eap - Peer indicated complete TLS record size will be 303 bytes
> Debug : (2,1) eap - Got complete TLS record, with length field (303 bytes)
> Debug : (2,1) eap - [eap-tls verify] = complete
> Debug : (2,1) eap - Handshake state - before SSL initialization
> Debug : (2,1) eap - Handshake state - Server before SSL initialization
> Debug : (2,1) eap - Handshake state - Server before SSL initialization
> Debug : (2,1) eap - <<< recv TLS 1.2 handshake [length 298], client_hello
> Debug : (2,1) eap - Handshake state - Server SSLv3/TLS read client hello
> Debug : (2,1) eap - >>> send TLS 1.2 handshake [length 57], server_hello
> Debug : (2,1) eap - Handshake state - Server SSLv3/TLS write server hello
> Debug : (2,1) eap - >>> send TLS 1.2 handshake [length 977], certificate
> Debug : (2,1) eap - Handshake state - Server SSLv3/TLS write certificate
> Debug : (2,1) eap - >>> send TLS 1.2 handshake [length 333], server_key_exchange
> Debug : (2,1) eap - Handshake state - Server SSLv3/TLS write key exchange
> Debug : (2,1) eap - >>> send TLS 1.2 handshake [length 4], server_hello_done
> Debug : (2,1) eap - Handshake state - Server SSLv3/TLS write server done
> Debug : (2,1) eap - Need more data from client
> Debug : (2,1) eap - Complete TLS record (1391 bytes) larger than MTU (1010 bytes), will fragment
> Debug : (2,1) eap - Sending first TLS record fragment (1010 bytes), 381 bytes remaining
> Debug : (2,1) eap - [eap-tls process] = handled
> Debug : (2,1) eap - Submodule eap_peap returned
> Debug : (2,1) eap - Sending EAP Request (code 1) ID 3 length 1020
> Debug : (2,1) eap (handled)
> Debug : (2,1) } # authenticate eap (handled)
> Debug : (2,1) Running 'send Access-Challenge' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (2,1) send Access-Challenge {
> Debug : (2,1) handled (handled)
> Debug : (2,1) } # send Access-Challenge (handled)
> Debug : (2,1) Sent code 11 Id 137 from 172.18.0.3:1812 to 192.168.117.1:38107 via eth0 length 0
> Debug : (2,1) EAP-Message = 0x010303fc19c00000056f1603030039020000350303549703689a939aeac1c66f69ed8baea993f697fbe505022dfe1de234167cbeee00c03000000dff01000100000b00040300010216030303d10b0003cd0003ca0003c7308203c3308202ab020900afb3f37fbfccf043300d06092a864886f70d01010b05003081ba310b30090603550406130252553118301606035504080c0f526f73746f76736b617961206f626c3117301506035504070c0e42656c617961204b616c6974766131283026060355040a0c1f495020436865726b61736f7620416e647265792056696b746f726f766963683110300e060355040b0c0742696c6c696e673118301606035504030c0f495020436865726b61736f762043413122302006092a864886f70d01090116137a61726563682e6d7440676d61696c2e636f6d301e170d3136313230323233303734345a170d3139303231303233303734345a30818b310b30090603550406130252553114301206035504080c0b4976616e6f76736b6179613110300e06035504070c074976616e6f766f310f300d060355040a0c0645657269657331133011060355040b0c0a4e6574776f726b696e67310f300d06035504030c06526164697573311d301b06092a864886f70d010901160e616c65782d6572694079612e727530820122300d06092a864886f70d01010105000382010f003082010a0282010100e7cbf2e573ded0439a98f471d6665a77265f4286d7d8470dc867ef1e05fbf980871fb0acca211769d3bb3a3e03ea9ba934ca1e07788d0229daa48f785a159453d1040b8e6ae38a05049c7b375dfd261a6c86380cce8c226336875fa3bf5f3989381c4192ab5f1416181af8f6dee8a8c1793319865554cebe79ebe5e4fe528b0a8a8305583a83d499c3951e518c2354f21dcf1bf24620a53bf506ca965dcc7d62c979f3cd4a1c15a9586b83cc1988f71d9ef246fe0ac5cd1eff6f28bdf3d64fbc9080376767d65991e81b9707b258a5c71149b7e13ba6618b09a04fc7c6e5a32d23710e08b9edc034f83e65c7a2272cbd882130f617f0f1965180a1628286de010203010001300d06092a864886f70d01010b0500038201010031d9a5dbf25b9e68e3328741adf3b5a9285e6fbff761903dc2c6492f1c2b4efafa9c0252ee3d69586fc065b08728604a9d6a651d601d255264ceecd5989728e89635fbce5e64f09294e1635076cb4dd44a2bd9c6ce17d2234d201ada79d7415c6ccd8fb24430ed51d0de114d705a86f6ffc45275e6d557ec0e9960a73a47eda65b33002afbd5f133ba3f87839448ba556ae5c3eb821e56ce97aa918d64d1e190bb3daaceb4c742acc67e64bce3a986228cdb4da70346f43905100f47332196cb248e5e8f011d9df204f8b12c5939c3b02af
> eff1e495577947292d03d7b5b
> Debug : (2,1) Message-Authenticator = 0x00000000000000000000000000000000
> Debug : (2,1) State = 0xb2642b2a813d8f79ac8a8184b2c3da85
> Debug : (2) done request
> Debug : (2) finished request.
> Debug : Waking up in 4.9 seconds.
> Debug : Waking up in 4.9 seconds.
> Debug : Waking up in 4.9 seconds.
> Debug : Network received packet size 143
> Debug : Waking up in 4.9 seconds.
> Debug : (3) running request
> Debug : (3) Received Access-Request ID 138
> Debug : (3) User-Name = "root"
> Debug : (3) NAS-IP-Address = 192.168.117.1
> Debug : (3) NAS-Identifier = "RalinkAP0"
> Debug : (3) NAS-Port = 0
> Debug : (3) Called-Station-Id = "C0-25-E9-4C-71-36"
> Debug : (3) Calling-Station-Id = "7C-B0-C2-74-6C-CE"
> Debug : (3) Framed-MTU = 1400
> Debug : (3) NAS-Port-Type = Wireless-802.11
> Debug : (3) EAP-Message = 0x020300061900
> Debug : (3) State = 0xb2642b2a813d8f79ac8a8184b2c3da85
> Debug : (3) Message-Authenticator = 0xf805b9a6268f13776c3d1eab0daaf378
> Debug : (3,1) Running 'recv Access-Request' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (3,1) recv Access-Request {
> Debug : (3,1) chap (noop)
> Debug : (3,1) mschap (noop)
> Debug : (3,1) eap - Peer sent EAP Response (code 2) ID 3 length 6
> Debug : (3,1) eap - Continuing tunnel setup
> Debug : (3,1) eap (ok)
> Debug : (3,1) } # recv Access-Request (ok)
> Debug : (3,1) Running 'authenticate eap' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (3,1) authenticate eap {
> Debug : (3,1) eap - Peer sent packet with EAP method PEAP (25)
> Debug : (3,1) eap - Calling submodule eap_peap
> Debug : (3,1) eap - Continuing EAP-TLS
> Debug : (3,1) eap - Peer ACKed our handshake fragment
> Debug : (3,1) eap - [eap-tls verify] = request
> Debug : (3,1) eap - Sending final TLS record fragment (381 bytes)
> Debug : (3,1) eap - [eap-tls process] = handled
> Debug : (3,1) eap - Submodule eap_peap returned
> Debug : (3,1) eap - Sending EAP Request (code 1) ID 4 length 387
> Debug : (3,1) eap (handled)
> Debug : (3,1) } # authenticate eap (handled)
> Debug : (3,1) Running 'send Access-Challenge' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (3,1) send Access-Challenge {
> Debug : (3,1) handled (handled)
> Debug : (3,1) } # send Access-Challenge (handled)
> Debug : (3,1) Sent code 11 Id 138 from 172.18.0.3:1812 to 192.168.117.1:38107 via eth0 length 0
> Debug : (3,1) EAP-Message = 0x010401831900fbbaf15e1a3e293a327e82d010cdd49f3559bc29d02fce116a258446e8ce9e7c6402160303014d0c0001490300174104c93a5787ae35adc6bfd9144e20cbd8c58d75f48444ac828c73bd949feb7ebeebbff328c4a6644b8457428236836e716b45b93b17da3baf4d6f7b2120842697f106010100afec75a99af69478fadfad73b6701bf7cfc54b93229339b7ee3951e6f3b94605ddd6046fca2f431ef26238ce43e2a1c69064aa8fb8708039eb596418c184689220a6baea52deb8fbc6c4fe33f4611b1f8fc13ecc133da24a2d2083836886d65341c4bea240fd325cc7c2a6fcb3af220bcbae77fe456e8ba8fcf133e12e9e113821d1fddf56d097ab8bb4c3f6bab8a26ab464041b141bdf99b76f1fc49be4ce44348d8e0ccd7dbc5533cffd6275665dd3606d1bb2a10d3a56d9aacb155522b3344442f9a1d6f65692b84f50b7a90f11cfbbf98b3ddc661a05f83af3c80a0fb11310c467cbb8aaf896d56584fd85d3d91f1d02b3eca5af419230a2539c6eb55de316030300040e000000
> Debug : (3,1) Message-Authenticator = 0x00000000000000000000000000000000
> Debug : (3,1) State = 0x65d194cfa08ad2d79bedf3ecee9534ae
> Debug : (3) done request
> Debug : (3) finished request.
> Debug : Waking up in 4.9 seconds.
> Debug : Waking up in 4.9 seconds.
> Debug : Waking up in 4.9 seconds.
> Debug : Network received packet size 273
> Debug : Waking up in 4.9 seconds.
> Debug : (4) running request
> Debug : (4) Received Access-Request ID 139
> Debug : (4) User-Name = "root"
> Debug : (4) NAS-IP-Address = 192.168.117.1
> Debug : (4) NAS-Identifier = "RalinkAP0"
> Debug : (4) NAS-Port = 0
> Debug : (4) Called-Station-Id = "C0-25-E9-4C-71-36"
> Debug : (4) Calling-Station-Id = "7C-B0-C2-74-6C-CE"
> Debug : (4) Framed-MTU = 1400
> Debug : (4) NAS-Port-Type = Wireless-802.11
> Debug : (4) EAP-Message = 0x0204008819800000007e1603030046100000424104da13159aa0ac86434cc6d7f84ecc35ed7a8c1e8b5d283b5379eb6fbab21da0c36bb0947adb8f3fd8403c490d694a8ad709f5c273173af8224f565a76dc1d0e961403030001011603030028a067af59dd1d68664ec57e42d6ea2cadf396a82902ecae3ca160a3f43ae92520b121198f8cd39a20
> Debug : (4) State = 0x65d194cfa08ad2d79bedf3ecee9534ae
> Debug : (4) Message-Authenticator = 0x2abbb039a268c2a0f7c29a349ed6ee03
> Debug : (4,1) Running 'recv Access-Request' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (4,1) recv Access-Request {
> Debug : (4,1) chap (noop)
> Debug : (4,1) mschap (noop)
> Debug : (4,1) eap - Peer sent EAP Response (code 2) ID 4 length 136
> Debug : (4,1) eap - Continuing tunnel setup
> Debug : (4,1) eap (ok)
> Debug : (4,1) } # recv Access-Request (ok)
> Debug : (4,1) Running 'authenticate eap' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (4,1) authenticate eap {
> Debug : (4,1) eap - Peer sent packet with EAP method PEAP (25)
> Debug : (4,1) eap - Calling submodule eap_peap
> Debug : (4,1) eap - Continuing EAP-TLS
> Debug : (4,1) eap - Peer indicated complete TLS record size will be 126 bytes
> Debug : (4,1) eap - Got complete TLS record, with length field (126 bytes)
> Debug : (4,1) eap - [eap-tls verify] = complete
> Debug : (4,1) eap - Handshake state - Server SSLv3/TLS write server done
> Debug : (4,1) eap - <<< recv TLS 1.2 handshake [length 70], client_key_exchange
> Debug : (4,1) eap - Handshake state - Server SSLv3/TLS read client key exchange
> Debug : (4,1) eap - Handshake state - Server SSLv3/TLS read change cipher spec
> Debug : (4,1) eap - <<< recv TLS 1.2 handshake [length 16], finished
> Debug : (4,1) eap - Handshake state - Server SSLv3/TLS read finished
> Debug : (4,1) eap - >>> send TLS 1.2 change_cipher_spec [length 1]
> Debug : (4,1) eap - Handshake state - Server SSLv3/TLS write change cipher spec
> Debug : (4,1) eap - >>> send TLS 1.2 handshake [length 16], finished
> Debug : (4,1) eap - Handshake state - Server SSLv3/TLS write finished
> Debug : (4,1) eap - Handshake state - SSL negotiation finished successfully
> Debug : (4,1) eap - Cipher suite: CDHE-RSA-AES256-GCM-SHA384 TLSv1.2 Kx=ECDH Au=RSA Enc=AESGCM(256) Mac=AEAD
> Debug : (4,1) eap - Sending complete TLS record (51 bytes)
> Debug : (4,1) eap - [eap-tls process] = handled
> Debug : (4,1) eap - Submodule eap_peap returned
> Debug : (4,1) eap - Sending EAP Request (code 1) ID 5 length 57
> Debug : (4,1) eap (handled)
> Debug : (4,1) } # authenticate eap (handled)
> Debug : (4,1) Running 'send Access-Challenge' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (4,1) send Access-Challenge {
> Debug : (4,1) handled (handled)
> Debug : (4,1) } # send Access-Challenge (handled)
> Debug : (4,1) Sent code 11 Id 139 from 172.18.0.3:1812 to 192.168.117.1:38107 via eth0 length 0
> Debug : (4,1) EAP-Message = 0x01050039190014030300010116030300280b604285400b205afdec0353bedec29d892baf11dde8bd350919c83674207294df0ddb99275a7b1e
> Debug : (4,1) Message-Authenticator = 0x00000000000000000000000000000000
> Debug : (4,1) State = 0x178ff424c1fbc3000969a78129d34a8f
> Debug : (4) done request
> Debug : (4) finished request.
> Debug : Waking up in 4.9 seconds.
> Debug : Waking up in 4.9 seconds.
> Debug : Waking up in 4.9 seconds.
> Debug : Network received packet size 143
> Debug : Waking up in 4.9 seconds.
> Debug : (5) running request
> Debug : (5) Received Access-Request ID 140
> Debug : (5) User-Name = "root"
> Debug : (5) NAS-IP-Address = 192.168.117.1
> Debug : (5) NAS-Identifier = "RalinkAP0"
> Debug : (5) NAS-Port = 0
> Debug : (5) Called-Station-Id = "C0-25-E9-4C-71-36"
> Debug : (5) Calling-Station-Id = "7C-B0-C2-74-6C-CE"
> Debug : (5) Framed-MTU = 1400
> Debug : (5) NAS-Port-Type = Wireless-802.11
> Debug : (5) EAP-Message = 0x020500061900
> Debug : (5) State = 0x178ff424c1fbc3000969a78129d34a8f
> Debug : (5) Message-Authenticator = 0x4554a700ca22859f544c194d9bdb71d0
> Debug : (5,1) Running 'recv Access-Request' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (5,1) recv Access-Request {
> Debug : (5,1) chap (noop)
> Debug : (5,1) mschap (noop)
> Debug : (5,1) eap - Peer sent EAP Response (code 2) ID 5 length 6
> Debug : (5,1) eap - Continuing tunnel setup
> Debug : (5,1) eap (ok)
> Debug : (5,1) } # recv Access-Request (ok)
> Debug : (5,1) Running 'authenticate eap' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (5,1) authenticate eap {
> Debug : (5,1) eap - Peer sent packet with EAP method PEAP (25)
> Debug : (5,1) eap - Calling submodule eap_peap
> Debug : (5,1) eap - Continuing EAP-TLS
> Debug : (5,1) eap - Peer ACKed our handshake fragment. handshake is finished
> Debug : (5,1) eap - [eap-tls verify] = established
> Debug : (5,1) eap - [eap-tls process] = established
> Debug : (5,1) eap - Session established. Decoding tunneled data
> Debug : (5,1) eap - PEAP state TUNNEL ESTABLISHED
> Debug : (5,1) eap - TLS application data to encrypt (5 bytes)
> Debug : (5,1) eap - Sending complete TLS record (34 bytes)
> Debug : (5,1) eap - Submodule eap_peap returned
> Debug : (5,1) eap - Sending EAP Request (code 1) ID 6 length 40
> Debug : (5,1) eap (handled)
> Debug : (5,1) } # authenticate eap (handled)
> Debug : (5,1) Running 'send Access-Challenge' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (5,1) send Access-Challenge {
> Debug : (5,1) handled (handled)
> Debug : (5,1) } # send Access-Challenge (handled)
> Debug : (5,1) Sent code 11 Id 140 from 172.18.0.3:1812 to 192.168.117.1:38107 via eth0 length 0
> Debug : (5,1) EAP-Message = 0x010600281900170303001d0b604285400b205b40e47b90a19c022cc58cf77d2435bd2dbdde93d7fe
> Debug : (5,1) Message-Authenticator = 0x00000000000000000000000000000000
> Debug : (5,1) State = 0xdd9d61181528ed51c335dd222177283e
> Debug : (5) done request
> Debug : (5) finished request.
> Debug : Waking up in 4.9 seconds.
> Debug : Waking up in 4.9 seconds.
> Debug : Waking up in 4.9 seconds.
> Debug : Network received packet size 177
> Debug : Waking up in 4.9 seconds.
> Debug : (6) running request
> Debug : (6) Received Access-Request ID 141
> Debug : (6) User-Name = "root"
> Debug : (6) NAS-IP-Address = 192.168.117.1
> Debug : (6) NAS-Identifier = "RalinkAP0"
> Debug : (6) NAS-Port = 0
> Debug : (6) Called-Station-Id = "C0-25-E9-4C-71-36"
> Debug : (6) Calling-Station-Id = "7C-B0-C2-74-6C-CE"
> Debug : (6) Framed-MTU = 1400
> Debug : (6) NAS-Port-Type = Wireless-802.11
> Debug : (6) EAP-Message = 0x020600281900170303001da067af59dd1d6867587c3781f68700da3b1714b7feb2c17fc21e538221
> Debug : (6) State = 0xdd9d61181528ed51c335dd222177283e
> Debug : (6) Message-Authenticator = 0x9b212313562c103adc03cd269bba419a
> Debug : (6,1) Running 'recv Access-Request' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (6,1) recv Access-Request {
> Debug : (6,1) chap (noop)
> Debug : (6,1) mschap (noop)
> Debug : (6,1) eap - Peer sent EAP Response (code 2) ID 6 length 40
> Debug : (6,1) eap - Continuing tunnel setup
> Debug : (6,1) eap (ok)
> Debug : (6,1) } # recv Access-Request (ok)
> Debug : (6,1) Running 'authenticate eap' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (6,1) authenticate eap {
> Debug : (6,1) eap - Peer sent packet with EAP method PEAP (25)
> Debug : (6,1) eap - Calling submodule eap_peap
> Debug : (6,1) eap - Continuing EAP-TLS
> Debug : (6,1) eap - Got complete TLS record (34 bytes)
> Debug : (6,1) eap - [eap-tls verify] = complete
> Debug : (6,1) eap - Decrypted TLS application data (5 bytes)
> Debug : (6,1) eap - [eap-tls process] = complete
> Debug : (6,1) eap - Session established. Decoding tunneled data
> Debug : (6,1) eap - PEAP state WAITING FOR INNER IDENTITY
> Debug : (6,1) eap - Received EAP-Identity-Response
> Debug : (6,1) eap - Got inner identity 'root'
> Debug : (6,1) eap - Got tunneled request
> Debug : (6,1) eap - &EAP-Message = 0x0206000901726f6f74
> Debug : (6,1) eap - Setting &request:User-Name from tunneled (inner) identity "root"
> Debug : (6,1) eap - Proxying tunneled request to virtual server "peap-tunnel"
> Debug : (6.0) Virtual server peap-tunnel received request
> Debug : (6.0) &EAP-Message = 0x0206000901726f6f74
> Debug : (6.0) &FreeRADIUS-Proxied-To = 127.0.0.1
> Debug : (6.0) &User-Name = "root"
> WARN : (6.0) WARNING: Outer and inner identities are the same. User privacy is compromised.
> Debug : (6.0) server peap-tunnel {
> Debug : (6.0) Received Access-Request ID 0
> Debug : (6.0) EAP-Message = 0x0206000901726f6f74
> Debug : (6.0) FreeRADIUS-Proxied-To = 127.0.0.1
> Debug : (6.0) User-Name = "root"
> Debug : (6.0) Running 'recv Access-Request' from file /opt/freeradius/etc/raddb/server.conf
> Debug : (6.0) recv Access-Request {
> Debug : (6.0) eap - Peer sent EAP Response (code 2) ID 6 length 9
> Debug : (6.0) eap - Peer sent EAP-Identity. Returning 'ok' so we can short-circuit the rest of authorize
> Debug : (6.0) eap (ok)
> Debug : (6.0) } # recv Access-Request (ok)
> Debug : (6.0) Running 'authenticate eap' from file /opt/freeradius/etc/raddb/server.conf
> Debug : (6.0) authenticate eap {
> Debug : (6.0) eap-inner - Peer sent packet with EAP method Identity (1)
> Debug : (6.0) eap-inner - Calling submodule eap_md5
> Debug : (6.0) eap-inner - Issuing MD5 Challenge
> Debug : (6.0) eap-inner - Submodule eap_md5 returned
> Debug : (6.0) eap-inner - Sending EAP Request (code 1) ID 7 length 22
> Debug : (6.0) eap-inner (handled)
> Debug : (6.0) } # authenticate eap (handled)
> Debug : (6.0) Sent Access-Challenge ID 0
> Debug : (6.0) EAP-Message = 0x0107001604109cfc58244b118bafdb8fd01345521f6c
> Debug : (6.0) Message-Authenticator = 0x00000000000000000000000000000000
> Debug : (6.0) } # server peap-tunnel
> Debug : (6,1) eap - Got tunneled reply Access-Challenge
> Debug : (6,1) eap - &EAP-Message = 0x0107001604109cfc58244b118bafdb8fd01345521f6c
> Debug : (6,1) eap - &Message-Authenticator = 0x00000000000000000000000000000000
> Debug : (6,1) eap - Got tunneled Access-Challenge
> Debug : (6,1) eap - TLS application data to encrypt (18 bytes)
> Debug : (6,1) eap - Sending complete TLS record (47 bytes)
> Debug : (6,1) eap - Submodule eap_peap returned
> Debug : (6,1) eap - Sending EAP Request (code 1) ID 7 length 53
> Debug : (6,1) eap (handled)
> Debug : (6,1) } # authenticate eap (handled)
> Debug : (6,1) Running 'send Access-Challenge' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (6,1) send Access-Challenge {
> Debug : (6,1) handled (handled)
> Debug : (6,1) } # send Access-Challenge (handled)
> Debug : (6,1) Sent code 11 Id 141 from 172.18.0.3:1812 to 192.168.117.1:38107 via eth0 length 0
> Debug : (6,1) EAP-Message = 0x010700351900170303002a0b604285400b205c76d2346d2235bbf7b944cc355d686b3e2a62ea956f493e98cfe29ccaf14ed1ee85b5
> Debug : (6,1) Message-Authenticator = 0x00000000000000000000000000000000
> Debug : (6,1) State = 0x952878a5d2bbbd5b27d1d926f44fdfdc
> Debug : (6) done request
> Debug : (6) finished request.
> Debug : Waking up in 4.9 seconds.
> Debug : Waking up in 4.9 seconds.
> Debug : Waking up in 4.9 seconds.
> Debug : Network received packet size 174
> Debug : Waking up in 4.9 seconds.
> Debug : (7) running request
> Debug : (7) Received Access-Request ID 142
> Debug : (7) User-Name = "root"
> Debug : (7) NAS-IP-Address = 192.168.117.1
> Debug : (7) NAS-Identifier = "RalinkAP0"
> Debug : (7) NAS-Port = 0
> Debug : (7) Called-Station-Id = "C0-25-E9-4C-71-36"
> Debug : (7) Calling-Station-Id = "7C-B0-C2-74-6C-CE"
> Debug : (7) Framed-MTU = 1400
> Debug : (7) NAS-Port-Type = Wireless-802.11
> Debug : (7) EAP-Message = 0x020700251900170303001aa067af59dd1d6868ff062c2574f115f2435d32563b9caccf379a
> Debug : (7) State = 0x952878a5d2bbbd5b27d1d926f44fdfdc
> Debug : (7) Message-Authenticator = 0x24a5855266a45af7159e746a1d408543
> Debug : (7,1) Running 'recv Access-Request' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (7,1) recv Access-Request {
> Debug : (7,1) chap (noop)
> Debug : (7,1) mschap (noop)
> Debug : (7,1) eap - Peer sent EAP Response (code 2) ID 7 length 37
> Debug : (7,1) eap - Continuing tunnel setup
> Debug : (7,1) eap (ok)
> Debug : (7,1) } # recv Access-Request (ok)
> Debug : (7,1) Running 'authenticate eap' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (7,1) authenticate eap {
> Debug : (7,1) eap - Peer sent packet with EAP method PEAP (25)
> Debug : (7,1) eap - Calling submodule eap_peap
> Debug : (7,1) eap - Continuing EAP-TLS
> Debug : (7,1) eap - Got complete TLS record (31 bytes)
> Debug : (7,1) eap - [eap-tls verify] = complete
> Debug : (7,1) eap - Decrypted TLS application data (2 bytes)
> Debug : (7,1) eap - [eap-tls process] = complete
> Debug : (7,1) eap - Session established. Decoding tunneled data
> Debug : (7,1) eap - PEAP state phase2
> Debug : (7,1) eap - EAP method NAK (3)
> Debug : (7,1) eap - Got tunneled request
> Debug : (7,1) eap - &EAP-Message = 0x02070006031a
> Debug : (7,1) eap - Setting &request:User-Name from tunneled (inner) identity "root"
> Debug : (7,1) eap - Proxying tunneled request to virtual server "peap-tunnel"
> Debug : (7.0) Virtual server peap-tunnel received request
> Debug : (7.0) &EAP-Message = 0x02070006031a
> Debug : (7.0) &FreeRADIUS-Proxied-To = 127.0.0.1
> Debug : (7.0) &User-Name = "root"
> WARN : (7.0) WARNING: Outer and inner identities are the same. User privacy is compromised.
> Debug : (7.0) server peap-tunnel {
> Debug : (7.0) Received Access-Request ID 0
> Debug : (7.0) EAP-Message = 0x02070006031a
> Debug : (7.0) FreeRADIUS-Proxied-To = 127.0.0.1
> Debug : (7.0) User-Name = "root"
> Debug : (7.0) Running 'recv Access-Request' from file /opt/freeradius/etc/raddb/server.conf
> Debug : (7.0) recv Access-Request {
> Debug : (7.0) eap - Peer sent EAP Response (code 2) ID 7 length 6
> Debug : (7.0) eap - Continuing on-going EAP conversation
> Debug : (7.0) eap (updated)
> Debug : (7.0) sql - EXPAND %{User-Name}
> Debug : (7.0) sql - --> root
> Debug : (7.0) sql - SQL-User-Name set to 'root'
> Debug : (7.0) sql - Reserved connection (5)
> Debug : (7.0) sql - EXPAND SELECT uuid as id, login as UserName, 'Cleartext-Password' as Attribute, password as Value , ':=' as Op FROM login WHERE login = 'root' ORDER BY uuid
> Debug : (7.0) sql - --> SELECT uuid as id, login as UserName, 'Cleartext-Password' as Attribute, password as Value , ':=' as Op FROM login WHERE login = 'root' ORDER BY uuid
> Debug : (7.0) sql - Executing select query: SELECT uuid as id, login as UserName, 'Cleartext-Password' as Attribute, password as Value , ':=' as Op FROM login WHERE login = 'root' ORDER BY uuid
> Debug : rlm_sql_postgresql - Status: PGRES_TUPLES_OK
> Debug : rlm_sql_postgresql - query affected rows = 1 , fields = 5
> Debug : (7.0) sql - User found in radcheck table
> Debug : (7.0) sql - Conditional check items matched, merging assignment check items
> Debug : (7.0) sql - &Cleartext-Password := "admin"
> Debug : (7.0) sql - Released connection (5)
> Info : (7.0) sql - Need 2 more connections to reach min connections (3)
> Debug : (7.0) sql - Opening additional connection (6), 1 of 31 pending slots used
> Debug : rlm_sql_postgresql - Connecting using parameters: host=postgres port=5432 dbname=billing user=radius password=raddpass application_name='FreeRADIUS 4.0.0 - radiusd (sql)'
> Debug : rlm_sql_postgresql - Connected to database 'billing' on 'postgres' server version 100003, protocol version 3, backend PID 679
> Debug : (7.0) sql - Closing expired connection (5): Needs reconnecting
> Debug : (7.0) sql - You probably need to lower "min"
> Debug : rlm_sql_postgresql - Socket destructor called, closing socket
> Debug : (7.0) sql (ok)
> Debug : (7.0) } # recv Access-Request (updated)
> Debug : (7.0) Running 'authenticate eap' from file /opt/freeradius/etc/raddb/server.conf
> Debug : (7.0) authenticate eap {
> Debug : (7.0) eap-inner - Peer sent packet with EAP method NAK (3)
> Debug : (7.0) eap-inner - Found mutually acceptable type MSCHAPv2 (26)
> Debug : (7.0) eap-inner - Calling submodule eap_mschapv2
> Debug : (7.0) eap-inner - Issuing Challenge
> Debug : (7.0) eap-inner - Submodule eap_mschapv2 returned
> Debug : (7.0) eap-inner - Sending EAP Request (code 1) ID 8 length 29
> Debug : (7.0) eap-inner (handled)
> Debug : (7.0) } # authenticate eap (handled)
> Debug : (7.0) Sent Access-Challenge ID 0
> Debug : (7.0) EAP-Message = 0x0108001d1a01080018103d41d0780eb5da44fe1364d75e0393ac554e41
> Debug : (7.0) Message-Authenticator = 0x00000000000000000000000000000000
> Debug : (7.0) } # server peap-tunnel
> Debug : (7,1) eap - Got tunneled reply Access-Challenge
> Debug : (7,1) eap - &EAP-Message = 0x0108001d1a01080018103d41d0780eb5da44fe1364d75e0393ac554e41
> Debug : (7,1) eap - &Message-Authenticator = 0x00000000000000000000000000000000
> Debug : (7,1) eap - Got tunneled Access-Challenge
> Debug : (7,1) eap - TLS application data to encrypt (25 bytes)
> Debug : (7,1) eap - Sending complete TLS record (54 bytes)
> Debug : (7,1) eap - Submodule eap_peap returned
> Debug : (7,1) eap - Sending EAP Request (code 1) ID 8 length 60
> Debug : (7,1) eap (handled)
> Debug : (7,1) } # authenticate eap (handled)
> Debug : (7,1) Running 'send Access-Challenge' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (7,1) send Access-Challenge {
> Debug : (7,1) handled (handled)
> Debug : (7,1) } # send Access-Challenge (handled)
> Debug : (7,1) Sent code 11 Id 142 from 172.18.0.3:1812 to 192.168.117.1:38107 via eth0 length 0
> Debug : (7,1) EAP-Message = 0x0108003c190017030300310b604285400b205db520709c48fa87df49eefddb448560fafb40fe0ca53a93279c9b72cc5d22f093757bf40da9a76a986d
> Debug : (7,1) Message-Authenticator = 0x00000000000000000000000000000000
> Debug : (7,1) State = 0xa2b9a122d310a2ebcec21c99f9293684
> Debug : (7) done request
> Debug : (7) finished request.
> Debug : Waking up in 4.9 seconds.
> Debug : Waking up in 4.9 seconds.
> Debug : Waking up in 4.9 seconds.
> Debug : Network received packet size 231
> Debug : Waking up in 4.9 seconds.
> Debug : (8) running request
> Debug : (8) Received Access-Request ID 143
> Debug : (8) User-Name = "root"
> Debug : (8) NAS-IP-Address = 192.168.117.1
> Debug : (8) NAS-Identifier = "RalinkAP0"
> Debug : (8) NAS-Port = 0
> Debug : (8) Called-Station-Id = "C0-25-E9-4C-71-36"
> Debug : (8) Calling-Station-Id = "7C-B0-C2-74-6C-CE"
> Debug : (8) Framed-MTU = 1400
> Debug : (8) NAS-Port-Type = Wireless-802.11
> Debug : (8) EAP-Message = 0x0208005e19001703030053a067af59dd1d6869898cd60cc2638f8d3d61deca0b4aeb0c15eb65833df12dbfb27832b3a3778e8149a1d119544b19e907e1dd987f0f231ec075c98060358c39ad3a8a3c51956a852feed12ddba47cbbb5d2bd
> Debug : (8) State = 0xa2b9a122d310a2ebcec21c99f9293684
> Debug : (8) Message-Authenticator = 0x03584e211552b8a5c47e114fb0874e34
> Debug : (8,1) Running 'recv Access-Request' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (8,1) recv Access-Request {
> Debug : (8,1) chap (noop)
> Debug : (8,1) mschap (noop)
> Debug : (8,1) eap - Peer sent EAP Response (code 2) ID 8 length 94
> Debug : (8,1) eap - Continuing tunnel setup
> Debug : (8,1) eap (ok)
> Debug : (8,1) } # recv Access-Request (ok)
> Debug : (8,1) Running 'authenticate eap' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (8,1) authenticate eap {
> Debug : (8,1) eap - Peer sent packet with EAP method PEAP (25)
> Debug : (8,1) eap - Calling submodule eap_peap
> Debug : (8,1) eap - Continuing EAP-TLS
> Debug : (8,1) eap - Got complete TLS record (88 bytes)
> Debug : (8,1) eap - [eap-tls verify] = complete
> Debug : (8,1) eap - Decrypted TLS application data (59 bytes)
> Debug : (8,1) eap - [eap-tls process] = complete
> Debug : (8,1) eap - Session established. Decoding tunneled data
> Debug : (8,1) eap - PEAP state phase2
> Debug : (8,1) eap - EAP method MSCHAPv2 (26)
> Debug : (8,1) eap - Got tunneled request
> Debug : (8,1) eap - &EAP-Message = 0x0208003f1a0208003a31263c0d593e3e8477431b6be93d5a0a69000000000000000060fc0b3e58ab7f4eed03c5f8acb1b88e01740259f4ac63dc00726f6f74
> Debug : (8,1) eap - Setting &request:User-Name from tunneled (inner) identity "root"
> Debug : (8,1) eap - Proxying tunneled request to virtual server "peap-tunnel"
> Debug : (8.0) Virtual server peap-tunnel received request
> Debug : (8.0) &EAP-Message = 0x0208003f1a0208003a31263c0d593e3e8477431b6be93d5a0a69000000000000000060fc0b3e58ab7f4eed03c5f8acb1b88e01740259f4ac63dc00726f6f74
> Debug : (8.0) &FreeRADIUS-Proxied-To = 127.0.0.1
> Debug : (8.0) &User-Name = "root"
> WARN : (8.0) WARNING: Outer and inner identities are the same. User privacy is compromised.
> Debug : (8.0) server peap-tunnel {
> Debug : (8.0) Received Access-Request ID 0
> Debug : (8.0) EAP-Message = 0x0208003f1a0208003a31263c0d593e3e8477431b6be93d5a0a69000000000000000060fc0b3e58ab7f4eed03c5f8acb1b88e01740259f4ac63dc00726f6f74
> Debug : (8.0) FreeRADIUS-Proxied-To = 127.0.0.1
> Debug : (8.0) User-Name = "root"
> Debug : (8.0) Running 'recv Access-Request' from file /opt/freeradius/etc/raddb/server.conf
> Debug : (8.0) recv Access-Request {
> Debug : (8.0) eap - Peer sent EAP Response (code 2) ID 8 length 63
> Debug : (8.0) eap - Continuing on-going EAP conversation
> Debug : (8.0) eap (updated)
> Debug : (8.0) sql - EXPAND %{User-Name}
> Debug : (8.0) sql - --> root
> Debug : (8.0) sql - SQL-User-Name set to 'root'
> Debug : (8.0) sql - Reserved connection (6)
> Debug : (8.0) sql - EXPAND SELECT uuid as id, login as UserName, 'Cleartext-Password' as Attribute, password as Value , ':=' as Op FROM login WHERE login = 'root' ORDER BY uuid
> Debug : (8.0) sql - --> SELECT uuid as id, login as UserName, 'Cleartext-Password' as Attribute, password as Value , ':=' as Op FROM login WHERE login = 'root' ORDER BY uuid
> Debug : (8.0) sql - Executing select query: SELECT uuid as id, login as UserName, 'Cleartext-Password' as Attribute, password as Value , ':=' as Op FROM login WHERE login = 'root' ORDER BY uuid
> Debug : rlm_sql_postgresql - Status: PGRES_TUPLES_OK
> Debug : rlm_sql_postgresql - query affected rows = 1 , fields = 5
> Debug : (8.0) sql - User found in radcheck table
> Debug : (8.0) sql - Conditional check items matched, merging assignment check items
> Debug : (8.0) sql - &Cleartext-Password := "admin"
> Debug : (8.0) sql - Released connection (6)
> Debug : (8.0) sql (ok)
> Debug : (8.0) } # recv Access-Request (updated)
> Debug : (8.0) Running 'authenticate eap' from file /opt/freeradius/etc/raddb/server.conf
> Debug : (8.0) authenticate eap {
> Debug : (8.0) eap-inner - Peer sent packet with EAP method MSCHAPv2 (26)
> Debug : (8.0) eap-inner - Calling submodule eap_mschapv2
> Debug : (8.0) eap-inner - Empty authenticate section in virtual server "peap-tunnel". Using default return value (reject)
> Debug : (8.0) eap-inner - Submodule eap_mschapv2 returned
> Debug : (8.0) eap-inner - Sending EAP Failure (code 4) ID 8 length 4
> Debug : (8.0) eap-inner - Cleaning up EAP session
> Debug : (8.0) eap-inner (reject)
> Debug : (8.0) } # authenticate eap (reject)
> Debug : (8.0) Failed to authenticate the user
> Auth : (8.0) Login incorrect: [root] (from client RalinkAP0 port 0 via proxy to virtual server)
> Debug : (8.0) Sent Access-Reject ID 0
> Debug : (8.0) EAP-Message = 0x04080004
> Debug : (8.0) Message-Authenticator = 0x00000000000000000000000000000000
> Debug : (8.0) } # server peap-tunnel
> Debug : (8,1) eap - Got tunneled reply Access-Reject
> Debug : (8,1) eap - &EAP-Message = 0x04080004
> Debug : (8,1) eap - &Message-Authenticator = 0x00000000000000000000000000000000
> Debug : (8,1) eap - Tunneled authentication was rejected
> Debug : (8,1) eap - FAILURE
> Debug : (8,1) eap - TLS application data to encrypt (11 bytes)
> Debug : (8,1) eap - Sending complete TLS record (40 bytes)
> Debug : (8,1) eap - Submodule eap_peap returned
> Debug : (8,1) eap - Sending EAP Request (code 1) ID 9 length 46
> Debug : (8,1) eap (handled)
> Debug : (8,1) } # authenticate eap (handled)
> Debug : (8,1) Running 'send Access-Challenge' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (8,1) send Access-Challenge {
> Debug : (8,1) handled (handled)
> Debug : (8,1) } # send Access-Challenge (handled)
> Debug : (8,1) Sent code 11 Id 143 from 172.18.0.3:1812 to 192.168.117.1:38107 via eth0 length 0
> Debug : (8,1) EAP-Message = 0x0109002e190017030300230b604285400b205e1172f1d017a3d121e8b13c1e0a94597c55090a3d212d38322e7402
> Debug : (8,1) Message-Authenticator = 0x00000000000000000000000000000000
> Debug : (8,1) State = 0x8af9a0eafbad677fea529a5f34932034
> Debug : (8) done request
> Debug : (8) finished request.
> Debug : Waking up in 4.9 seconds.
> Debug : Waking up in 4.9 seconds.
> Debug : Waking up in 4.9 seconds.
> Debug : Network received packet size 183
> Debug : Waking up in 4.9 seconds.
> Debug : (9) running request
> Debug : (9) Received Access-Request ID 144
> Debug : (9) User-Name = "root"
> Debug : (9) NAS-IP-Address = 192.168.117.1
> Debug : (9) NAS-Identifier = "RalinkAP0"
> Debug : (9) NAS-Port = 0
> Debug : (9) Called-Station-Id = "C0-25-E9-4C-71-36"
> Debug : (9) Calling-Station-Id = "7C-B0-C2-74-6C-CE"
> Debug : (9) Framed-MTU = 1400
> Debug : (9) NAS-Port-Type = Wireless-802.11
> Debug : (9) EAP-Message = 0x0209002e19001703030023a067af59dd1d686a0b857024c375deaeff75be1164607b6caa4ed6738a9e81a79712c4
> Debug : (9) State = 0x8af9a0eafbad677fea529a5f34932034
> Debug : (9) Message-Authenticator = 0x316492614b92a839a8e8d5ad0ba4e2b5
> Debug : (9,1) Running 'recv Access-Request' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (9,1) recv Access-Request {
> Debug : (9,1) chap (noop)
> Debug : (9,1) mschap (noop)
> Debug : (9,1) eap - Peer sent EAP Response (code 2) ID 9 length 46
> Debug : (9,1) eap - Continuing tunnel setup
> Debug : (9,1) eap (ok)
> Debug : (9,1) } # recv Access-Request (ok)
> Debug : (9,1) Running 'authenticate eap' from file /opt/freeradius/etc/raddb/auth.conf
> Debug : (9,1) authenticate eap {
> Debug : (9,1) eap - Peer sent packet with EAP method PEAP (25)
> Debug : (9,1) eap - Calling submodule eap_peap
> Debug : (9,1) eap - Continuing EAP-TLS
> Debug : (9,1) eap - Got complete TLS record (40 bytes)
> Debug : (9,1) eap - [eap-tls verify] = complete
> Debug : (9,1) eap - Decrypted TLS application data (11 bytes)
> Debug : (9,1) eap - [eap-tls process] = complete
> Debug : (9,1) eap - Session established. Decoding tunneled data
> Debug : (9,1) eap - PEAP state send tlv failure
> ERROR : (9,1) eap - ERROR: The users session was previously rejected: returning reject (again.)
> : (9,1) eap - This means you need to read the PREVIOUS messages in the debug output
> : (9,1) eap - to find out the reason why the user was rejected
> : (9,1) eap - Look for "reject" or "fail". Those earlier messages will tell you
> : (9,1) eap - what went wrong, and how to fix the problem
> Debug : (9,1) eap - Submodule eap_peap returned
> Debug : (9,1) eap - Sending EAP Failure (code 4) ID 9 length 4
> Debug : (9,1) eap - Cleaning up EAP session
> Debug : (9,1) eap (reject)
> Debug : (9,1) } # authenticate eap (reject)
> Debug : (9,1) Failed to authenticate the user
> Auth : (9,1) Login incorrect (eap: The users session was previously rejected: returning reject (again.)): [root] (from client RalinkAP0 port 0 cli 7C-B0-C2-74-6C-CE)
> Debug : (9,1) Sent code 3 Id 144 from 172.18.0.3:1812 to 192.168.117.1:38107 via eth0 length 0
> Debug : (9,1) EAP-Message = 0x04090004
> Debug : (9,1) Message-Authenticator = 0x00000000000000000000000000000000
> Debug : (9) done request
> Debug : (9) finished request.
> Debug : Waking up in 4.9 seconds.
> Debug : Waking up in 4.9 seconds.
> Debug : Waking up in 4.9 seconds.
> Debug : TIMER - proto_radius cleanup delay for ID 136
> Debug : TIMER - proto_radius cleanup delay for ID 137
> Debug : TIMER - proto_radius cleanup delay for ID 138
> Debug : TIMER - proto_radius cleanup delay for ID 139
> Debug : TIMER - proto_radius cleanup delay for ID 140
> Debug : TIMER - proto_radius cleanup delay for ID 141
> Debug : TIMER - proto_radius cleanup delay for ID 142
> Debug : TIMER - proto_radius cleanup delay for ID 143
> Debug : TIMER - proto_radius cleanup delay for ID 144
> Debug : Waking up in 23.5 seconds.
> Debug : TIMER - worker max_request_time
> Debug : Waking up in 3570.3 seconds.
>
> --
> Best regards, Aleksandr Stepanov.
>
> 20.03.2018, 17:49, "Aleksandr Stepanov" <alex-eri at ya.ru>:
>> my config was copied from v3 =)
>> v4 has this section!
>>
>> thanks
>>
>> --
>> Best regards, Aleksandr Stepanov.
>>
>> 20.03.2018, 17:44, "Aleksandr Stepanov" <alex-eri at ya.ru>:
>>> This file listed in my first message and it has all subsections.
>>>
>>> I found problem.
>>>
>>> Eap module also need included:
>>>
>>> type = md5
>>> type = mschapv2
>>> type = peap
>>>
>>> This part is missed in default configuration for v4. Seems its ok if "eap-inner" loaded before "eap". Eap-inner has "type" lines and bootstraps submodules.
>>>
>>> --
>>> Best regards, Aleksandr Stepanov.
>>>
>>> 20.03.2018, 17:35, "Matthew Newton" <mcn at freeradius.org>:
>>>> On Tue, 2018-03-20 at 17:25 +0300, Aleksandr Stepanov wrote:
>>>>> Debug : Including configuration file "/opt/freeradius/etc/raddb/mods-
>>>>> enabled/eap"
>>>>
>>>> Check "/opt/freeradius/etc/raddb/mods-enabled/eap", and make sure it
>>>> contains the full default eap config.
>>>>
>>>> It's missing all the peap{}, tls{}, etc sections.
>>>>
>>>> --
>>>> Matthew
>>>>
>>>> -
>>>> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
>>>
>>> -
>>> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
>>
>> -
>> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
>
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
More information about the Freeradius-Users
mailing list