openwrt, freeradius,

20 Apr 2016

      My English not well... So Im sorry.

OpenWrt Chaos Calmer 15.05
freeradius 2.2.8-2

Installed:
freeradius2 - 2.2.8-2
freeradius2-common - 2.2.8-2
freeradius2-democerts - 2.2.8-2
freeradius2-mod-always - 2.2.8-2
freeradius2-mod-chap - 2.2.8-2
freeradius2-mod-eap - 2.2.8-2
freeradius2-mod-eap-md5 - 2.2.8-2
freeradius2-mod-eap-mschapv2 - 2.2.8-2
freeradius2-mod-eap-peap - 2.2.8-2
freeradius2-mod-eap-tls - 2.2.8-2
freeradius2-mod-eap-ttls - 2.2.8-2
freeradius2-mod-exec - 2.2.8-2
freeradius2-mod-expr - 2.2.8-2
freeradius2-mod-files - 2.2.8-2
freeradius2-mod-mschap - 2.2.8-2
freeradius2-mod-pap - 2.2.8-2
freeradius2-mod-radutmp - 2.2.8-2
freeradius2-mod-realm - 2.2.8-2
freeradius2-utils - 2.2.8-2

IP-addres radius-server: 192.168.1.4
Wifi name: Openwrt
Model: TL-WR842ND, ver 2.0

IP-addres wifi station:  192.168.1.1
Wifi name: ROSTELECOM_8804B
Model: GPT-2542GNAUC

ca.pem add to "Trusted Root Centers" at computer.
I got ca.pem, from freeradius2-democerts.

Problem: when I connect to "Openwrt" all good. But if I connect to "ROSTELECOM_8804B". I got nothing after "Sending Access-Challenge of id 0 to 192.168.1.1".
I fast read   http://wiki.freeradius.org/guide/Certificate_Compatibility , but not deep into well, becouse I think certs from " freeradius2-democerts" is good. Am I right?
By the way, even if I tried did my own certs - I got it error too.

Do own certs like that:
openssl genrsa -des3 -out ca.key 2048
openssl req -new -x509 -days 3650 -key ca.key -out ca.pem
openssl genrsa -des3 -out server.key 2048
openssl req -new -key server.key -out server.csr
openssl x509 -req -days 3650 -in server.csr -CA ca.pem -CAkey ca.key -set_serial 01 -out server.pem

Maybe GPT-2542GNAUC doesnt work properly?

root@OpenWrt:/etc/freeradius2/certs# radiusd -XX
Tue Apr 19 16:22:20 2016 : Info: radiusd: FreeRADIUS Version 2.2.8, for host mips-openwrt-linux-gnu, built on Jan 4 2016 at 09:40:51
Tue Apr 19 16:22:20 2016 : Debug: Server was built with:
Tue Apr 19 16:22:20 2016 : Debug: accounting
Tue Apr 19 16:22:20 2016 : Debug: authentication
Tue Apr 19 16:22:20 2016 : Debug: WITH_DHCP
Tue Apr 19 16:22:20 2016 : Debug: WITH_VMPS
Tue Apr 19 16:22:20 2016 : Debug: Server core libs:
Tue Apr 19 16:22:20 2016 : Debug: ssl: OpenSSL 1.0.2g 1 Mar 2016
Tue Apr 19 16:22:20 2016 : Info: Copyright (C) 1999-2015 The FreeRADIUS server project and contributors.
Tue Apr 19 16:22:20 2016 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
Tue Apr 19 16:22:20 2016 : Info: PARTICULAR PURPOSE.
Tue Apr 19 16:22:20 2016 : Info: You may redistribute copies of FreeRADIUS under the terms of the
Tue Apr 19 16:22:20 2016 : Info: GNU General Public License.
Tue Apr 19 16:22:20 2016 : Info: For more information about these matters, see the file named COPYRIGHT.
Tue Apr 19 16:22:20 2016 : Info: Starting - reading configuration files ...
Tue Apr 19 16:22:20 2016 : Debug: including configuration file /etc/freeradius2/radiusd.conf
Tue Apr 19 16:22:20 2016 : Debug: including configuration file /etc/freeradius2/clients.conf
Tue Apr 19 16:22:20 2016 : Debug: including files in directory /etc/freeradius2/modules/
Tue Apr 19 16:22:20 2016 : Debug: including configuration file /etc/freeradius2/modules/pap
Tue Apr 19 16:22:20 2016 : Debug: including configuration file /etc/freeradius2/modules/chap
Tue Apr 19 16:22:20 2016 : Debug: including configuration file /etc/freeradius2/modules/echo
Tue Apr 19 16:22:20 2016 : Debug: including configuration file /etc/freeradius2/modules/exec
Tue Apr 19 16:22:20 2016 : Debug: including configuration file /etc/freeradius2/modules/expr
Tue Apr 19 16:22:20 2016 : Debug: including configuration file /etc/freeradius2/modules/radutmp
Tue Apr 19 16:22:20 2016 : Debug: including configuration file /etc/freeradius2/modules/files
Tue Apr 19 16:22:20 2016 : Debug: including configuration file /etc/freeradius2/modules/realm
Tue Apr 19 16:22:20 2016 : Debug: including configuration file /etc/freeradius2/modules/sradutmp
Tue Apr 19 16:22:20 2016 : Debug: including configuration file /etc/freeradius2/modules/inner-eap
Tue Apr 19 16:22:20 2016 : Debug: including configuration file /etc/freeradius2/modules/always
Tue Apr 19 16:22:20 2016 : Debug: including configuration file /etc/freeradius2/modules/mschap
Tue Apr 19 16:22:20 2016 : Debug: including configuration file /etc/freeradius2/eap.conf
Tue Apr 19 16:22:20 2016 : Debug: including configuration file /etc/freeradius2/policy.conf
Tue Apr 19 16:22:20 2016 : Debug: including files in directory /etc/freeradius2/sites/
Tue Apr 19 16:22:20 2016 : Debug: including configuration file /etc/freeradius2/sites/default
Tue Apr 19 16:22:20 2016 : Debug: main {
Tue Apr 19 16:22:20 2016 : Debug: allow_core_dumps = no
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: including dictionary file /etc/freeradius2/dictionary
Tue Apr 19 16:22:20 2016 : Debug: main {
Tue Apr 19 16:22:20 2016 : Debug: name = "radiusd"
Tue Apr 19 16:22:20 2016 : Debug: prefix = "/usr"
Tue Apr 19 16:22:20 2016 : Debug: localstatedir = "/var"
Tue Apr 19 16:22:20 2016 : Debug: sbindir = "/usr/sbin"
Tue Apr 19 16:22:20 2016 : Debug: logdir = "/var/log"
Tue Apr 19 16:22:20 2016 : Debug: run_dir = "/var/run"
Tue Apr 19 16:22:20 2016 : Debug: libdir = "/usr/lib/freeradius2"
Tue Apr 19 16:22:20 2016 : Debug: radacctdir = "/var/db/radacct"
Tue Apr 19 16:22:20 2016 : Debug: hostname_lookups = no
Tue Apr 19 16:22:20 2016 : Debug: max_request_time = 30
Tue Apr 19 16:22:20 2016 : Debug: cleanup_delay = 5
Tue Apr 19 16:22:20 2016 : Debug: max_requests = 1024
Tue Apr 19 16:22:20 2016 : Debug: pidfile = "/var/run/radiusd.pid"
Tue Apr 19 16:22:20 2016 : Debug: checkrad = "/usr/sbin/checkrad"
Tue Apr 19 16:22:20 2016 : Debug: debug_level = 0
Tue Apr 19 16:22:20 2016 : Debug: proxy_requests = no
Tue Apr 19 16:22:20 2016 : Debug: log {
Tue Apr 19 16:22:20 2016 : Debug: stripped_names = no
Tue Apr 19 16:22:20 2016 : Debug: auth = no
Tue Apr 19 16:22:20 2016 : Debug: auth_badpass = no
Tue Apr 19 16:22:20 2016 : Debug: auth_goodpass = no
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: security {
Tue Apr 19 16:22:20 2016 : Debug: max_attributes = 200
Tue Apr 19 16:22:20 2016 : Debug: reject_delay = 1
Tue Apr 19 16:22:20 2016 : Debug: status_server = yes
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: radiusd: #### Loading Realms and Home Servers ####
Tue Apr 19 16:22:20 2016 : Debug: radiusd: #### Loading Clients ####
Tue Apr 19 16:22:20 2016 : Debug: client localhost {
Tue Apr 19 16:22:20 2016 : Debug: ipaddr = 127.0.0.1
Tue Apr 19 16:22:20 2016 : Debug: require_message_authenticator = no
Tue Apr 19 16:22:20 2016 : Debug: secret = "AccessDeniedRADIUS1"
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: client radiusServ {
Tue Apr 19 16:22:20 2016 : Debug: ipaddr = 192.168.1.4
Tue Apr 19 16:22:20 2016 : Debug: require_message_authenticator = yes
Tue Apr 19 16:22:20 2016 : Debug: secret = "AccessDeniedRADIUS1"
Tue Apr 19 16:22:20 2016 : Debug: nastype = "other"
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: client 192.168.1.1 {
Tue Apr 19 16:22:20 2016 : Debug: ipaddr = 192.168.1.1
Tue Apr 19 16:22:20 2016 : Debug: require_message_authenticator = yes
Tue Apr 19 16:22:20 2016 : Debug: secret = "AccessDeniedRADIUS1"
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: radiusd: #### Instantiating modules ####
Tue Apr 19 16:22:20 2016 : Debug: instantiate {
Tue Apr 19 16:22:20 2016 : Debug: (Loaded rlm_expr, checking if it's valid)
Tue Apr 19 16:22:20 2016 : Debug: Module: Linked to module rlm_expr
Tue Apr 19 16:22:20 2016 : Debug: Module: Instantiating module "expr" from file /etc/freeradius2/modules/expr
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: radiusd: #### Loading Virtual Servers ####
Tue Apr 19 16:22:20 2016 : Debug: server { # from file /etc/freeradius2/radiusd.conf
Tue Apr 19 16:22:20 2016 : Debug: modules {
Tue Apr 19 16:22:20 2016 : Debug: Module: Checking authenticate {...} for more modules to load
Tue Apr 19 16:22:20 2016 : Debug: (Loaded rlm_pap, checking if it's valid)
Tue Apr 19 16:22:20 2016 : Debug: Module: Linked to module rlm_pap
Tue Apr 19 16:22:20 2016 : Debug: Module: Instantiating module "pap" from file /etc/freeradius2/modules/pap
Tue Apr 19 16:22:20 2016 : Debug: pap {
Tue Apr 19 16:22:20 2016 : Debug: encryption_scheme = "auto"
Tue Apr 19 16:22:20 2016 : Debug: auto_header = yes
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: (Loaded rlm_chap, checking if it's valid)
Tue Apr 19 16:22:20 2016 : Debug: Module: Linked to module rlm_chap
Tue Apr 19 16:22:20 2016 : Debug: Module: Instantiating module "chap" from file /etc/freeradius2/modules/chap
Tue Apr 19 16:22:20 2016 : Debug: (Loaded rlm_mschap, checking if it's valid)
Tue Apr 19 16:22:20 2016 : Debug: Module: Linked to module rlm_mschap
Tue Apr 19 16:22:20 2016 : Debug: Module: Instantiating module "mschap" from file /etc/freeradius2/modules/mschap
Tue Apr 19 16:22:20 2016 : Debug: mschap {
Tue Apr 19 16:22:20 2016 : Debug: use_mppe = yes
Tue Apr 19 16:22:20 2016 : Debug: require_encryption = no
Tue Apr 19 16:22:20 2016 : Debug: require_strong = no
Tue Apr 19 16:22:20 2016 : Debug: with_ntdomain_hack = no
Tue Apr 19 16:22:20 2016 : Debug: allow_retry = yes
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: (Loaded rlm_eap, checking if it's valid)
Tue Apr 19 16:22:20 2016 : Debug: Module: Linked to module rlm_eap
Tue Apr 19 16:22:20 2016 : Debug: Module: Instantiating module "eap" from file /etc/freeradius2/eap.conf
Tue Apr 19 16:22:20 2016 : Debug: eap {
Tue Apr 19 16:22:20 2016 : Debug: default_eap_type = "peap"
Tue Apr 19 16:22:20 2016 : Debug: timer_expire = 60
Tue Apr 19 16:22:20 2016 : Debug: ignore_unknown_eap_types = no
Tue Apr 19 16:22:20 2016 : Debug: cisco_accounting_username_bug = no
Tue Apr 19 16:22:20 2016 : Debug: max_sessions = 1024
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: Module: Linked to sub-module rlm_eap_tls
Tue Apr 19 16:22:20 2016 : Debug: Module: Instantiating eap-tls
Tue Apr 19 16:22:20 2016 : Debug: tls {
Tue Apr 19 16:22:20 2016 : Debug: rsa_key_exchange = no
Tue Apr 19 16:22:20 2016 : Debug: dh_key_exchange = yes
Tue Apr 19 16:22:20 2016 : Debug: rsa_key_length = 512
Tue Apr 19 16:22:20 2016 : Debug: dh_key_length = 512
Tue Apr 19 16:22:20 2016 : Debug: verify_depth = 0
Tue Apr 19 16:22:20 2016 : Debug: CA_path = "/etc/freeradius2/certs"
Tue Apr 19 16:22:20 2016 : Debug: pem_file_type = yes
Tue Apr 19 16:22:20 2016 : Debug: private_key_file = "/etc/freeradius2/certs/server.pem"
Tue Apr 19 16:22:20 2016 : Debug: certificate_file = "/etc/freeradius2/certs/server.pem"
Tue Apr 19 16:22:20 2016 : Debug: CA_file = "/etc/freeradius2/certs/ca.pem"
Tue Apr 19 16:22:20 2016 : Debug: private_key_password = "whatever"
Tue Apr 19 16:22:20 2016 : Debug: dh_file = "/etc/freeradius2/certs/dh"
Tue Apr 19 16:22:20 2016 : Debug: fragment_size = 1024
Tue Apr 19 16:22:20 2016 : Debug: include_length = yes
Tue Apr 19 16:22:20 2016 : Debug: check_crl = no
Tue Apr 19 16:22:20 2016 : Debug: check_all_crl = no
Tue Apr 19 16:22:20 2016 : Debug: cipher_list = "DEFAULT"
Tue Apr 19 16:22:20 2016 : Debug: ecdh_curve = "prime256v1"
Tue Apr 19 16:22:20 2016 : Debug: verify {
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: ocsp {
Tue Apr 19 16:22:20 2016 : Debug: enable = no
Tue Apr 19 16:22:20 2016 : Debug: override_cert_url = yes
Tue Apr 19 16:22:20 2016 : Debug: url = " http://127.0.0.1/ocsp/ "
Tue Apr 19 16:22:20 2016 : Debug: use_nonce = yes
Tue Apr 19 16:22:20 2016 : Debug: timeout = 0
Tue Apr 19 16:22:20 2016 : Debug: softfail = no
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: Module: Linked to sub-module rlm_eap_ttls
Tue Apr 19 16:22:20 2016 : Debug: Module: Instantiating eap-ttls
Tue Apr 19 16:22:20 2016 : Debug: ttls {
Tue Apr 19 16:22:20 2016 : Debug: default_eap_type = "md5"
Tue Apr 19 16:22:20 2016 : Debug: copy_request_to_tunnel = yes
Tue Apr 19 16:22:20 2016 : Debug: use_tunneled_reply = yes
Tue Apr 19 16:22:20 2016 : Debug: include_length = yes
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: Module: Linked to sub-module rlm_eap_peap
Tue Apr 19 16:22:20 2016 : Debug: Module: Instantiating eap-peap
Tue Apr 19 16:22:20 2016 : Debug: peap {
Tue Apr 19 16:22:20 2016 : Debug: default_eap_type = "mschapv2"
Tue Apr 19 16:22:20 2016 : Debug: copy_request_to_tunnel = yes
Tue Apr 19 16:22:20 2016 : Debug: use_tunneled_reply = yes
Tue Apr 19 16:22:20 2016 : Debug: proxy_tunneled_request_as_eap = no
Tue Apr 19 16:22:20 2016 : Debug: soh = no
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: Module: Linked to sub-module rlm_eap_mschapv2
Tue Apr 19 16:22:20 2016 : Debug: Module: Instantiating eap-mschapv2
Tue Apr 19 16:22:20 2016 : Debug: mschapv2 {
Tue Apr 19 16:22:20 2016 : Debug: with_ntdomain_hack = no
Tue Apr 19 16:22:20 2016 : Debug: send_error = no
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: Module: Checking authorize {...} for more modules to load
Tue Apr 19 16:22:20 2016 : Debug: Module: Loading virtual module rewrite.calling_station_id
Tue Apr 19 16:22:20 2016 : Debug: (Loaded rlm_always, checking if it's valid)
Tue Apr 19 16:22:20 2016 : Debug: Module: Linked to module rlm_always
Tue Apr 19 16:22:20 2016 : Debug: Module: Instantiating module "updated" from file /etc/freeradius2/modules/always
Tue Apr 19 16:22:20 2016 : Debug: always updated {
Tue Apr 19 16:22:20 2016 : Debug: rcode = "updated"
Tue Apr 19 16:22:20 2016 : Debug: simulcount = 0
Tue Apr 19 16:22:20 2016 : Debug: mpp = no
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: Module: Instantiating module "noop" from file /etc/freeradius2/modules/always
Tue Apr 19 16:22:20 2016 : Debug: always noop {
Tue Apr 19 16:22:20 2016 : Debug: rcode = "noop"
Tue Apr 19 16:22:20 2016 : Debug: simulcount = 0
Tue Apr 19 16:22:20 2016 : Debug: mpp = no
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: (Loaded rlm_files, checking if it's valid)
Tue Apr 19 16:22:20 2016 : Debug: Module: Linked to module rlm_files
Tue Apr 19 16:22:20 2016 : Debug: Module: Instantiating module "authorized_macs" from file /etc/freeradius2/modules/files
Tue Apr 19 16:22:20 2016 : Debug: files authorized_macs {
Tue Apr 19 16:22:20 2016 : Debug: usersfile = "/etc/freeradius2/authorized_macs"
Tue Apr 19 16:22:20 2016 : Debug: compat = "no"
Tue Apr 19 16:22:20 2016 : Debug: key = "%{Calling-Station-ID}"
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: reading pairlist file /etc/freeradius2/authorized_macs
Tue Apr 19 16:22:20 2016 : Debug: Module: Instantiating module "reject" from file /etc/freeradius2/modules/always
Tue Apr 19 16:22:20 2016 : Debug: always reject {
Tue Apr 19 16:22:20 2016 : Debug: rcode = "reject"
Tue Apr 19 16:22:20 2016 : Debug: simulcount = 0
Tue Apr 19 16:22:20 2016 : Debug: mpp = no
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: Module: Instantiating module "files" from file /etc/freeradius2/modules/files
Tue Apr 19 16:22:20 2016 : Debug: files {
Tue Apr 19 16:22:20 2016 : Debug: usersfile = "/etc/freeradius2/users"
Tue Apr 19 16:22:20 2016 : Debug: acctusersfile = "/etc/freeradius2/acct_users"
Tue Apr 19 16:22:20 2016 : Debug: preproxy_usersfile = "/etc/freeradius2/preproxy_users"
Tue Apr 19 16:22:20 2016 : Debug: compat = "no"
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: reading pairlist file /etc/freeradius2/users
Tue Apr 19 16:22:20 2016 : Debug: reading pairlist file /etc/freeradius2/acct_users
Tue Apr 19 16:22:20 2016 : Debug: reading pairlist file /etc/freeradius2/preproxy_users
Tue Apr 19 16:22:20 2016 : Debug: Module: Checking accounting {...} for more modules to load
Tue Apr 19 16:22:20 2016 : Debug: (Loaded rlm_exec, checking if it's valid)
Tue Apr 19 16:22:20 2016 : Debug: Module: Linked to module rlm_exec
Tue Apr 19 16:22:20 2016 : Debug: Module: Instantiating module "exec" from file /etc/freeradius2/modules/exec
Tue Apr 19 16:22:20 2016 : Debug: exec {
Tue Apr 19 16:22:20 2016 : Debug: wait = no
Tue Apr 19 16:22:20 2016 : Debug: input_pairs = "request"
Tue Apr 19 16:22:20 2016 : Debug: shell_escape = yes
Tue Apr 19 16:22:20 2016 : Debug: timeout = 10
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: Module: Checking session {...} for more modules to load
Tue Apr 19 16:22:20 2016 : Debug: (Loaded rlm_radutmp, checking if it's valid)
Tue Apr 19 16:22:20 2016 : Debug: Module: Linked to module rlm_radutmp
Tue Apr 19 16:22:20 2016 : Debug: Module: Instantiating module "radutmp" from file /etc/freeradius2/modules/radutmp
Tue Apr 19 16:22:20 2016 : Debug: radutmp {
Tue Apr 19 16:22:20 2016 : Debug: filename = "/var/db/radacct/radutmp"
Tue Apr 19 16:22:20 2016 : Debug: username = "%{User-Name}"
Tue Apr 19 16:22:20 2016 : Debug: case_sensitive = yes
Tue Apr 19 16:22:20 2016 : Debug: check_with_nas = yes
Tue Apr 19 16:22:20 2016 : Debug: perm = 384
Tue Apr 19 16:22:20 2016 : Debug: callerid = yes
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: } # modules
Tue Apr 19 16:22:20 2016 : Debug: } # server
Tue Apr 19 16:22:20 2016 : Debug: radiusd: #### Opening IP addresses and Ports ####
Tue Apr 19 16:22:20 2016 : Debug: listen {
Tue Apr 19 16:22:20 2016 : Debug: type = "auth"
Tue Apr 19 16:22:20 2016 : Debug: ipaddr = *
Tue Apr 19 16:22:20 2016 : Debug: port = 0
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: listen {
Tue Apr 19 16:22:20 2016 : Debug: type = "acct"
Tue Apr 19 16:22:20 2016 : Debug: ipaddr = *
Tue Apr 19 16:22:20 2016 : Debug: port = 0
Tue Apr 19 16:22:20 2016 : Debug: }
Tue Apr 19 16:22:20 2016 : Debug: Listening on authentication address * port 1812
Tue Apr 19 16:22:20 2016 : Debug: Listening on accounting interface br-lan address * port 1813
Tue Apr 19 16:22:20 2016 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 192.168.1.1 port 47559, id=0, length=115
User-Name = "k"
NAS-IP-Address = 192.168.1.1
Called-Station-Id = "b046fc58804c"
Calling-Station-Id = "ccaf78073b5a"
NAS-Identifier = "b046fc58804c"
NAS-Port = 2
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x02000006016b
Message-Authenticator = 0x63908c544fdb135590b53eddfac9ffc4
Tue Apr 19 16:22:49 2016 : Info: # Executing section authorize from file /etc/freeradius2/sites/default
Tue Apr 19 16:22:49 2016 : Info: +group authorize {
Tue Apr 19 16:22:49 2016 : Info: ++policy rewrite.calling_station_id {
Tue Apr 19 16:22:49 2016 : Info: +++? if ((Calling-Station-Id) && "%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i)
Tue Apr 19 16:22:49 2016 : Info: ?? Evaluating (Calling-Station-Id) -> TRUE
Tue Apr 19 16:22:49 2016 : Info: expand: %{Calling-Station-Id} -> ccaf78073b5a
Tue Apr 19 16:22:49 2016 : Info: expand: policy.mac-addr -> policy.mac-addr
Tue Apr 19 16:22:49 2016 : Info: expand: ^%{config:policy.mac-addr}$ -> ^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$
Tue Apr 19 16:22:49 2016 : Info: ? Evaluating ("%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) -> TRUE
Tue Apr 19 16:22:49 2016 : Info: +++? if ((Calling-Station-Id) && "%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) -> TRUE
Tue Apr 19 16:22:49 2016 : Info: +++if ((Calling-Station-Id) && "%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) {
Tue Apr 19 16:22:49 2016 : Info: ++++update request {
Tue Apr 19 16:22:49 2016 : Info: expand: %{1}-%{2}-%{3}-%{4}-%{5}-%{6} -> cc-af-78-07-3b-5a
Tue Apr 19 16:22:49 2016 : Info: expand: %{tolower:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}} -> cc-af-78-07-3b-5a
Tue Apr 19 16:22:49 2016 : Info: ++++} # update request = noop
Tue Apr 19 16:22:49 2016 : Info: ++++[updated] = updated
Tue Apr 19 16:22:49 2016 : Info: +++} # if ((Calling-Station-Id) && "%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) = updated
Tue Apr 19 16:22:49 2016 : Info: +++ ... skipping else for request 0: Preceding "if" was taken
Tue Apr 19 16:22:49 2016 : Info: ++} # policy rewrite.calling_station_id = updated
Tue Apr 19 16:22:49 2016 : Info: [authorized_macs] expand: %{Calling-Station-ID} -> cc-af-78-07-3b-5a
Tue Apr 19 16:22:49 2016 : Info: [authorized_macs] users: Matched entry cc-af-78-07-3b-5a at line 12
Tue Apr 19 16:22:49 2016 : Info: ++[authorized_macs] = ok
Tue Apr 19 16:22:49 2016 : Info: ++? if (!ok)
Tue Apr 19 16:22:49 2016 : Info: ? Evaluating !(ok) -> FALSE
Tue Apr 19 16:22:49 2016 : Info: ++? if (!ok) -> FALSE
Tue Apr 19 16:22:49 2016 : Info: [eap] EAP packet type response id 0 length 6
Tue Apr 19 16:22:49 2016 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Tue Apr 19 16:22:49 2016 : Info: ++[eap] = updated
Tue Apr 19 16:22:49 2016 : Info: [files] users: Matched entry k at line 5
Tue Apr 19 16:22:49 2016 : Info: [files] expand: Hello, %{User-Name} -> Hello, k
Tue Apr 19 16:22:49 2016 : Info: ++[files] = ok
Tue Apr 19 16:22:49 2016 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP
Tue Apr 19 16:22:49 2016 : Info: ++[pap] = noop
Tue Apr 19 16:22:49 2016 : Info: +} # group authorize = updated
Tue Apr 19 16:22:49 2016 : Info: Found Auth-Type = EAP
Tue Apr 19 16:22:49 2016 : Info: # Executing group from file /etc/freeradius2/sites/default
Tue Apr 19 16:22:49 2016 : Info: +group authenticate {
Tue Apr 19 16:22:49 2016 : Info: [eap] EAP Identity
Tue Apr 19 16:22:49 2016 : Info: [eap] processing type tls
Tue Apr 19 16:22:49 2016 : Info: [tls] Initiate
Tue Apr 19 16:22:49 2016 : Info: [tls] Start returned 1
Tue Apr 19 16:22:49 2016 : Info: ++[eap] = handled
Tue Apr 19 16:22:49 2016 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 0 to 192.168.1.1 port 47559
Reply-Message = "Hello, k"
EAP-Message = 0x010100061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x2bc7c2802bc6dba8902f8db7525fd589
Tue Apr 19 16:22:49 2016 : Info: Finished request 0.
Tue Apr 19 16:22:49 2016 : Debug: Going to the next request
Tue Apr 19 16:22:49 2016 : Debug: Waking up in 4.9 seconds.
Tue Apr 19 16:22:54 2016 : Info: Cleaning up request 0 ID 0 with timestamp +29
Tue Apr 19 16:22:54 2016 : Debug: WARNING: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Tue Apr 19 16:22:54 2016 : Debug: WARNING: !! EAP session for state 0x2bc7c2802bc6dba8 did not finish!
Tue Apr 19 16:22:54 2016 : Debug: WARNING: !! Please read  http://wiki.freeradius.org/guide/Certificate_Compatibility
Tue Apr 19 16:22:54 2016 : Debug: WARNING: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Tue Apr 19 16:22:54 2016 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 192.168.1.1 port 56343, id=0, length=115
User-Name = "k"
NAS-IP-Address = 192.168.1.1
Called-Station-Id = "b046fc58804c"
Calling-Station-Id = "ccaf78073b5a"
NAS-Identifier = "b046fc58804c"
NAS-Port = 2
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x02000006016b
Message-Authenticator = 0x92c6a8bb5d14b2e4781523d9b5be03df
Tue Apr 19 16:24:24 2016 : Info: # Executing section authorize from file /etc/freeradius2/sites/default
Tue Apr 19 16:24:24 2016 : Info: +group authorize {
Tue Apr 19 16:24:24 2016 : Info: ++policy rewrite.calling_station_id {
Tue Apr 19 16:24:24 2016 : Info: +++? if ((Calling-Station-Id) && "%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i)
Tue Apr 19 16:24:24 2016 : Info: ?? Evaluating (Calling-Station-Id) -> TRUE
Tue Apr 19 16:24:24 2016 : Info: expand: %{Calling-Station-Id} -> ccaf78073b5a
Tue Apr 19 16:24:24 2016 : Info: expand: policy.mac-addr -> policy.mac-addr
Tue Apr 19 16:24:24 2016 : Info: expand: ^%{config:policy.mac-addr}$ -> ^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$
Tue Apr 19 16:24:24 2016 : Info: ? Evaluating ("%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) -> TRUE
Tue Apr 19 16:24:24 2016 : Info: +++? if ((Calling-Station-Id) && "%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) -> TRUE
Tue Apr 19 16:24:24 2016 : Info: +++if ((Calling-Station-Id) && "%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) {
Tue Apr 19 16:24:24 2016 : Info: ++++update request {
Tue Apr 19 16:24:24 2016 : Info: expand: %{1}-%{2}-%{3}-%{4}-%{5}-%{6} -> cc-af-78-07-3b-5a
Tue Apr 19 16:24:24 2016 : Info: expand: %{tolower:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}} -> cc-af-78-07-3b-5a
Tue Apr 19 16:24:24 2016 : Info: ++++} # update request = noop
Tue Apr 19 16:24:24 2016 : Info: ++++[updated] = updated
Tue Apr 19 16:24:24 2016 : Info: +++} # if ((Calling-Station-Id) && "%{Calling-Station-Id}" =~ /^%{config:policy.mac-addr}$/i) = updated
Tue Apr 19 16:24:24 2016 : Info: +++ ... skipping else for request 1: Preceding "if" was taken
Tue Apr 19 16:24:24 2016 : Info: ++} # policy rewrite.calling_station_id = updated
Tue Apr 19 16:24:24 2016 : Info: [authorized_macs] expand: %{Calling-Station-ID} -> cc-af-78-07-3b-5a
Tue Apr 19 16:24:24 2016 : Info: [authorized_macs] users: Matched entry cc-af-78-07-3b-5a at line 12
Tue Apr 19 16:24:24 2016 : Info: ++[authorized_macs] = ok
Tue Apr 19 16:24:24 2016 : Info: ++? if (!ok)
Tue Apr 19 16:24:24 2016 : Info: ? Evaluating !(ok) -> FALSE
Tue Apr 19 16:24:24 2016 : Info: ++? if (!ok) -> FALSE
Tue Apr 19 16:24:24 2016 : Info: [eap] EAP packet type response id 0 length 6
Tue Apr 19 16:24:24 2016 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Tue Apr 19 16:24:24 2016 : Info: ++[eap] = updated
Tue Apr 19 16:24:24 2016 : Info: [files] users: Matched entry k at line 5
Tue Apr 19 16:24:24 2016 : Info: [files] expand: Hello, %{User-Name} -> Hello, k
Tue Apr 19 16:24:24 2016 : Info: ++[files] = ok
Tue Apr 19 16:24:24 2016 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP
Tue Apr 19 16:24:24 2016 : Info: ++[pap] = noop
Tue Apr 19 16:24:24 2016 : Info: +} # group authorize = updated
Tue Apr 19 16:24:24 2016 : Info: Found Auth-Type = EAP
Tue Apr 19 16:24:24 2016 : Info: # Executing group from file /etc/freeradius2/sites/default
Tue Apr 19 16:24:24 2016 : Info: +group authenticate {
Tue Apr 19 16:24:24 2016 : Info: [eap] EAP Identity
Tue Apr 19 16:24:24 2016 : Info: [eap] processing type tls
Tue Apr 19 16:24:24 2016 : Info: [tls] Initiate
Tue Apr 19 16:24:24 2016 : Info: [tls] Start returned 1
Tue Apr 19 16:24:24 2016 : Info: ++[eap] = handled
Tue Apr 19 16:24:24 2016 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 0 to 192.168.1.1 port 56343
Reply-Message = "Hello, k"
EAP-Message = 0x010100061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xc7cb19abc7ca00b9956b02c17b8e07a9
Tue Apr 19 16:24:24 2016 : Info: Finished request 1.
Tue Apr 19 16:24:24 2016 : Debug: Going to the next request
Tue Apr 19 16:24:24 2016 : Debug: Waking up in 4.9 seconds.
Tue Apr 19 16:24:29 2016 : Info: Cleaning up request 1 ID 0 with timestamp +124
Tue Apr 19 16:24:29 2016 : Debug: WARNING: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Tue Apr 19 16:24:29 2016 : Debug: WARNING: !! EAP session for state 0xc7cb19abc7ca00b9 did not finish!
Tue Apr 19 16:24:29 2016 : Debug: WARNING: !! Please read  http://wiki.freeradius.org/guide/Certificate_Compatibility
Tue Apr 19 16:24:29 2016 : Debug: WARNING: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Tue Apr 19 16:24:29 2016 : Info: Ready to process requests.
^C

openwrt, freeradius,

Mildok