Le précedent débug n'état pas bon. Voila le debug complet:
Wed Nov 14 19:05:47 2012 : Info: FreeRADIUS Version 2.1.12, for host arm-unknown-linux-gnueabihf, built on Sep 14 2012 at 22:56:14
Wed Nov 14 19:05:47 2012 : Info: Copyright (C) 1999-2009 The FreeRADIUS server project and contributors.
Wed Nov 14 19:05:47 2012 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
Wed Nov 14 19:05:47 2012 : Info: PARTICULAR PURPOSE.
Wed Nov 14 19:05:47 2012 : Info: You may redistribute copies of FreeRADIUS under the terms of the
Wed Nov 14 19:05:47 2012 : Info: GNU General Public License v2.
Wed Nov 14 19:05:47 2012 : Info: Starting - reading configuration files ...
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/radiusd.conf
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/proxy.conf
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/clients.conf
Wed Nov 14 19:05:47 2012 : Debug: including files in directory /etc/freeradius/modules/
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/attr_filter
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/linelog
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/perl
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/otp
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/acct_unique
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/unix
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/wimax
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/dynamic_clients
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/expr
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/sql_log
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/digest
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/detail
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/soh
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/attr_rewrite
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/expiration
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/smsotp
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/pam
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/preprocess
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/rediswho
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/sradutmp
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/detail.log
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/inner-eap
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/krb5
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/ldap
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/always
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/chap
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/detail.example.com
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/files
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/replicate
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/radutmp
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/pap
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/redis
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/realm
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/mac2vlan
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/cui
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/echo
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/sqlcounter_expire_on_login
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/etc_group
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/passwd
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/ippool
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/opendirectory
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/policy
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/smbpasswd
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/counter
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/ntlm_auth
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/mac2ip
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/logintime
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/mschap
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/exec
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/modules/checkval
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/eap.conf
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/policy.conf
Wed Nov 14 19:05:47 2012 : Debug: including files in directory /etc/freeradius/sites-enabled/
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/sites-enabled/inner-tunnel
Wed Nov 14 19:05:47 2012 : Debug: including configuration file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:05:47 2012 : Debug: main {
Wed Nov 14 19:05:47 2012 : Debug: user = "freerad"
Wed Nov 14 19:05:47 2012 : Debug: group = "freerad"
Wed Nov 14 19:05:47 2012 : Debug: allow_core_dumps = no
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: including dictionary file /etc/freeradius/dictionary
Wed Nov 14 19:05:47 2012 : Debug: main {
Wed Nov 14 19:05:47 2012 : Debug: name = "freeradius"
Wed Nov 14 19:05:47 2012 : Debug: prefix = "/usr"
Wed Nov 14 19:05:47 2012 : Debug: localstatedir = "/var"
Wed Nov 14 19:05:47 2012 : Debug: sbindir = "/usr/sbin"
Wed Nov 14 19:05:47 2012 : Debug: logdir = "/var/log/freeradius"
Wed Nov 14 19:05:47 2012 : Debug: run_dir = "/var/run/freeradius"
Wed Nov 14 19:05:47 2012 : Debug: libdir = "/usr/lib/freeradius"
Wed Nov 14 19:05:47 2012 : Debug: radacctdir = "/var/log/freeradius/radacct"
Wed Nov 14 19:05:47 2012 : Debug: hostname_lookups = no
Wed Nov 14 19:05:47 2012 : Debug: max_request_time = 30
Wed Nov 14 19:05:47 2012 : Debug: cleanup_delay = 5
Wed Nov 14 19:05:47 2012 : Debug: max_requests = 1024
Wed Nov 14 19:05:47 2012 : Debug: pidfile = "/var/run/freeradius/freeradius.pid"
Wed Nov 14 19:05:47 2012 : Debug: checkrad = "/usr/sbin/checkrad"
Wed Nov 14 19:05:47 2012 : Debug: debug_level = 0
Wed Nov 14 19:05:47 2012 : Debug: proxy_requests = yes
Wed Nov 14 19:05:47 2012 : Debug: log {
Wed Nov 14 19:05:47 2012 : Debug: stripped_names = no
Wed Nov 14 19:05:47 2012 : Debug: auth = yes
Wed Nov 14 19:05:47 2012 : Debug: auth_badpass = yes
Wed Nov 14 19:05:47 2012 : Debug: auth_goodpass = no
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: security {
Wed Nov 14 19:05:47 2012 : Debug: max_attributes = 200
Wed Nov 14 19:05:47 2012 : Debug: reject_delay = 1
Wed Nov 14 19:05:47 2012 : Debug: status_server = yes
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: radiusd: #### Loading Realms and Home Servers ####
Wed Nov 14 19:05:47 2012 : Debug: proxy server {
Wed Nov 14 19:05:47 2012 : Debug: retry_delay = 5
Wed Nov 14 19:05:47 2012 : Debug: retry_count = 3
Wed Nov 14 19:05:47 2012 : Debug: default_fallback = no
Wed Nov 14 19:05:47 2012 : Debug: dead_time = 120
Wed Nov 14 19:05:47 2012 : Debug: wake_all_if_all_dead = no
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: home_server localhost {
Wed Nov 14 19:05:47 2012 : Debug: ipaddr = 127.0.0.1
Wed Nov 14 19:05:47 2012 : Debug: port = 1812
Wed Nov 14 19:05:47 2012 : Debug: type = "auth"
Wed Nov 14 19:05:47 2012 : Debug: secret = "testing123"
Wed Nov 14 19:05:47 2012 : Debug: response_window = 20
Wed Nov 14 19:05:47 2012 : Debug: max_outstanding = 65536
Wed Nov 14 19:05:47 2012 : Debug: require_message_authenticator = yes
Wed Nov 14 19:05:47 2012 : Debug: zombie_period = 40
Wed Nov 14 19:05:47 2012 : Debug: status_check = "status-server"
Wed Nov 14 19:05:47 2012 : Debug: ping_interval = 30
Wed Nov 14 19:05:47 2012 : Debug: check_interval = 30
Wed Nov 14 19:05:47 2012 : Debug: num_answers_to_alive = 3
Wed Nov 14 19:05:47 2012 : Debug: num_pings_to_alive = 3
Wed Nov 14 19:05:47 2012 : Debug: revive_interval = 120
Wed Nov 14 19:05:47 2012 : Debug: status_check_timeout = 4
Wed Nov 14 19:05:47 2012 : Debug: coa {
Wed Nov 14 19:05:47 2012 : Debug: irt = 2
Wed Nov 14 19:05:47 2012 : Debug: mrt = 16
Wed Nov 14 19:05:47 2012 : Debug: mrc = 5
Wed Nov 14 19:05:47 2012 : Debug: mrd = 30
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: home_server_pool my_auth_failover {
Wed Nov 14 19:05:47 2012 : Debug: type = fail-over
Wed Nov 14 19:05:47 2012 : Debug: home_server = localhost
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: realm example.com {
Wed Nov 14 19:05:47 2012 : Debug: auth_pool = my_auth_failover
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: realm LOCAL {
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: radiusd: #### Loading Clients ####
Wed Nov 14 19:05:47 2012 : Debug: client localhost {
Wed Nov 14 19:05:47 2012 : Debug: ipaddr = 127.0.0.1
Wed Nov 14 19:05:47 2012 : Debug: require_message_authenticator = no
Wed Nov 14 19:05:47 2012 : Debug: secret = "testing123"
Wed Nov 14 19:05:47 2012 : Debug: nastype = "other"
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: client 192.168.2.10/24 {
Wed Nov 14 19:05:47 2012 : Debug: require_message_authenticator = no
Wed Nov 14 19:05:47 2012 : Debug: secret = "secret"
Wed Nov 14 19:05:47 2012 : Debug: shortname = "remywifi"
Wed Nov 14 19:05:47 2012 : Debug: nastype = "RalinkAP0"
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: radiusd: #### Instantiating modules ####
Wed Nov 14 19:05:47 2012 : Debug: instantiate {
Wed Nov 14 19:05:47 2012 : Debug: (Loaded rlm_exec, checking if it's valid)
Wed Nov 14 19:05:47 2012 : Debug: Module: Linked to module rlm_exec
Wed Nov 14 19:05:47 2012 : Debug: Module: Instantiating module "exec" from file /etc/freeradius/modules/exec
Wed Nov 14 19:05:47 2012 : Debug: exec {
Wed Nov 14 19:05:47 2012 : Debug: wait = no
Wed Nov 14 19:05:47 2012 : Debug: input_pairs = "request"
Wed Nov 14 19:05:47 2012 : Debug: shell_escape = yes
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: (Loaded rlm_expr, checking if it's valid)
Wed Nov 14 19:05:47 2012 : Debug: Module: Linked to module rlm_expr
Wed Nov 14 19:05:47 2012 : Debug: Module: Instantiating module "expr" from file /etc/freeradius/modules/expr
Wed Nov 14 19:05:47 2012 : Debug: (Loaded rlm_expiration, checking if it's valid)
Wed Nov 14 19:05:47 2012 : Debug: Module: Linked to module rlm_expiration
Wed Nov 14 19:05:47 2012 : Debug: Module: Instantiating module "expiration" from file /etc/freeradius/modules/expiration
Wed Nov 14 19:05:47 2012 : Debug: expiration {
Wed Nov 14 19:05:47 2012 : Debug: reply-message = "Password Has Expired "
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: (Loaded rlm_logintime, checking if it's valid)
Wed Nov 14 19:05:47 2012 : Debug: Module: Linked to module rlm_logintime
Wed Nov 14 19:05:47 2012 : Debug: Module: Instantiating module "logintime" from file /etc/freeradius/modules/logintime
Wed Nov 14 19:05:47 2012 : Debug: logintime {
Wed Nov 14 19:05:47 2012 : Debug: reply-message = "You are calling outside your allowed timespan "
Wed Nov 14 19:05:47 2012 : Debug: minimum-timeout = 60
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: radiusd: #### Loading Virtual Servers ####
Wed Nov 14 19:05:47 2012 : Debug: server { # from file /etc/freeradius/radiusd.conf
Wed Nov 14 19:05:47 2012 : Debug: modules {
Wed Nov 14 19:05:47 2012 : Debug: Module: Creating Auth-Type = digest
Wed Nov 14 19:05:47 2012 : Debug: Module: Creating Post-Auth-Type = REJECT
Wed Nov 14 19:05:47 2012 : Debug: Module: Checking authenticate {...} for more modules to load
Wed Nov 14 19:05:47 2012 : Debug: (Loaded rlm_pap, checking if it's valid)
Wed Nov 14 19:05:47 2012 : Debug: Module: Linked to module rlm_pap
Wed Nov 14 19:05:47 2012 : Debug: Module: Instantiating module "pap" from file /etc/freeradius/modules/pap
Wed Nov 14 19:05:47 2012 : Debug: pap {
Wed Nov 14 19:05:47 2012 : Debug: encryption_scheme = "auto"
Wed Nov 14 19:05:47 2012 : Debug: auto_header = no
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: (Loaded rlm_chap, checking if it's valid)
Wed Nov 14 19:05:47 2012 : Debug: Module: Linked to module rlm_chap
Wed Nov 14 19:05:47 2012 : Debug: Module: Instantiating module "chap" from file /etc/freeradius/modules/chap
Wed Nov 14 19:05:47 2012 : Debug: (Loaded rlm_mschap, checking if it's valid)
Wed Nov 14 19:05:47 2012 : Debug: Module: Linked to module rlm_mschap
Wed Nov 14 19:05:47 2012 : Debug: Module: Instantiating module "mschap" from file /etc/freeradius/modules/mschap
Wed Nov 14 19:05:47 2012 : Debug: mschap {
Wed Nov 14 19:05:47 2012 : Debug: use_mppe = yes
Wed Nov 14 19:05:47 2012 : Debug: require_encryption = no
Wed Nov 14 19:05:47 2012 : Debug: require_strong = no
Wed Nov 14 19:05:47 2012 : Debug: with_ntdomain_hack = no
Wed Nov 14 19:05:47 2012 : Debug: allow_retry = yes
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: (Loaded rlm_digest, checking if it's valid)
Wed Nov 14 19:05:47 2012 : Debug: Module: Linked to module rlm_digest
Wed Nov 14 19:05:47 2012 : Debug: Module: Instantiating module "digest" from file /etc/freeradius/modules/digest
Wed Nov 14 19:05:47 2012 : Debug: (Loaded rlm_unix, checking if it's valid)
Wed Nov 14 19:05:47 2012 : Debug: Module: Linked to module rlm_unix
Wed Nov 14 19:05:47 2012 : Debug: Module: Instantiating module "unix" from file /etc/freeradius/modules/unix
Wed Nov 14 19:05:47 2012 : Debug: unix {
Wed Nov 14 19:05:47 2012 : Debug: radwtmp = "/var/log/freeradius/radwtmp"
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: (Loaded rlm_eap, checking if it's valid)
Wed Nov 14 19:05:47 2012 : Debug: Module: Linked to module rlm_eap
Wed Nov 14 19:05:47 2012 : Debug: Module: Instantiating module "eap" from file /etc/freeradius/eap.conf
Wed Nov 14 19:05:47 2012 : Debug: eap {
Wed Nov 14 19:05:47 2012 : Debug: default_eap_type = "md5"
Wed Nov 14 19:05:47 2012 : Debug: timer_expire = 60
Wed Nov 14 19:05:47 2012 : Debug: ignore_unknown_eap_types = no
Wed Nov 14 19:05:47 2012 : Debug: cisco_accounting_username_bug = no
Wed Nov 14 19:05:47 2012 : Debug: max_sessions = 4096
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: Module: Linked to sub-module rlm_eap_md5
Wed Nov 14 19:05:47 2012 : Debug: Module: Instantiating eap-md5
Wed Nov 14 19:05:47 2012 : Debug: Module: Linked to sub-module rlm_eap_leap
Wed Nov 14 19:05:47 2012 : Debug: Module: Instantiating eap-leap
Wed Nov 14 19:05:47 2012 : Debug: Module: Linked to sub-module rlm_eap_gtc
Wed Nov 14 19:05:47 2012 : Debug: Module: Instantiating eap-gtc
Wed Nov 14 19:05:47 2012 : Debug: gtc {
Wed Nov 14 19:05:47 2012 : Debug: challenge = "Password: "
Wed Nov 14 19:05:47 2012 : Debug: auth_type = "PAP"
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: Module: Linked to sub-module rlm_eap_tls
Wed Nov 14 19:05:47 2012 : Debug: Module: Instantiating eap-tls
Wed Nov 14 19:05:47 2012 : Debug: tls {
Wed Nov 14 19:05:47 2012 : Debug: rsa_key_exchange = no
Wed Nov 14 19:05:47 2012 : Debug: dh_key_exchange = yes
Wed Nov 14 19:05:47 2012 : Debug: rsa_key_length = 512
Wed Nov 14 19:05:47 2012 : Debug: dh_key_length = 512
Wed Nov 14 19:05:47 2012 : Debug: verify_depth = 0
Wed Nov 14 19:05:47 2012 : Debug: CA_path = "/etc/freeradius/certs"
Wed Nov 14 19:05:47 2012 : Debug: pem_file_type = yes
Wed Nov 14 19:05:47 2012 : Debug: private_key_file = "/etc/freeradius/certs/server.key"
Wed Nov 14 19:05:47 2012 : Debug: certificate_file = "/etc/freeradius/certs/server.pem"
Wed Nov 14 19:05:47 2012 : Debug: CA_file = "/etc/freeradius/certs/ca.pem"
Wed Nov 14 19:05:47 2012 : Debug: private_key_password = "whatever"
Wed Nov 14 19:05:47 2012 : Debug: dh_file = "/etc/freeradius/certs/dh"
Wed Nov 14 19:05:47 2012 : Debug: random_file = "/dev/urandom"
Wed Nov 14 19:05:47 2012 : Debug: fragment_size = 1024
Wed Nov 14 19:05:47 2012 : Debug: include_length = yes
Wed Nov 14 19:05:47 2012 : Debug: check_crl = no
Wed Nov 14 19:05:47 2012 : Debug: cipher_list = "DEFAULT"
Wed Nov 14 19:05:47 2012 : Debug: make_cert_command = "/etc/freeradius/certs/bootstrap"
Wed Nov 14 19:05:47 2012 : Debug: ecdh_curve = "prime256v1"
Wed Nov 14 19:05:47 2012 : Debug: cache {
Wed Nov 14 19:05:47 2012 : Debug: enable = no
Wed Nov 14 19:05:47 2012 : Debug: lifetime = 24
Wed Nov 14 19:05:47 2012 : Debug: max_entries = 255
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: verify {
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: ocsp {
Wed Nov 14 19:05:47 2012 : Debug: enable = no
Wed Nov 14 19:05:47 2012 : Debug: override_cert_url = yes
Wed Nov 14 19:05:47 2012 : Debug: url = "http://127.0.0.1/ocsp/"
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:47 2012 : Debug: }
Wed Nov 14 19:05:49 2012 : Debug: Module: Linked to sub-module rlm_eap_ttls
Wed Nov 14 19:05:50 2012 : Debug: Module: Instantiating eap-ttls
Wed Nov 14 19:05:50 2012 : Debug: ttls {
Wed Nov 14 19:05:50 2012 : Debug: default_eap_type = "md5"
Wed Nov 14 19:05:50 2012 : Debug: copy_request_to_tunnel = no
Wed Nov 14 19:05:50 2012 : Debug: use_tunneled_reply = no
Wed Nov 14 19:05:50 2012 : Debug: virtual_server = "inner-tunnel"
Wed Nov 14 19:05:50 2012 : Debug: include_length = yes
Wed Nov 14 19:05:50 2012 : Debug: }
Wed Nov 14 19:05:50 2012 : Debug: Module: Linked to sub-module rlm_eap_peap
Wed Nov 14 19:05:50 2012 : Debug: Module: Instantiating eap-peap
Wed Nov 14 19:05:50 2012 : Debug: peap {
Wed Nov 14 19:05:50 2012 : Debug: default_eap_type = "mschapv2"
Wed Nov 14 19:05:50 2012 : Debug: copy_request_to_tunnel = no
Wed Nov 14 19:05:50 2012 : Debug: use_tunneled_reply = no
Wed Nov 14 19:05:50 2012 : Debug: proxy_tunneled_request_as_eap = yes
Wed Nov 14 19:05:50 2012 : Debug: virtual_server = "inner-tunnel"
Wed Nov 14 19:05:50 2012 : Debug: soh = no
Wed Nov 14 19:05:50 2012 : Debug: }
Wed Nov 14 19:05:50 2012 : Debug: Module: Linked to sub-module rlm_eap_mschapv2
Wed Nov 14 19:05:50 2012 : Debug: Module: Instantiating eap-mschapv2
Wed Nov 14 19:05:50 2012 : Debug: mschapv2 {
Wed Nov 14 19:05:50 2012 : Debug: with_ntdomain_hack = no
Wed Nov 14 19:05:50 2012 : Debug: send_error = no
Wed Nov 14 19:05:50 2012 : Debug: }
Wed Nov 14 19:05:50 2012 : Debug: Module: Checking authorize {...} for more modules to load
Wed Nov 14 19:05:50 2012 : Debug: (Loaded rlm_preprocess, checking if it's valid)
Wed Nov 14 19:05:50 2012 : Debug: Module: Linked to module rlm_preprocess
Wed Nov 14 19:05:50 2012 : Debug: Module: Instantiating module "preprocess" from file /etc/freeradius/modules/preprocess
Wed Nov 14 19:05:50 2012 : Debug: preprocess {
Wed Nov 14 19:05:50 2012 : Debug: huntgroups = "/etc/freeradius/huntgroups"
Wed Nov 14 19:05:50 2012 : Debug: hints = "/etc/freeradius/hints"
Wed Nov 14 19:05:50 2012 : Debug: with_ascend_hack = no
Wed Nov 14 19:05:50 2012 : Debug: ascend_channels_per_line = 23
Wed Nov 14 19:05:50 2012 : Debug: with_ntdomain_hack = no
Wed Nov 14 19:05:50 2012 : Debug: with_specialix_jetstream_hack = no
Wed Nov 14 19:05:50 2012 : Debug: with_cisco_vsa_hack = no
Wed Nov 14 19:05:50 2012 : Debug: with_alvarion_vsa_hack = no
Wed Nov 14 19:05:50 2012 : Debug: }
Wed Nov 14 19:05:50 2012 : Debug: (Loaded rlm_realm, checking if it's valid)
Wed Nov 14 19:05:50 2012 : Debug: Module: Linked to module rlm_realm
Wed Nov 14 19:05:50 2012 : Debug: Module: Instantiating module "suffix" from file /etc/freeradius/modules/realm
Wed Nov 14 19:05:50 2012 : Debug: realm suffix {
Wed Nov 14 19:05:50 2012 : Debug: format = "suffix"
Wed Nov 14 19:05:50 2012 : Debug: delimiter = "@"
Wed Nov 14 19:05:50 2012 : Debug: ignore_default = no
Wed Nov 14 19:05:50 2012 : Debug: ignore_null = no
Wed Nov 14 19:05:50 2012 : Debug: }
Wed Nov 14 19:05:50 2012 : Debug: (Loaded rlm_files, checking if it's valid)
Wed Nov 14 19:05:50 2012 : Debug: Module: Linked to module rlm_files
Wed Nov 14 19:05:50 2012 : Debug: Module: Instantiating module "files" from file /etc/freeradius/modules/files
Wed Nov 14 19:05:50 2012 : Debug: files {
Wed Nov 14 19:05:50 2012 : Debug: usersfile = "/etc/freeradius/users"
Wed Nov 14 19:05:50 2012 : Debug: acctusersfile = "/etc/freeradius/acct_users"
Wed Nov 14 19:05:50 2012 : Debug: preproxy_usersfile = "/etc/freeradius/preproxy_users"
Wed Nov 14 19:05:50 2012 : Debug: compat = "no"
Wed Nov 14 19:05:50 2012 : Debug: }
Wed Nov 14 19:05:50 2012 : Debug: Module: Checking preacct {...} for more modules to load
Wed Nov 14 19:05:50 2012 : Debug: (Loaded rlm_acct_unique, checking if it's valid)
Wed Nov 14 19:05:50 2012 : Debug: Module: Linked to module rlm_acct_unique
Wed Nov 14 19:05:50 2012 : Debug: Module: Instantiating module "acct_unique" from file /etc/freeradius/modules/acct_unique
Wed Nov 14 19:05:50 2012 : Debug: acct_unique {
Wed Nov 14 19:05:50 2012 : Debug: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
Wed Nov 14 19:05:50 2012 : Debug: }
Wed Nov 14 19:05:50 2012 : Debug: Module: Checking accounting {...} for more modules to load
Wed Nov 14 19:05:50 2012 : Debug: (Loaded rlm_detail, checking if it's valid)
Wed Nov 14 19:05:50 2012 : Debug: Module: Linked to module rlm_detail
Wed Nov 14 19:05:50 2012 : Debug: Module: Instantiating module "detail" from file /etc/freeradius/modules/detail
Wed Nov 14 19:05:50 2012 : Debug: detail {
Wed Nov 14 19:05:50 2012 : Debug: detailfile = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d"
Wed Nov 14 19:05:50 2012 : Debug: header = "%t"
Wed Nov 14 19:05:50 2012 : Debug: detailperm = 384
Wed Nov 14 19:05:50 2012 : Debug: dirperm = 493
Wed Nov 14 19:05:50 2012 : Debug: locking = no
Wed Nov 14 19:05:50 2012 : Debug: log_packet_header = no
Wed Nov 14 19:05:50 2012 : Debug: }
Wed Nov 14 19:05:50 2012 : Debug: (Loaded rlm_radutmp, checking if it's valid)
Wed Nov 14 19:05:50 2012 : Debug: Module: Linked to module rlm_radutmp
Wed Nov 14 19:05:50 2012 : Debug: Module: Instantiating module "radutmp" from file /etc/freeradius/modules/radutmp
Wed Nov 14 19:05:50 2012 : Debug: radutmp {
Wed Nov 14 19:05:50 2012 : Debug: filename = "/var/log/freeradius/radutmp"
Wed Nov 14 19:05:50 2012 : Debug: username = "%{User-Name}"
Wed Nov 14 19:05:50 2012 : Debug: case_sensitive = yes
Wed Nov 14 19:05:50 2012 : Debug: check_with_nas = yes
Wed Nov 14 19:05:50 2012 : Debug: perm = 384
Wed Nov 14 19:05:50 2012 : Debug: callerid = yes
Wed Nov 14 19:05:50 2012 : Debug: }
Wed Nov 14 19:05:50 2012 : Debug: (Loaded rlm_attr_filter, checking if it's valid)
Wed Nov 14 19:05:50 2012 : Debug: Module: Linked to module rlm_attr_filter
Wed Nov 14 19:05:50 2012 : Debug: Module: Instantiating module "attr_filter.accounting_response" from file /etc/freeradius/modules/attr_filter
Wed Nov 14 19:05:50 2012 : Debug: attr_filter attr_filter.accounting_response {
Wed Nov 14 19:05:50 2012 : Debug: attrsfile = "/etc/freeradius/attrs.accounting_response"
Wed Nov 14 19:05:50 2012 : Debug: key = "%{User-Name}"
Wed Nov 14 19:05:50 2012 : Debug: relaxed = no
Wed Nov 14 19:05:50 2012 : Debug: }
Wed Nov 14 19:05:50 2012 : Debug: Module: Checking session {...} for more modules to load
Wed Nov 14 19:05:50 2012 : Debug: Module: Checking post-proxy {...} for more modules to load
Wed Nov 14 19:05:50 2012 : Debug: Module: Checking post-auth {...} for more modules to load
Wed Nov 14 19:05:50 2012 : Debug: Module: Instantiating module "attr_filter.access_reject" from file /etc/freeradius/modules/attr_filter
Wed Nov 14 19:05:50 2012 : Debug: attr_filter attr_filter.access_reject {
Wed Nov 14 19:05:50 2012 : Debug: attrsfile = "/etc/freeradius/attrs.access_reject"
Wed Nov 14 19:05:50 2012 : Debug: key = "%{User-Name}"
Wed Nov 14 19:05:50 2012 : Debug: relaxed = no
Wed Nov 14 19:05:50 2012 : Debug: }
Wed Nov 14 19:05:50 2012 : Debug: } # modules
Wed Nov 14 19:05:50 2012 : Debug: } # server
Wed Nov 14 19:05:50 2012 : Debug: server inner-tunnel { # from file /etc/freeradius/sites-enabled/inner-tunnel
Wed Nov 14 19:05:50 2012 : Debug: modules {
Wed Nov 14 19:05:50 2012 : Debug: Module: Checking authenticate {...} for more modules to load
Wed Nov 14 19:05:50 2012 : Debug: Module: Checking authorize {...} for more modules to load
Wed Nov 14 19:05:50 2012 : Debug: Module: Checking session {...} for more modules to load
Wed Nov 14 19:05:50 2012 : Debug: Module: Checking post-proxy {...} for more modules to load
Wed Nov 14 19:05:50 2012 : Debug: Module: Checking post-auth {...} for more modules to load
Wed Nov 14 19:05:50 2012 : Debug: } # modules
Wed Nov 14 19:05:50 2012 : Debug: } # server
Wed Nov 14 19:05:50 2012 : Debug: radiusd: #### Opening IP addresses and Ports ####
Wed Nov 14 19:05:50 2012 : Debug: listen {
Wed Nov 14 19:05:50 2012 : Debug: type = "auth"
Wed Nov 14 19:05:50 2012 : Debug: ipaddr = *
Wed Nov 14 19:05:50 2012 : Debug: port = 0
Wed Nov 14 19:05:50 2012 : Debug: }
Wed Nov 14 19:05:50 2012 : Debug: listen {
Wed Nov 14 19:05:50 2012 : Debug: type = "acct"
Wed Nov 14 19:05:50 2012 : Debug: ipaddr = *
Wed Nov 14 19:05:50 2012 : Debug: port = 0
Wed Nov 14 19:05:50 2012 : Debug: }
Wed Nov 14 19:05:50 2012 : Debug: listen {
Wed Nov 14 19:05:50 2012 : Debug: type = "auth"
Wed Nov 14 19:05:50 2012 : Debug: ipaddr = 127.0.0.1
Wed Nov 14 19:05:50 2012 : Debug: port = 18120
Wed Nov 14 19:05:50 2012 : Debug: }
Wed Nov 14 19:05:50 2012 : Info: ... adding new socket proxy address * port 47244
Wed Nov 14 19:05:50 2012 : Debug: Listening on authentication address * port 1812
Wed Nov 14 19:05:50 2012 : Debug: Listening on accounting address * port 1813
Wed Nov 14 19:05:50 2012 : Debug: Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel
Wed Nov 14 19:05:50 2012 : Debug: Listening on proxy address * port 1814
Wed Nov 14 19:05:50 2012 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 192.168.2.10 port 3079, id=22, length=128
User-Name = "remy"
NAS-IP-Address = 192.168.2.10
NAS-Identifier = "RalinkAP0"
NAS-Port = 0
Called-Station-Id = "00-14-D1-9D-0F-10"
Calling-Station-Id = "A0-0B-BA-D6-63-BE"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x020100090172656d79
Message-Authenticator = 0xe60edddb20d9a70b3b344ea7f8367006
Wed Nov 14 19:07:35 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:35 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:35 2012 : Info: ++[preprocess] returns ok
Wed Nov 14 19:07:35 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[digest] returns noop
Wed Nov 14 19:07:35 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:35 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:35 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP packet type response id 1 length 9
Wed Nov 14 19:07:35 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Wed Nov 14 19:07:35 2012 : Info: ++[eap] returns updated
Wed Nov 14 19:07:35 2012 : Info: [files] users: Matched entry remy at line 206
Wed Nov 14 19:07:35 2012 : Info: ++[files] returns ok
Wed Nov 14 19:07:35 2012 : Info: ++[expiration] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[logintime] returns noop
Wed Nov 14 19:07:35 2012 : Info: [pap] Normalizing SHA-Password from hex encoding
Wed Nov 14 19:07:35 2012 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP
Wed Nov 14 19:07:35 2012 : Info: ++[pap] returns noop
Wed Nov 14 19:07:35 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:35 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:35 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP Identity
Wed Nov 14 19:07:35 2012 : Info: [eap] processing type md5
Wed Nov 14 19:07:35 2012 : Debug: rlm_eap_md5: Issuing Challenge
Wed Nov 14 19:07:35 2012 : Info: ++[eap] returns handled
Sending Access-Challenge of id 22 to 192.168.2.10 port 3079
EAP-Message = 0x0102001604108876be2b51bfcdfe09b9746c0ee47f21
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x7d0c82717d0e86642a42e5741cc98360
Wed Nov 14 19:07:35 2012 : Info: Finished request 0.
Wed Nov 14 19:07:35 2012 : Debug: Going to the next request
Wed Nov 14 19:07:35 2012 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.2.10 port 3079, id=23, length=143
User-Name = "remy"
NAS-IP-Address = 192.168.2.10
NAS-Identifier = "RalinkAP0"
NAS-Port = 0
Called-Station-Id = "00-14-D1-9D-0F-10"
Calling-Station-Id = "A0-0B-BA-D6-63-BE"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x020200060319
State = 0x7d0c82717d0e86642a42e5741cc98360
Message-Authenticator = 0x2702597733d47246dfb2b46aaf894f55
Wed Nov 14 19:07:35 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:35 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:35 2012 : Info: ++[preprocess] returns ok
Wed Nov 14 19:07:35 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[digest] returns noop
Wed Nov 14 19:07:35 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:35 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:35 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP packet type response id 2 length 6
Wed Nov 14 19:07:35 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Wed Nov 14 19:07:35 2012 : Info: ++[eap] returns updated
Wed Nov 14 19:07:35 2012 : Info: [files] users: Matched entry remy at line 206
Wed Nov 14 19:07:35 2012 : Info: ++[files] returns ok
Wed Nov 14 19:07:35 2012 : Info: ++[expiration] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[logintime] returns noop
Wed Nov 14 19:07:35 2012 : Info: [pap] Normalizing SHA-Password from hex encoding
Wed Nov 14 19:07:35 2012 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP
Wed Nov 14 19:07:35 2012 : Info: ++[pap] returns noop
Wed Nov 14 19:07:35 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:35 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:35 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:35 2012 : Info: [eap] Request found, released from the list
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP NAK
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP-NAK asked for EAP-Type/peap
Wed Nov 14 19:07:35 2012 : Info: [eap] processing type tls
Wed Nov 14 19:07:35 2012 : Info: [tls] Initiate
Wed Nov 14 19:07:35 2012 : Info: [tls] Start returned 1
Wed Nov 14 19:07:35 2012 : Info: ++[eap] returns handled
Sending Access-Challenge of id 23 to 192.168.2.10 port 3079
EAP-Message = 0x010300061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x7d0c82717c0f9b642a42e5741cc98360
Wed Nov 14 19:07:35 2012 : Info: Finished request 1.
Wed Nov 14 19:07:35 2012 : Debug: Going to the next request
Wed Nov 14 19:07:35 2012 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.2.10 port 3079, id=24, length=345
User-Name = "remy"
NAS-IP-Address = 192.168.2.10
NAS-Identifier = "RalinkAP0"
NAS-Port = 0
Called-Station-Id = "00-14-D1-9D-0F-10"
Calling-Station-Id = "A0-0B-BA-D6-63-BE"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x020300d01980000000c616030100c1010000bd030150a3dde64eae1721ba84b0640c553e42d5799121f900c21c1d56e026b3a72048000054c014c00ac022c02100390038c00fc0050035c012c008c01cc01b00160013c00dc003000ac013c009c01fc01e00330032c00ec004002fc011c007c00cc002000500040015001200090014001100080006000300ff01000040000b000403000102000a00340032000e000d0019000b000c00180009000a00160017000800060007001400150004000500120013000100020003000f00100011
State = 0x7d0c82717c0f9b642a42e5741cc98360
Message-Authenticator = 0x528230329ebe3904c221def9cde50068
Wed Nov 14 19:07:35 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:35 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:35 2012 : Info: ++[preprocess] returns ok
Wed Nov 14 19:07:35 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[digest] returns noop
Wed Nov 14 19:07:35 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:35 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:35 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP packet type response id 3 length 208
Wed Nov 14 19:07:35 2012 : Info: [eap] Continuing tunnel setup.
Wed Nov 14 19:07:35 2012 : Info: ++[eap] returns ok
Wed Nov 14 19:07:35 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:35 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:35 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:35 2012 : Info: [eap] Request found, released from the list
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP/peap
Wed Nov 14 19:07:35 2012 : Info: [eap] processing type peap
Wed Nov 14 19:07:35 2012 : Info: [peap] processing EAP-TLS
Wed Nov 14 19:07:35 2012 : Debug: TLS Length 198
Wed Nov 14 19:07:35 2012 : Info: [peap] Length Included
Wed Nov 14 19:07:35 2012 : Info: [peap] eaptls_verify returned 11
Wed Nov 14 19:07:35 2012 : Info: [peap] (other): before/accept initialization
Wed Nov 14 19:07:35 2012 : Info: [peap] TLS_accept: before/accept initialization
Wed Nov 14 19:07:35 2012 : Info: [peap] <<< TLS 1.0 Handshake [length 00c1], ClientHello
Wed Nov 14 19:07:35 2012 : Info: [peap] TLS_accept: SSLv3 read client hello A
Wed Nov 14 19:07:35 2012 : Info: [peap] >>> TLS 1.0 Handshake [length 0039], ServerHello
Wed Nov 14 19:07:35 2012 : Info: [peap] TLS_accept: SSLv3 write server hello A
Wed Nov 14 19:07:35 2012 : Info: [peap] >>> TLS 1.0 Handshake [length 02ca], Certificate
Wed Nov 14 19:07:35 2012 : Info: [peap] TLS_accept: SSLv3 write certificate A
Wed Nov 14 19:07:35 2012 : Info: [peap] >>> TLS 1.0 Handshake [length 014b], ServerKeyExchange
Wed Nov 14 19:07:35 2012 : Info: [peap] TLS_accept: SSLv3 write key exchange A
Wed Nov 14 19:07:35 2012 : Info: [peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
Wed Nov 14 19:07:35 2012 : Info: [peap] TLS_accept: SSLv3 write server done A
Wed Nov 14 19:07:35 2012 : Info: [peap] TLS_accept: SSLv3 flush data
Wed Nov 14 19:07:35 2012 : Info: [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A
Wed Nov 14 19:07:35 2012 : Debug: In SSL Handshake Phase
Wed Nov 14 19:07:35 2012 : Debug: In SSL Accept mode
Wed Nov 14 19:07:35 2012 : Info: [peap] eaptls_process returned 13
Wed Nov 14 19:07:35 2012 : Info: [peap] EAPTLS_HANDLED
Wed Nov 14 19:07:35 2012 : Info: ++[eap] returns handled
Sending Access-Challenge of id 24 to 192.168.2.10 port 3079
EAP-Message = 0x0104040019c000000466160301003902000035030150a3dde7ebdd5dfb7d3082b92bb98835266aad15d25c1db525503007afe1ca7200c01400000dff01000100000b00040300010216030102ca0b0002c60002c30002c0308202bc308201a4a003020102020900949b3689e1037e9c300d06092a864886f70d01010505003016311430120603550403130b7261737062657272797069301e170d3132313131323231323530345a170d3232313131303231323530345a3016311430120603550403130b726173706265727279706930820122300d06092a864886f70d01010105000382010f003082010a0282010100dca0cc418820bcf0867fbdc96fc9
EAP-Message = 0xfa81586d63ea36f1eae162bf1b77529341b440ccd7e90a260332bf3eeec4bebe6ab7718703c46eaccd759b9cd459d63f511da72547e98cdc6a90ac60cff07843e559b9b1bee160ebdd1aaabf1b6d400ae1f6920a4bfe7316f73943a721b9d458f005977b2138d752572f35830f43981584a6985a10628148183cd5a866e1df07df4516a548135ee56e9c3c0ad046d6c78452cb07177e8e88566fc0452c24c8eb4f777eb4836465df48391802aa17393f67dc906a0df4012b55906256b507f07536fcba2227cf5f7f74ca369eecbeb99c2aadd0457b3f4a9152d5fd6b9ddc48237c00f44d31b397a9271c03ceb48df873dc810203010001a30d300b3009
EAP-Message = 0x0603551d1304023000300d06092a864886f70d010105050003820101002342eb822166e5f1aa0ac4529c18a463f8ec3202e42a20ace218ae6b1b09a00adde2fa8207224a45f153fab75efcfe008560049c17495372321d0bf1519c408ce060fe6cf8a49234c7b95a30f1dc39f0caf0e5038b3242cce12429976483940b33b4d774e324c12327cf4523801b4cfea8fcd75bc4d4a117c47a974c146886465dfba0895a374ee6f43cfbd2a59f78e97c8baf9b1f1e0e66ade3d1baf41b1bc267d885aa931021c93ce4dbb3f5ef16cd9629daeaa3dc074cda5ea574d740c8d027882f0d70a3d03a8ae71a25236cabd89ef28a452ca1367c9402b233da7d4164
EAP-Message = 0x55d10206f2c1648c1957595e39df55689c2ce55224faa21e65f48231c77066b0160301014b0c00014703001741044821bd371aef9b855599ca4650474f5d7e20697f0a958aff65f042d9d096ba03fcf3310a9bc178534e7e64dbcc201af6e68172fda3f6192b5380b428550f826c010075dc9bf25936a1322a4890ffd613bc97ae0b2aa260756f9a543cc3ee8268b2a874c897e0799453e791b428ca42fc4b97c152f6f65a8689753cd9b0ea29ff119fbbf3d0d673d4399741f64786de19b0e1e0c7b6a6c7f36068f1e896a9d109c348f0826ec69a5d0a1c2cfbf1317a3cf54fc10c72c0120d654816c00f6d539e7f25738466b1a7ffcc98920e142c3d
EAP-Message = 0x40f00bf5f2264f0d1a679a50
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x7d0c82717f089b642a42e5741cc98360
Wed Nov 14 19:07:35 2012 : Info: Finished request 2.
Wed Nov 14 19:07:35 2012 : Debug: Going to the next request
Wed Nov 14 19:07:35 2012 : Debug: Waking up in 4.8 seconds.
rad_recv: Access-Request packet from host 192.168.2.10 port 3079, id=25, length=143
User-Name = "remy"
NAS-IP-Address = 192.168.2.10
NAS-Identifier = "RalinkAP0"
NAS-Port = 0
Called-Station-Id = "00-14-D1-9D-0F-10"
Calling-Station-Id = "A0-0B-BA-D6-63-BE"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x020400061900
State = 0x7d0c82717f089b642a42e5741cc98360
Message-Authenticator = 0xd879ed3a533e1f5761afd863aaacaad1
Wed Nov 14 19:07:35 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:35 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:35 2012 : Info: ++[preprocess] returns ok
Wed Nov 14 19:07:35 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[digest] returns noop
Wed Nov 14 19:07:35 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:35 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:35 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP packet type response id 4 length 6
Wed Nov 14 19:07:35 2012 : Info: [eap] Continuing tunnel setup.
Wed Nov 14 19:07:35 2012 : Info: ++[eap] returns ok
Wed Nov 14 19:07:35 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:35 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:35 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:35 2012 : Info: [eap] Request found, released from the list
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP/peap
Wed Nov 14 19:07:35 2012 : Info: [eap] processing type peap
Wed Nov 14 19:07:35 2012 : Info: [peap] processing EAP-TLS
Wed Nov 14 19:07:35 2012 : Info: [peap] Received TLS ACK
Wed Nov 14 19:07:35 2012 : Info: [peap] ACK handshake fragment handler
Wed Nov 14 19:07:35 2012 : Info: [peap] eaptls_verify returned 1
Wed Nov 14 19:07:35 2012 : Info: [peap] eaptls_process returned 13
Wed Nov 14 19:07:35 2012 : Info: [peap] EAPTLS_HANDLED
Wed Nov 14 19:07:35 2012 : Info: ++[eap] returns handled
Sending Access-Challenge of id 25 to 192.168.2.10 port 3079
EAP-Message = 0x0105007619002810c47077535ebc41d46ec85bb5c44735312908ad2e3326048ee10942539f8e6cd6d84353cc1bab475d48b8b4c80eb8613d24825bd310d613a890e5d12da7baece1646234082479ccf2604b70db235f71f43ec690dedc5f09d28a0d3d23787aeaafa9de96a90416030100040e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x7d0c82717e099b642a42e5741cc98360
Wed Nov 14 19:07:35 2012 : Info: Finished request 3.
Wed Nov 14 19:07:35 2012 : Debug: Going to the next request
Wed Nov 14 19:07:35 2012 : Debug: Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 192.168.2.10 port 3079, id=26, length=281
User-Name = "remy"
NAS-IP-Address = 192.168.2.10
NAS-Identifier = "RalinkAP0"
NAS-Port = 0
Called-Station-Id = "00-14-D1-9D-0F-10"
Calling-Station-Id = "A0-0B-BA-D6-63-BE"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x020500901980000000861603010046100000424104badeaabcb2296cffa2403d47061a9fc7f4c63e47f6daa8d96dad075aa8579c3b15f97f3a07a8a455afc164d9a1b647839a77b3dec113df200c4935a194ba88451403010001011603010030b68abde9e54e49b881bfb038e257888e77e2a74d5df89b650cda0eb88cb3fbc1d2e9dc203d4408eff1220b2e7917cc3f
State = 0x7d0c82717e099b642a42e5741cc98360
Message-Authenticator = 0x00c3b6c067b1c2944f9fb5d920e7d097
Wed Nov 14 19:07:35 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:35 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:35 2012 : Info: ++[preprocess] returns ok
Wed Nov 14 19:07:35 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[digest] returns noop
Wed Nov 14 19:07:35 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:35 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:35 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP packet type response id 5 length 144
Wed Nov 14 19:07:35 2012 : Info: [eap] Continuing tunnel setup.
Wed Nov 14 19:07:35 2012 : Info: ++[eap] returns ok
Wed Nov 14 19:07:35 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:35 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:35 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:35 2012 : Info: [eap] Request found, released from the list
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP/peap
Wed Nov 14 19:07:35 2012 : Info: [eap] processing type peap
Wed Nov 14 19:07:35 2012 : Info: [peap] processing EAP-TLS
Wed Nov 14 19:07:35 2012 : Debug: TLS Length 134
Wed Nov 14 19:07:35 2012 : Info: [peap] Length Included
Wed Nov 14 19:07:35 2012 : Info: [peap] eaptls_verify returned 11
Wed Nov 14 19:07:35 2012 : Info: [peap] <<< TLS 1.0 Handshake [length 0046], ClientKeyExchange
Wed Nov 14 19:07:35 2012 : Info: [peap] TLS_accept: SSLv3 read client key exchange A
Wed Nov 14 19:07:35 2012 : Info: [peap] <<< TLS 1.0 ChangeCipherSpec [length 0001]
Wed Nov 14 19:07:35 2012 : Info: [peap] <<< TLS 1.0 Handshake [length 0010], Finished
Wed Nov 14 19:07:35 2012 : Info: [peap] TLS_accept: SSLv3 read finished A
Wed Nov 14 19:07:35 2012 : Info: [peap] >>> TLS 1.0 ChangeCipherSpec [length 0001]
Wed Nov 14 19:07:35 2012 : Info: [peap] TLS_accept: SSLv3 write change cipher spec A
Wed Nov 14 19:07:35 2012 : Info: [peap] >>> TLS 1.0 Handshake [length 0010], Finished
Wed Nov 14 19:07:35 2012 : Info: [peap] TLS_accept: SSLv3 write finished A
Wed Nov 14 19:07:35 2012 : Info: [peap] TLS_accept: SSLv3 flush data
Wed Nov 14 19:07:35 2012 : Info: [peap] (other): SSL negotiation finished successfully
Wed Nov 14 19:07:35 2012 : Debug: SSL Connection Established
Wed Nov 14 19:07:35 2012 : Info: [peap] eaptls_process returned 13
Wed Nov 14 19:07:35 2012 : Info: [peap] EAPTLS_HANDLED
Wed Nov 14 19:07:35 2012 : Info: ++[eap] returns handled
Sending Access-Challenge of id 26 to 192.168.2.10 port 3079
EAP-Message = 0x01060041190014030100010116030100303ad99c26b84db2d956a56b71db8b58ea881bd7798e9305ebace55736d3952862d61f57e5b3903f0e1c771377aa25e30f
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x7d0c8271790a9b642a42e5741cc98360
Wed Nov 14 19:07:35 2012 : Info: Finished request 4.
Wed Nov 14 19:07:35 2012 : Debug: Going to the next request
Wed Nov 14 19:07:35 2012 : Debug: Waking up in 4.6 seconds.
rad_recv: Access-Request packet from host 192.168.2.10 port 3079, id=27, length=143
User-Name = "remy"
NAS-IP-Address = 192.168.2.10
NAS-Identifier = "RalinkAP0"
NAS-Port = 0
Called-Station-Id = "00-14-D1-9D-0F-10"
Calling-Station-Id = "A0-0B-BA-D6-63-BE"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x020600061900
State = 0x7d0c8271790a9b642a42e5741cc98360
Message-Authenticator = 0x5803c5b6a1ecaccc69c32607ded941f9
Wed Nov 14 19:07:35 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:35 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:35 2012 : Info: ++[preprocess] returns ok
Wed Nov 14 19:07:35 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[digest] returns noop
Wed Nov 14 19:07:35 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:35 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:35 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP packet type response id 6 length 6
Wed Nov 14 19:07:35 2012 : Info: [eap] Continuing tunnel setup.
Wed Nov 14 19:07:35 2012 : Info: ++[eap] returns ok
Wed Nov 14 19:07:35 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:35 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:35 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:35 2012 : Info: [eap] Request found, released from the list
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP/peap
Wed Nov 14 19:07:35 2012 : Info: [eap] processing type peap
Wed Nov 14 19:07:35 2012 : Info: [peap] processing EAP-TLS
Wed Nov 14 19:07:35 2012 : Info: [peap] Received TLS ACK
Wed Nov 14 19:07:35 2012 : Info: [peap] ACK handshake is finished
Wed Nov 14 19:07:35 2012 : Info: [peap] eaptls_verify returned 3
Wed Nov 14 19:07:35 2012 : Info: [peap] eaptls_process returned 3
Wed Nov 14 19:07:35 2012 : Info: [peap] EAPTLS_SUCCESS
Wed Nov 14 19:07:35 2012 : Info: [peap] Session established. Decoding tunneled attributes.
Wed Nov 14 19:07:35 2012 : Info: [peap] Peap state TUNNEL ESTABLISHED
Wed Nov 14 19:07:35 2012 : Info: ++[eap] returns handled
Sending Access-Challenge of id 27 to 192.168.2.10 port 3079
EAP-Message = 0x0107002b190017030100206410cc3341cf32e248499107d1de3a22d0271cf598c7217f03a69a5c288b9846
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x7d0c8271780b9b642a42e5741cc98360
Wed Nov 14 19:07:35 2012 : Info: Finished request 5.
Wed Nov 14 19:07:35 2012 : Debug: Going to the next request
Wed Nov 14 19:07:35 2012 : Debug: Waking up in 4.6 seconds.
rad_recv: Access-Request packet from host 192.168.2.10 port 3079, id=28, length=217
User-Name = "remy"
NAS-IP-Address = 192.168.2.10
NAS-Identifier = "RalinkAP0"
NAS-Port = 0
Called-Station-Id = "00-14-D1-9D-0F-10"
Calling-Station-Id = "A0-0B-BA-D6-63-BE"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x0207005019001703010020763581dc3b1f1b3af7176c3ef92714467ced4b063995704a9fda6238f28e5c2717030100207dcd81e5b7089fcefe5229d5aa1466e49339c334a37958e8a04e6119bfdc45f1
State = 0x7d0c8271780b9b642a42e5741cc98360
Message-Authenticator = 0x009a330cc06bb2f10fdef27fb6af375e
Wed Nov 14 19:07:35 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:35 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:35 2012 : Info: ++[preprocess] returns ok
Wed Nov 14 19:07:35 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[digest] returns noop
Wed Nov 14 19:07:35 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:35 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:35 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP packet type response id 7 length 80
Wed Nov 14 19:07:35 2012 : Info: [eap] Continuing tunnel setup.
Wed Nov 14 19:07:35 2012 : Info: ++[eap] returns ok
Wed Nov 14 19:07:35 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:35 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:35 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:35 2012 : Info: [eap] Request found, released from the list
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP/peap
Wed Nov 14 19:07:35 2012 : Info: [eap] processing type peap
Wed Nov 14 19:07:35 2012 : Info: [peap] processing EAP-TLS
Wed Nov 14 19:07:35 2012 : Info: [peap] eaptls_verify returned 7
Wed Nov 14 19:07:35 2012 : Info: [peap] Done initial handshake
Wed Nov 14 19:07:35 2012 : Info: [peap] eaptls_process returned 7
Wed Nov 14 19:07:35 2012 : Info: [peap] EAPTLS_OK
Wed Nov 14 19:07:35 2012 : Info: [peap] Session established. Decoding tunneled attributes.
Wed Nov 14 19:07:35 2012 : Info: [peap] Peap state WAITING FOR INNER IDENTITY
Wed Nov 14 19:07:35 2012 : Info: [peap] Identity - remy
Wed Nov 14 19:07:35 2012 : Info: [peap] Got inner identity 'remy'
Wed Nov 14 19:07:35 2012 : Info: [peap] Setting default EAP type for tunneled EAP session.
Wed Nov 14 19:07:35 2012 : Info: [peap] Got tunneled request
EAP-Message = 0x020700090172656d79
server {
Wed Nov 14 19:07:35 2012 : Info: [peap] Setting User-Name to remy
Sending tunneled request
EAP-Message = 0x020700090172656d79
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "remy"
server inner-tunnel {
Wed Nov 14 19:07:35 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel
Wed Nov 14 19:07:35 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:35 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:35 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:35 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:35 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[control] returns noop
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP packet type response id 7 length 9
Wed Nov 14 19:07:35 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Wed Nov 14 19:07:35 2012 : Info: ++[eap] returns updated
Wed Nov 14 19:07:35 2012 : Info: [files] users: Matched entry remy at line 206
Wed Nov 14 19:07:35 2012 : Info: ++[files] returns ok
Wed Nov 14 19:07:35 2012 : Info: ++[expiration] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[logintime] returns noop
Wed Nov 14 19:07:35 2012 : Info: [pap] Normalizing SHA-Password from hex encoding
Wed Nov 14 19:07:35 2012 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP
Wed Nov 14 19:07:35 2012 : Info: ++[pap] returns noop
Wed Nov 14 19:07:35 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:35 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
Wed Nov 14 19:07:35 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP Identity
Wed Nov 14 19:07:35 2012 : Info: [eap] processing type mschapv2
Wed Nov 14 19:07:35 2012 : Debug: rlm_eap_mschapv2: Issuing Challenge
Wed Nov 14 19:07:35 2012 : Info: ++[eap] returns handled
} # server inner-tunnel
Wed Nov 14 19:07:35 2012 : Info: [peap] Got tunneled reply code 11
EAP-Message = 0x0108001e1a01080019107b5e8711d1c93282ae82c68e2d51985972656d79
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x7d6763917d6f79a05af800b89bff6744
Wed Nov 14 19:07:35 2012 : Info: [peap] Got tunneled reply RADIUS code 11
EAP-Message = 0x0108001e1a01080019107b5e8711d1c93282ae82c68e2d51985972656d79
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x7d6763917d6f79a05af800b89bff6744
Wed Nov 14 19:07:35 2012 : Info: [peap] Got tunneled Access-Challenge
PEAP tunnel data out 0000: 1a 01 08 00 19 10 7b 5e 87 11 d1 c9 32 82 ae 82
PEAP tunnel data out 0010: c6 8e 2d 51 98 59 72 65 6d 79
Wed Nov 14 19:07:35 2012 : Info: ++[eap] returns handled
Sending Access-Challenge of id 28 to 192.168.2.10 port 3079
EAP-Message = 0x0108003b190017030100300792acea7915ced4cae73061d1532bc0ab5835a72cc23c5926e8c54c0292c0ef81b995cba92a18a50cd4681054327097
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x7d0c82717b049b642a42e5741cc98360
Wed Nov 14 19:07:35 2012 : Info: Finished request 6.
Wed Nov 14 19:07:35 2012 : Debug: Going to the next request
Wed Nov 14 19:07:35 2012 : Debug: Waking up in 4.5 seconds.
rad_recv: Access-Request packet from host 192.168.2.10 port 3079, id=29, length=265
User-Name = "remy"
NAS-IP-Address = 192.168.2.10
NAS-Identifier = "RalinkAP0"
NAS-Port = 0
Called-Station-Id = "00-14-D1-9D-0F-10"
Calling-Station-Id = "A0-0B-BA-D6-63-BE"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x02080080190017030100207024487f4cf8a8fc2888ad22cbafac0d3b600b8044f06fbec1920c1cb896999017030100501ecbc14032635cfd6d4d82eefb2f1cd6d1b0a52034e5009cd641bf475969dc900c058608d25457c0a1e45d34b1e86ce5f272d195a9d9aa308fe3b53ca7dcde47573e7f98f5987c71e33a2f67f9f70a36
State = 0x7d0c82717b049b642a42e5741cc98360
Message-Authenticator = 0x3d2e47136c560ea1f472d23831fe90b0
Wed Nov 14 19:07:35 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:35 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:35 2012 : Info: ++[preprocess] returns ok
Wed Nov 14 19:07:35 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[digest] returns noop
Wed Nov 14 19:07:35 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:35 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:35 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP packet type response id 8 length 128
Wed Nov 14 19:07:35 2012 : Info: [eap] Continuing tunnel setup.
Wed Nov 14 19:07:35 2012 : Info: ++[eap] returns ok
Wed Nov 14 19:07:35 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:35 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:35 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:35 2012 : Info: [eap] Request found, released from the list
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP/peap
Wed Nov 14 19:07:35 2012 : Info: [eap] processing type peap
Wed Nov 14 19:07:35 2012 : Info: [peap] processing EAP-TLS
Wed Nov 14 19:07:35 2012 : Info: [peap] eaptls_verify returned 7
Wed Nov 14 19:07:35 2012 : Info: [peap] Done initial handshake
Wed Nov 14 19:07:35 2012 : Info: [peap] eaptls_process returned 7
Wed Nov 14 19:07:35 2012 : Info: [peap] EAPTLS_OK
Wed Nov 14 19:07:35 2012 : Info: [peap] Session established. Decoding tunneled attributes.
Wed Nov 14 19:07:35 2012 : Info: [peap] Peap state phase2
Wed Nov 14 19:07:35 2012 : Info: [peap] EAP type mschapv2
Wed Nov 14 19:07:35 2012 : Info: [peap] Got tunneled request
EAP-Message = 0x0208003f1a0208003a31a9774074fca3160b7f5566619041727100000000000000006677a8de72c075766fc843e81d157732e116af689f2fe5db0072656d79
server {
Wed Nov 14 19:07:35 2012 : Info: [peap] Setting User-Name to remy
Sending tunneled request
EAP-Message = 0x0208003f1a0208003a31a9774074fca3160b7f5566619041727100000000000000006677a8de72c075766fc843e81d157732e116af689f2fe5db0072656d79
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "remy"
State = 0x7d6763917d6f79a05af800b89bff6744
server inner-tunnel {
Wed Nov 14 19:07:35 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel
Wed Nov 14 19:07:35 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:35 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:35 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:35 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:35 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[control] returns noop
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP packet type response id 8 length 63
Wed Nov 14 19:07:35 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Wed Nov 14 19:07:35 2012 : Info: ++[eap] returns updated
Wed Nov 14 19:07:35 2012 : Info: [files] users: Matched entry remy at line 206
Wed Nov 14 19:07:35 2012 : Info: ++[files] returns ok
Wed Nov 14 19:07:35 2012 : Info: ++[expiration] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[logintime] returns noop
Wed Nov 14 19:07:35 2012 : Info: [pap] Normalizing SHA-Password from hex encoding
Wed Nov 14 19:07:35 2012 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP
Wed Nov 14 19:07:35 2012 : Info: ++[pap] returns noop
Wed Nov 14 19:07:35 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:35 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
Wed Nov 14 19:07:35 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:35 2012 : Info: [eap] Request found, released from the list
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP/mschapv2
Wed Nov 14 19:07:35 2012 : Info: [eap] processing type mschapv2
Wed Nov 14 19:07:35 2012 : Info: [mschapv2] # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
Wed Nov 14 19:07:35 2012 : Info: [mschapv2] +- entering group MS-CHAP {...}
Wed Nov 14 19:07:35 2012 : Info: [mschap] No Cleartext-Password configured. Cannot create LM-Password.
Wed Nov 14 19:07:35 2012 : Info: [mschap] No Cleartext-Password configured. Cannot create NT-Password.
Wed Nov 14 19:07:35 2012 : Info: [mschap] Creating challenge hash with username: remy
Wed Nov 14 19:07:35 2012 : Info: [mschap] Told to do MS-CHAPv2 for remy with NT-Password
Wed Nov 14 19:07:35 2012 : Info: [mschap] FAILED: No NT/LM-Password. Cannot perform authentication.
Wed Nov 14 19:07:35 2012 : Info: [mschap] FAILED: MS-CHAP2-Response is incorrect
Wed Nov 14 19:07:35 2012 : Info: ++[mschap] returns reject
Wed Nov 14 19:07:35 2012 : Info: [eap] Freeing handler
Wed Nov 14 19:07:35 2012 : Info: ++[eap] returns reject
Wed Nov 14 19:07:35 2012 : Info: Failed to authenticate the user.
Wed Nov 14 19:07:35 2012 : Auth: Login incorrect: [remy/<via Auth-Type = EAP>] (from client remywifi port 0 via TLS tunnel)
} # server inner-tunnel
Wed Nov 14 19:07:35 2012 : Info: [peap] Got tunneled reply code 3
MS-CHAP-Error = "\010E=691 R=1"
EAP-Message = 0x04080004
Message-Authenticator = 0x00000000000000000000000000000000
Wed Nov 14 19:07:35 2012 : Info: [peap] Got tunneled reply RADIUS code 3
MS-CHAP-Error = "\010E=691 R=1"
EAP-Message = 0x04080004
Message-Authenticator = 0x00000000000000000000000000000000
Wed Nov 14 19:07:35 2012 : Info: [peap] Tunneled authentication was rejected.
Wed Nov 14 19:07:35 2012 : Info: [peap] FAILURE
Wed Nov 14 19:07:35 2012 : Info: ++[eap] returns handled
Sending Access-Challenge of id 29 to 192.168.2.10 port 3079
EAP-Message = 0x0109002b1900170301002031aa12c26bbbb75bc2f4b5769ea50a778706db350b7d432bd726678aa1e5e5c7
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x7d0c82717a059b642a42e5741cc98360
Wed Nov 14 19:07:35 2012 : Info: Finished request 7.
Wed Nov 14 19:07:35 2012 : Debug: Going to the next request
Wed Nov 14 19:07:35 2012 : Debug: Waking up in 4.4 seconds.
rad_recv: Access-Request packet from host 192.168.2.10 port 3079, id=30, length=217
User-Name = "remy"
NAS-IP-Address = 192.168.2.10
NAS-Identifier = "RalinkAP0"
NAS-Port = 0
Called-Station-Id = "00-14-D1-9D-0F-10"
Calling-Station-Id = "A0-0B-BA-D6-63-BE"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x0209005019001703010020c7a95d84b564f93a1960cf7f6bc86f65b86886c7987972b349ba6a74873f3e9017030100205dedc04e347a1f59d6d094caf3b4aeb5b9de55f1c916f15ab1b82b0b0f9e6a8c
State = 0x7d0c82717a059b642a42e5741cc98360
Message-Authenticator = 0x573c643c57caf5105bc178d26d2f844e
Wed Nov 14 19:07:35 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:35 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:35 2012 : Info: ++[preprocess] returns ok
Wed Nov 14 19:07:35 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:35 2012 : Info: ++[digest] returns noop
Wed Nov 14 19:07:35 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:35 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:35 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP packet type response id 9 length 80
Wed Nov 14 19:07:35 2012 : Info: [eap] Continuing tunnel setup.
Wed Nov 14 19:07:35 2012 : Info: ++[eap] returns ok
Wed Nov 14 19:07:35 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:35 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:35 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:35 2012 : Info: [eap] Request found, released from the list
Wed Nov 14 19:07:35 2012 : Info: [eap] EAP/peap
Wed Nov 14 19:07:35 2012 : Info: [eap] processing type peap
Wed Nov 14 19:07:35 2012 : Info: [peap] processing EAP-TLS
Wed Nov 14 19:07:35 2012 : Info: [peap] eaptls_verify returned 7
Wed Nov 14 19:07:35 2012 : Info: [peap] Done initial handshake
Wed Nov 14 19:07:35 2012 : Info: [peap] eaptls_process returned 7
Wed Nov 14 19:07:35 2012 : Info: [peap] EAPTLS_OK
Wed Nov 14 19:07:35 2012 : Info: [peap] Session established. Decoding tunneled attributes.
Wed Nov 14 19:07:35 2012 : Info: [peap] Peap state send tlv failure
Wed Nov 14 19:07:35 2012 : Info: [peap] Received EAP-TLV response.
Wed Nov 14 19:07:35 2012 : Info: [peap] The users session was previously rejected: returning reject (again.)
Wed Nov 14 19:07:35 2012 : Info: [peap] *** This means you need to read the PREVIOUS messages in the debug output
Wed Nov 14 19:07:35 2012 : Info: [peap] *** to find out the reason why the user was rejected.
Wed Nov 14 19:07:35 2012 : Info: [peap] *** Look for "reject" or "fail". Those earlier messages will tell you.
Wed Nov 14 19:07:35 2012 : Info: [peap] *** what went wrong, and how to fix the problem.
Wed Nov 14 19:07:35 2012 : Info: [eap] Handler failed in EAP/peap
Wed Nov 14 19:07:35 2012 : Info: [eap] Failed in EAP select
Wed Nov 14 19:07:35 2012 : Info: ++[eap] returns invalid
Wed Nov 14 19:07:35 2012 : Info: Failed to authenticate the user.
Wed Nov 14 19:07:35 2012 : Auth: Login incorrect: [remy/<via Auth-Type = EAP>] (from client remywifi port 0 cli A0-0B-BA-D6-63-BE)
Wed Nov 14 19:07:35 2012 : Info: Using Post-Auth-Type Reject
Wed Nov 14 19:07:35 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:35 2012 : Info: +- entering group REJECT {...}
Wed Nov 14 19:07:35 2012 : Info: [attr_filter.access_reject] expand: %{User-Name} -> remy
Wed Nov 14 19:07:35 2012 : Debug: attr_filter: Matched entry DEFAULT at line 11
Wed Nov 14 19:07:35 2012 : Info: ++[attr_filter.access_reject] returns updated
Wed Nov 14 19:07:35 2012 : Info: Delaying reject of request 8 for 1 seconds
Wed Nov 14 19:07:35 2012 : Debug: Going to the next request
Wed Nov 14 19:07:35 2012 : Debug: Waking up in 0.9 seconds.
Wed Nov 14 19:07:36 2012 : Info: Sending delayed reject for request 8
Sending Access-Reject of id 30 to 192.168.2.10 port 3079
EAP-Message = 0x04090004
Message-Authenticator = 0x00000000000000000000000000000000
Wed Nov 14 19:07:36 2012 : Debug: Waking up in 3.4 seconds.
rad_recv: Access-Request packet from host 192.168.2.10 port 3079, id=31, length=128
User-Name = "remy"
NAS-IP-Address = 192.168.2.10
NAS-Identifier = "RalinkAP0"
NAS-Port = 0
Called-Station-Id = "00-14-D1-9D-0F-10"
Calling-Station-Id = "A0-0B-BA-D6-63-BE"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x020100090172656d79
Message-Authenticator = 0xaf83843780d194536c8f2cbdd4771206
Wed Nov 14 19:07:39 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:39 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:39 2012 : Info: ++[preprocess] returns ok
Wed Nov 14 19:07:39 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[digest] returns noop
Wed Nov 14 19:07:39 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:39 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:39 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP packet type response id 1 length 9
Wed Nov 14 19:07:39 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns updated
Wed Nov 14 19:07:39 2012 : Info: [files] users: Matched entry remy at line 206
Wed Nov 14 19:07:39 2012 : Info: ++[files] returns ok
Wed Nov 14 19:07:39 2012 : Info: ++[expiration] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[logintime] returns noop
Wed Nov 14 19:07:39 2012 : Info: [pap] Normalizing SHA-Password from hex encoding
Wed Nov 14 19:07:39 2012 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP
Wed Nov 14 19:07:39 2012 : Info: ++[pap] returns noop
Wed Nov 14 19:07:39 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:39 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:39 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP Identity
Wed Nov 14 19:07:39 2012 : Info: [eap] processing type md5
Wed Nov 14 19:07:39 2012 : Debug: rlm_eap_md5: Issuing Challenge
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns handled
Sending Access-Challenge of id 31 to 192.168.2.10 port 3079
EAP-Message = 0x0102001604103032a3117595549ed7bd734fabc7dc13
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xacbba286acb9a699580815ef5be5c20c
Wed Nov 14 19:07:39 2012 : Info: Finished request 9.
Wed Nov 14 19:07:39 2012 : Debug: Going to the next request
Wed Nov 14 19:07:39 2012 : Debug: Waking up in 1.1 seconds.
rad_recv: Access-Request packet from host 192.168.2.10 port 3079, id=32, length=143
User-Name = "remy"
NAS-IP-Address = 192.168.2.10
NAS-Identifier = "RalinkAP0"
NAS-Port = 0
Called-Station-Id = "00-14-D1-9D-0F-10"
Calling-Station-Id = "A0-0B-BA-D6-63-BE"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x020200060319
State = 0xacbba286acb9a699580815ef5be5c20c
Message-Authenticator = 0x7f6b8814d24c7ef04ab51b3ea7afbb9c
Wed Nov 14 19:07:39 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:39 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:39 2012 : Info: ++[preprocess] returns ok
Wed Nov 14 19:07:39 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[digest] returns noop
Wed Nov 14 19:07:39 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:39 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:39 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP packet type response id 2 length 6
Wed Nov 14 19:07:39 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns updated
Wed Nov 14 19:07:39 2012 : Info: [files] users: Matched entry remy at line 206
Wed Nov 14 19:07:39 2012 : Info: ++[files] returns ok
Wed Nov 14 19:07:39 2012 : Info: ++[expiration] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[logintime] returns noop
Wed Nov 14 19:07:39 2012 : Info: [pap] Normalizing SHA-Password from hex encoding
Wed Nov 14 19:07:39 2012 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP
Wed Nov 14 19:07:39 2012 : Info: ++[pap] returns noop
Wed Nov 14 19:07:39 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:39 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:39 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:39 2012 : Info: [eap] Request found, released from the list
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP NAK
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP-NAK asked for EAP-Type/peap
Wed Nov 14 19:07:39 2012 : Info: [eap] processing type tls
Wed Nov 14 19:07:39 2012 : Info: [tls] Initiate
Wed Nov 14 19:07:39 2012 : Info: [tls] Start returned 1
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns handled
Sending Access-Challenge of id 32 to 192.168.2.10 port 3079
EAP-Message = 0x010300061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xacbba286adb8bb99580815ef5be5c20c
Wed Nov 14 19:07:39 2012 : Info: Finished request 10.
Wed Nov 14 19:07:39 2012 : Debug: Going to the next request
Wed Nov 14 19:07:39 2012 : Debug: Waking up in 1.1 seconds.
rad_recv: Access-Request packet from host 192.168.2.10 port 3079, id=33, length=345
User-Name = "remy"
NAS-IP-Address = 192.168.2.10
NAS-Identifier = "RalinkAP0"
NAS-Port = 0
Called-Station-Id = "00-14-D1-9D-0F-10"
Calling-Station-Id = "A0-0B-BA-D6-63-BE"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x020300d01980000000c616030100c1010000bd030150a3ddeab34a39df2ea88cebe01495fe9d69a7104818a8d9ab3757d0daaa6274000054c014c00ac022c02100390038c00fc0050035c012c008c01cc01b00160013c00dc003000ac013c009c01fc01e00330032c00ec004002fc011c007c00cc002000500040015001200090014001100080006000300ff01000040000b000403000102000a00340032000e000d0019000b000c00180009000a00160017000800060007001400150004000500120013000100020003000f00100011
State = 0xacbba286adb8bb99580815ef5be5c20c
Message-Authenticator = 0x544053244b2ec02f2b45f5d48b90b2c9
Wed Nov 14 19:07:39 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:39 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:39 2012 : Info: ++[preprocess] returns ok
Wed Nov 14 19:07:39 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[digest] returns noop
Wed Nov 14 19:07:39 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:39 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:39 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP packet type response id 3 length 208
Wed Nov 14 19:07:39 2012 : Info: [eap] Continuing tunnel setup.
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns ok
Wed Nov 14 19:07:39 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:39 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:39 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:39 2012 : Info: [eap] Request found, released from the list
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP/peap
Wed Nov 14 19:07:39 2012 : Info: [eap] processing type peap
Wed Nov 14 19:07:39 2012 : Info: [peap] processing EAP-TLS
Wed Nov 14 19:07:39 2012 : Debug: TLS Length 198
Wed Nov 14 19:07:39 2012 : Info: [peap] Length Included
Wed Nov 14 19:07:39 2012 : Info: [peap] eaptls_verify returned 11
Wed Nov 14 19:07:39 2012 : Info: [peap] (other): before/accept initialization
Wed Nov 14 19:07:39 2012 : Info: [peap] TLS_accept: before/accept initialization
Wed Nov 14 19:07:39 2012 : Info: [peap] <<< TLS 1.0 Handshake [length 00c1], ClientHello
Wed Nov 14 19:07:39 2012 : Info: [peap] TLS_accept: SSLv3 read client hello A
Wed Nov 14 19:07:39 2012 : Info: [peap] >>> TLS 1.0 Handshake [length 0039], ServerHello
Wed Nov 14 19:07:39 2012 : Info: [peap] TLS_accept: SSLv3 write server hello A
Wed Nov 14 19:07:39 2012 : Info: [peap] >>> TLS 1.0 Handshake [length 02ca], Certificate
Wed Nov 14 19:07:39 2012 : Info: [peap] TLS_accept: SSLv3 write certificate A
Wed Nov 14 19:07:39 2012 : Info: [peap] >>> TLS 1.0 Handshake [length 014b], ServerKeyExchange
Wed Nov 14 19:07:39 2012 : Info: [peap] TLS_accept: SSLv3 write key exchange A
Wed Nov 14 19:07:39 2012 : Info: [peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
Wed Nov 14 19:07:39 2012 : Info: [peap] TLS_accept: SSLv3 write server done A
Wed Nov 14 19:07:39 2012 : Info: [peap] TLS_accept: SSLv3 flush data
Wed Nov 14 19:07:39 2012 : Info: [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A
Wed Nov 14 19:07:39 2012 : Debug: In SSL Handshake Phase
Wed Nov 14 19:07:39 2012 : Debug: In SSL Accept mode
Wed Nov 14 19:07:39 2012 : Info: [peap] eaptls_process returned 13
Wed Nov 14 19:07:39 2012 : Info: [peap] EAPTLS_HANDLED
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns handled
Sending Access-Challenge of id 33 to 192.168.2.10 port 3079
EAP-Message = 0x0104040019c000000466160301003902000035030150a3ddebfd4569f119cd5e9b43e4dba6548bbb52df082edcb444ede0afc00fed00c01400000dff01000100000b00040300010216030102ca0b0002c60002c30002c0308202bc308201a4a003020102020900949b3689e1037e9c300d06092a864886f70d01010505003016311430120603550403130b7261737062657272797069301e170d3132313131323231323530345a170d3232313131303231323530345a3016311430120603550403130b726173706265727279706930820122300d06092a864886f70d01010105000382010f003082010a0282010100dca0cc418820bcf0867fbdc96fc9
EAP-Message = 0xfa81586d63ea36f1eae162bf1b77529341b440ccd7e90a260332bf3eeec4bebe6ab7718703c46eaccd759b9cd459d63f511da72547e98cdc6a90ac60cff07843e559b9b1bee160ebdd1aaabf1b6d400ae1f6920a4bfe7316f73943a721b9d458f005977b2138d752572f35830f43981584a6985a10628148183cd5a866e1df07df4516a548135ee56e9c3c0ad046d6c78452cb07177e8e88566fc0452c24c8eb4f777eb4836465df48391802aa17393f67dc906a0df4012b55906256b507f07536fcba2227cf5f7f74ca369eecbeb99c2aadd0457b3f4a9152d5fd6b9ddc48237c00f44d31b397a9271c03ceb48df873dc810203010001a30d300b3009
EAP-Message = 0x0603551d1304023000300d06092a864886f70d010105050003820101002342eb822166e5f1aa0ac4529c18a463f8ec3202e42a20ace218ae6b1b09a00adde2fa8207224a45f153fab75efcfe008560049c17495372321d0bf1519c408ce060fe6cf8a49234c7b95a30f1dc39f0caf0e5038b3242cce12429976483940b33b4d774e324c12327cf4523801b4cfea8fcd75bc4d4a117c47a974c146886465dfba0895a374ee6f43cfbd2a59f78e97c8baf9b1f1e0e66ade3d1baf41b1bc267d885aa931021c93ce4dbb3f5ef16cd9629daeaa3dc074cda5ea574d740c8d027882f0d70a3d03a8ae71a25236cabd89ef28a452ca1367c9402b233da7d4164
EAP-Message = 0x55d10206f2c1648c1957595e39df55689c2ce55224faa21e65f48231c77066b0160301014b0c000147030017410412c503208ba63f0799d43394f0f14445ba34b822eea41bd3defad5265054676d2cae3dd1fda4e40026fd28196df8b1d3ac08e710937efb92b9f0bbc9fb6a844b010071f190ba631c2af97ba767b39a033db677e1ce5a73b61329ae2ac2e5b105e4f5c13f97c34492412f80333fbbdcd673a7cd21d99cb5ae2d2c369e5e585bb5e38db12d26edfde0182e223e89cc7c5553ef97764401b2fc69d6e59287dbaadd781041d0e4cca40a1c1e679bf33c1f9577e92fb097b3950dc63b3f1fafaa5808d0492faba8842bda2d8ab580b830a8
EAP-Message = 0xbcbd704f43446a44b24b684c
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xacbba286aebfbb99580815ef5be5c20c
Wed Nov 14 19:07:39 2012 : Info: Finished request 11.
Wed Nov 14 19:07:39 2012 : Debug: Going to the next request
Wed Nov 14 19:07:39 2012 : Debug: Waking up in 0.9 seconds.
rad_recv: Access-Request packet from host 192.168.2.10 port 3079, id=17, length=217
User-Name = "remy"
NAS-IP-Address = 192.168.2.10
NAS-Identifier = "RalinkAP0"
NAS-Port = 0
Called-Station-Id = "00-14-D1-9D-0F-10"
Calling-Station-Id = "A0-0B-BA-D6-63-BE"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x0209005019001703010020d9219b58cba739373d784169bf64589d123f4ec53510ba7d6c4c4e063b5e9aaa17030100200e176cdc8f35cab58ef283b05dcf08be9e70ac12f3cecf0532e478440fca803a
State = 0xfebf194ff9b600611b1b83f17cf16f5f
Message-Authenticator = 0x83ce619dfb184f8beb17815e20809a54
Wed Nov 14 19:07:39 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:39 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:39 2012 : Info: ++[preprocess] returns ok
Wed Nov 14 19:07:39 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[digest] returns noop
Wed Nov 14 19:07:39 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:39 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:39 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP packet type response id 9 length 80
Wed Nov 14 19:07:39 2012 : Info: [eap] Continuing tunnel setup.
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns ok
Wed Nov 14 19:07:39 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:39 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:39 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:39 2012 : Error: rlm_eap: No EAP session matching the State variable.
Wed Nov 14 19:07:39 2012 : Info: [eap] Either EAP-request timed out OR EAP-response to an unknown EAP-request
Wed Nov 14 19:07:39 2012 : Info: [eap] Failed in handler
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns invalid
Wed Nov 14 19:07:39 2012 : Info: Failed to authenticate the user.
Wed Nov 14 19:07:39 2012 : Auth: Login incorrect: [remy/<via Auth-Type = EAP>] (from client remywifi port 0 cli A0-0B-BA-D6-63-BE)
Wed Nov 14 19:07:39 2012 : Info: Using Post-Auth-Type Reject
Wed Nov 14 19:07:39 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:39 2012 : Info: +- entering group REJECT {...}
Wed Nov 14 19:07:39 2012 : Info: [attr_filter.access_reject] expand: %{User-Name} -> remy
Wed Nov 14 19:07:39 2012 : Debug: attr_filter: Matched entry DEFAULT at line 11
Wed Nov 14 19:07:39 2012 : Info: ++[attr_filter.access_reject] returns updated
Wed Nov 14 19:07:39 2012 : Info: Delaying reject of request 12 for 1 seconds
Wed Nov 14 19:07:39 2012 : Debug: Going to the next request
Wed Nov 14 19:07:39 2012 : Debug: Waking up in 0.9 seconds.
rad_recv: Access-Request packet from host 192.168.2.10 port 3079, id=34, length=143
User-Name = "remy"
NAS-IP-Address = 192.168.2.10
NAS-Identifier = "RalinkAP0"
NAS-Port = 0
Called-Station-Id = "00-14-D1-9D-0F-10"
Calling-Station-Id = "A0-0B-BA-D6-63-BE"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x020400061900
State = 0xacbba286aebfbb99580815ef5be5c20c
Message-Authenticator = 0xe2755a6101a44dc4e0aef40f6c65c1a8
Wed Nov 14 19:07:39 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:39 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:39 2012 : Info: ++[preprocess] returns ok
Wed Nov 14 19:07:39 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[digest] returns noop
Wed Nov 14 19:07:39 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:39 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:39 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP packet type response id 4 length 6
Wed Nov 14 19:07:39 2012 : Info: [eap] Continuing tunnel setup.
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns ok
Wed Nov 14 19:07:39 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:39 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:39 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:39 2012 : Info: [eap] Request found, released from the list
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP/peap
Wed Nov 14 19:07:39 2012 : Info: [eap] processing type peap
Wed Nov 14 19:07:39 2012 : Info: [peap] processing EAP-TLS
Wed Nov 14 19:07:39 2012 : Info: [peap] Received TLS ACK
Wed Nov 14 19:07:39 2012 : Info: [peap] ACK handshake fragment handler
Wed Nov 14 19:07:39 2012 : Info: [peap] eaptls_verify returned 1
Wed Nov 14 19:07:39 2012 : Info: [peap] eaptls_process returned 13
Wed Nov 14 19:07:39 2012 : Info: [peap] EAPTLS_HANDLED
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns handled
Sending Access-Challenge of id 34 to 192.168.2.10 port 3079
EAP-Message = 0x010500761900205dbaea5831266e95882e0d2ae3b6108aa88ab13448d43d5e4eeda883cc75ab43285ec994347583f01b76d3243c76f7aeec52e49fe1bc3aa5d6112195919d2a254edc6e01321b08787e3569c31fc42599934def60211485b59161f0bba5143f62a6ee6f52024216030100040e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xacbba286afbebb99580815ef5be5c20c
Wed Nov 14 19:07:39 2012 : Info: Finished request 13.
Wed Nov 14 19:07:39 2012 : Debug: Going to the next request
Wed Nov 14 19:07:39 2012 : Debug: Waking up in 0.9 seconds.
rad_recv: Access-Request packet from host 192.168.2.10 port 3079, id=35, length=281
User-Name = "remy"
NAS-IP-Address = 192.168.2.10
NAS-Identifier = "RalinkAP0"
NAS-Port = 0
Called-Station-Id = "00-14-D1-9D-0F-10"
Calling-Station-Id = "A0-0B-BA-D6-63-BE"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x020500901980000000861603010046100000424104ad14b2464620cbfa47b6012b1ef0943be66a53dd39143fe9ce41ba5cf3ea0400ba381d2509f868e9cc782fb02cb4088c69c1622d514a93033d3b55c5d24c14cf1403010001011603010030ba3a2e7a32942d0dc70a5856c8b2f44136347bc83043829eb8ab17eeea891145960381ee6bfb8ea398ead99a970a830b
State = 0xacbba286afbebb99580815ef5be5c20c
Message-Authenticator = 0xb5a2c45d2078a956368b0603b774c1c7
Wed Nov 14 19:07:39 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:39 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:39 2012 : Info: ++[preprocess] returns ok
Wed Nov 14 19:07:39 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[digest] returns noop
Wed Nov 14 19:07:39 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:39 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:39 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP packet type response id 5 length 144
Wed Nov 14 19:07:39 2012 : Info: [eap] Continuing tunnel setup.
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns ok
Wed Nov 14 19:07:39 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:39 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:39 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:39 2012 : Info: [eap] Request found, released from the list
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP/peap
Wed Nov 14 19:07:39 2012 : Info: [eap] processing type peap
Wed Nov 14 19:07:39 2012 : Info: [peap] processing EAP-TLS
Wed Nov 14 19:07:39 2012 : Debug: TLS Length 134
Wed Nov 14 19:07:39 2012 : Info: [peap] Length Included
Wed Nov 14 19:07:39 2012 : Info: [peap] eaptls_verify returned 11
Wed Nov 14 19:07:39 2012 : Info: [peap] <<< TLS 1.0 Handshake [length 0046], ClientKeyExchange
Wed Nov 14 19:07:39 2012 : Info: [peap] TLS_accept: SSLv3 read client key exchange A
Wed Nov 14 19:07:39 2012 : Info: [peap] <<< TLS 1.0 ChangeCipherSpec [length 0001]
Wed Nov 14 19:07:39 2012 : Info: [peap] <<< TLS 1.0 Handshake [length 0010], Finished
Wed Nov 14 19:07:39 2012 : Info: [peap] TLS_accept: SSLv3 read finished A
Wed Nov 14 19:07:39 2012 : Info: [peap] >>> TLS 1.0 ChangeCipherSpec [length 0001]
Wed Nov 14 19:07:39 2012 : Info: [peap] TLS_accept: SSLv3 write change cipher spec A
Wed Nov 14 19:07:39 2012 : Info: [peap] >>> TLS 1.0 Handshake [length 0010], Finished
Wed Nov 14 19:07:39 2012 : Info: [peap] TLS_accept: SSLv3 write finished A
Wed Nov 14 19:07:39 2012 : Info: [peap] TLS_accept: SSLv3 flush data
Wed Nov 14 19:07:39 2012 : Info: [peap] (other): SSL negotiation finished successfully
Wed Nov 14 19:07:39 2012 : Debug: SSL Connection Established
Wed Nov 14 19:07:39 2012 : Info: [peap] eaptls_process returned 13
Wed Nov 14 19:07:39 2012 : Info: [peap] EAPTLS_HANDLED
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns handled
Sending Access-Challenge of id 35 to 192.168.2.10 port 3079
EAP-Message = 0x010600411900140301000101160301003063ec27ce6ee91f17d1287a6c15dac8bd76c1525a76c4870909b7f1cf2166dd9e0b9cd091c19506dd4d59ee21831db971
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xacbba286a8bdbb99580815ef5be5c20c
Wed Nov 14 19:07:39 2012 : Info: Finished request 14.
Wed Nov 14 19:07:39 2012 : Debug: Going to the next request
Wed Nov 14 19:07:39 2012 : Debug: Waking up in 0.8 seconds.
rad_recv: Access-Request packet from host 192.168.2.10 port 3079, id=36, length=143
User-Name = "remy"
NAS-IP-Address = 192.168.2.10
NAS-Identifier = "RalinkAP0"
NAS-Port = 0
Called-Station-Id = "00-14-D1-9D-0F-10"
Calling-Station-Id = "A0-0B-BA-D6-63-BE"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x020600061900
State = 0xacbba286a8bdbb99580815ef5be5c20c
Message-Authenticator = 0x619b4b43327d960fb4414bf038c4e06e
Wed Nov 14 19:07:39 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:39 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:39 2012 : Info: ++[preprocess] returns ok
Wed Nov 14 19:07:39 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[digest] returns noop
Wed Nov 14 19:07:39 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:39 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:39 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP packet type response id 6 length 6
Wed Nov 14 19:07:39 2012 : Info: [eap] Continuing tunnel setup.
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns ok
Wed Nov 14 19:07:39 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:39 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:39 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:39 2012 : Info: [eap] Request found, released from the list
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP/peap
Wed Nov 14 19:07:39 2012 : Info: [eap] processing type peap
Wed Nov 14 19:07:39 2012 : Info: [peap] processing EAP-TLS
Wed Nov 14 19:07:39 2012 : Info: [peap] Received TLS ACK
Wed Nov 14 19:07:39 2012 : Info: [peap] ACK handshake is finished
Wed Nov 14 19:07:39 2012 : Info: [peap] eaptls_verify returned 3
Wed Nov 14 19:07:39 2012 : Info: [peap] eaptls_process returned 3
Wed Nov 14 19:07:39 2012 : Info: [peap] EAPTLS_SUCCESS
Wed Nov 14 19:07:39 2012 : Info: [peap] Session established. Decoding tunneled attributes.
Wed Nov 14 19:07:39 2012 : Info: [peap] Peap state TUNNEL ESTABLISHED
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns handled
Sending Access-Challenge of id 36 to 192.168.2.10 port 3079
EAP-Message = 0x0107002b190017030100205ee89caf00736c92e56b2bfd41b028f47714edbf734fe5d5f2c3835d60f209a8
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xacbba286a9bcbb99580815ef5be5c20c
Wed Nov 14 19:07:39 2012 : Info: Finished request 15.
Wed Nov 14 19:07:39 2012 : Debug: Going to the next request
Wed Nov 14 19:07:39 2012 : Debug: Waking up in 0.8 seconds.
rad_recv: Access-Request packet from host 192.168.2.10 port 3079, id=37, length=217
User-Name = "remy"
NAS-IP-Address = 192.168.2.10
NAS-Identifier = "RalinkAP0"
NAS-Port = 0
Called-Station-Id = "00-14-D1-9D-0F-10"
Calling-Station-Id = "A0-0B-BA-D6-63-BE"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x0207005019001703010020eb7d36551601194078b9692d643839797a7b4dc5928ec5e1d23a3478e18c41241703010020c7a943e10dfff507ebc1722d105f20c140809741b675c7dc64794723c2b98c33
State = 0xacbba286a9bcbb99580815ef5be5c20c
Message-Authenticator = 0xde353ac71c8100fce49b5656bfb7962a
Wed Nov 14 19:07:39 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:39 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:39 2012 : Info: ++[preprocess] returns ok
Wed Nov 14 19:07:39 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[digest] returns noop
Wed Nov 14 19:07:39 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:39 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:39 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP packet type response id 7 length 80
Wed Nov 14 19:07:39 2012 : Info: [eap] Continuing tunnel setup.
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns ok
Wed Nov 14 19:07:39 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:39 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:39 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:39 2012 : Info: [eap] Request found, released from the list
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP/peap
Wed Nov 14 19:07:39 2012 : Info: [eap] processing type peap
Wed Nov 14 19:07:39 2012 : Info: [peap] processing EAP-TLS
Wed Nov 14 19:07:39 2012 : Info: [peap] eaptls_verify returned 7
Wed Nov 14 19:07:39 2012 : Info: [peap] Done initial handshake
Wed Nov 14 19:07:39 2012 : Info: [peap] eaptls_process returned 7
Wed Nov 14 19:07:39 2012 : Info: [peap] EAPTLS_OK
Wed Nov 14 19:07:39 2012 : Info: [peap] Session established. Decoding tunneled attributes.
Wed Nov 14 19:07:39 2012 : Info: [peap] Peap state WAITING FOR INNER IDENTITY
Wed Nov 14 19:07:39 2012 : Info: [peap] Identity - remy
Wed Nov 14 19:07:39 2012 : Info: [peap] Got inner identity 'remy'
Wed Nov 14 19:07:39 2012 : Info: [peap] Setting default EAP type for tunneled EAP session.
Wed Nov 14 19:07:39 2012 : Info: [peap] Got tunneled request
EAP-Message = 0x020700090172656d79
server {
Wed Nov 14 19:07:39 2012 : Info: [peap] Setting User-Name to remy
Sending tunneled request
EAP-Message = 0x020700090172656d79
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "remy"
server inner-tunnel {
Wed Nov 14 19:07:39 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel
Wed Nov 14 19:07:39 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:39 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:39 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:39 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:39 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[control] returns noop
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP packet type response id 7 length 9
Wed Nov 14 19:07:39 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns updated
Wed Nov 14 19:07:39 2012 : Info: [files] users: Matched entry remy at line 206
Wed Nov 14 19:07:39 2012 : Info: ++[files] returns ok
Wed Nov 14 19:07:39 2012 : Info: ++[expiration] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[logintime] returns noop
Wed Nov 14 19:07:39 2012 : Info: [pap] Normalizing SHA-Password from hex encoding
Wed Nov 14 19:07:39 2012 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP
Wed Nov 14 19:07:39 2012 : Info: ++[pap] returns noop
Wed Nov 14 19:07:39 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:39 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
Wed Nov 14 19:07:39 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP Identity
Wed Nov 14 19:07:39 2012 : Info: [eap] processing type mschapv2
Wed Nov 14 19:07:39 2012 : Debug: rlm_eap_mschapv2: Issuing Challenge
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns handled
} # server inner-tunnel
Wed Nov 14 19:07:39 2012 : Info: [peap] Got tunneled reply code 11
EAP-Message = 0x0108001e1a0108001910afa64c228471975dafb7f38bad4b56fe72656d79
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x08a00dc708a817263f872d2fe752bfcf
Wed Nov 14 19:07:39 2012 : Info: [peap] Got tunneled reply RADIUS code 11
EAP-Message = 0x0108001e1a0108001910afa64c228471975dafb7f38bad4b56fe72656d79
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x08a00dc708a817263f872d2fe752bfcf
Wed Nov 14 19:07:39 2012 : Info: [peap] Got tunneled Access-Challenge
PEAP tunnel data out 0000: 1a 01 08 00 19 10 af a6 4c 22 84 71 97 5d af b7
PEAP tunnel data out 0010: f3 8b ad 4b 56 fe 72 65 6d 79
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns handled
Sending Access-Challenge of id 37 to 192.168.2.10 port 3079
EAP-Message = 0x0108003b190017030100301e7cad42c59e94050e0c379f9fadcf5d380a30b9e8bf0af2702cf35bc138cfe119f3b146fffb16ce05017548e5b24c59
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xacbba286aab3bb99580815ef5be5c20c
Wed Nov 14 19:07:39 2012 : Info: Finished request 16.
Wed Nov 14 19:07:39 2012 : Debug: Going to the next request
Wed Nov 14 19:07:39 2012 : Debug: Waking up in 0.7 seconds.
rad_recv: Access-Request packet from host 192.168.2.10 port 3079, id=38, length=265
User-Name = "remy"
NAS-IP-Address = 192.168.2.10
NAS-Identifier = "RalinkAP0"
NAS-Port = 0
Called-Station-Id = "00-14-D1-9D-0F-10"
Calling-Station-Id = "A0-0B-BA-D6-63-BE"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x0208008019001703010020877d363bb22c97f5f90edfb64f6b6940425a1a2b1a883344e06efb3e895cd5211703010050c2cdb7bfa87130986ab6e3c144046f455ffa298c4fb21da246c24b03fd4cb8a42c884c5844e05ca040a407884a06eceed6c24ce9a7e5abe9c07bf1cc9ce30ebcd16b6d6413615a63ef5515b2ed08ee86
State = 0xacbba286aab3bb99580815ef5be5c20c
Message-Authenticator = 0xba0a07663c1838a10f492b0cd9725d5a
Wed Nov 14 19:07:39 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:39 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:39 2012 : Info: ++[preprocess] returns ok
Wed Nov 14 19:07:39 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[digest] returns noop
Wed Nov 14 19:07:39 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:39 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:39 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP packet type response id 8 length 128
Wed Nov 14 19:07:39 2012 : Info: [eap] Continuing tunnel setup.
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns ok
Wed Nov 14 19:07:39 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:39 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:39 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:39 2012 : Info: [eap] Request found, released from the list
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP/peap
Wed Nov 14 19:07:39 2012 : Info: [eap] processing type peap
Wed Nov 14 19:07:39 2012 : Info: [peap] processing EAP-TLS
Wed Nov 14 19:07:39 2012 : Info: [peap] eaptls_verify returned 7
Wed Nov 14 19:07:39 2012 : Info: [peap] Done initial handshake
Wed Nov 14 19:07:39 2012 : Info: [peap] eaptls_process returned 7
Wed Nov 14 19:07:39 2012 : Info: [peap] EAPTLS_OK
Wed Nov 14 19:07:39 2012 : Info: [peap] Session established. Decoding tunneled attributes.
Wed Nov 14 19:07:39 2012 : Info: [peap] Peap state phase2
Wed Nov 14 19:07:39 2012 : Info: [peap] EAP type mschapv2
Wed Nov 14 19:07:39 2012 : Info: [peap] Got tunneled request
EAP-Message = 0x0208003f1a0208003a3140fc2c950e605b3352ab394335f5ccb000000000000000009668435b3034772758340cf2d5d429ec51e01a623332340f0072656d79
server {
Wed Nov 14 19:07:39 2012 : Info: [peap] Setting User-Name to remy
Sending tunneled request
EAP-Message = 0x0208003f1a0208003a3140fc2c950e605b3352ab394335f5ccb000000000000000009668435b3034772758340cf2d5d429ec51e01a623332340f0072656d79
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "remy"
State = 0x08a00dc708a817263f872d2fe752bfcf
server inner-tunnel {
Wed Nov 14 19:07:39 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel
Wed Nov 14 19:07:39 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:39 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:39 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:39 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:39 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[control] returns noop
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP packet type response id 8 length 63
Wed Nov 14 19:07:39 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns updated
Wed Nov 14 19:07:39 2012 : Info: [files] users: Matched entry remy at line 206
Wed Nov 14 19:07:39 2012 : Info: ++[files] returns ok
Wed Nov 14 19:07:39 2012 : Info: ++[expiration] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[logintime] returns noop
Wed Nov 14 19:07:39 2012 : Info: [pap] Normalizing SHA-Password from hex encoding
Wed Nov 14 19:07:39 2012 : Info: [pap] WARNING: Auth-Type already set. Not setting to PAP
Wed Nov 14 19:07:39 2012 : Info: ++[pap] returns noop
Wed Nov 14 19:07:39 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:39 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
Wed Nov 14 19:07:39 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:39 2012 : Info: [eap] Request found, released from the list
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP/mschapv2
Wed Nov 14 19:07:39 2012 : Info: [eap] processing type mschapv2
Wed Nov 14 19:07:39 2012 : Info: [mschapv2] # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
Wed Nov 14 19:07:39 2012 : Info: [mschapv2] +- entering group MS-CHAP {...}
Wed Nov 14 19:07:39 2012 : Info: [mschap] No Cleartext-Password configured. Cannot create LM-Password.
Wed Nov 14 19:07:39 2012 : Info: [mschap] No Cleartext-Password configured. Cannot create NT-Password.
Wed Nov 14 19:07:39 2012 : Info: [mschap] Creating challenge hash with username: remy
Wed Nov 14 19:07:39 2012 : Info: [mschap] Told to do MS-CHAPv2 for remy with NT-Password
Wed Nov 14 19:07:39 2012 : Info: [mschap] FAILED: No NT/LM-Password. Cannot perform authentication.
Wed Nov 14 19:07:39 2012 : Info: [mschap] FAILED: MS-CHAP2-Response is incorrect
Wed Nov 14 19:07:39 2012 : Info: ++[mschap] returns reject
Wed Nov 14 19:07:39 2012 : Info: [eap] Freeing handler
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns reject
Wed Nov 14 19:07:39 2012 : Info: Failed to authenticate the user.
Wed Nov 14 19:07:39 2012 : Auth: Login incorrect: [remy/<via Auth-Type = EAP>] (from client remywifi port 0 via TLS tunnel)
} # server inner-tunnel
Wed Nov 14 19:07:39 2012 : Info: [peap] Got tunneled reply code 3
MS-CHAP-Error = "\010E=691 R=1"
EAP-Message = 0x04080004
Message-Authenticator = 0x00000000000000000000000000000000
Wed Nov 14 19:07:39 2012 : Info: [peap] Got tunneled reply RADIUS code 3
MS-CHAP-Error = "\010E=691 R=1"
EAP-Message = 0x04080004
Message-Authenticator = 0x00000000000000000000000000000000
Wed Nov 14 19:07:39 2012 : Info: [peap] Tunneled authentication was rejected.
Wed Nov 14 19:07:39 2012 : Info: [peap] FAILURE
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns handled
Sending Access-Challenge of id 38 to 192.168.2.10 port 3079
EAP-Message = 0x0109002b1900170301002088529cd825601d2c203f7b0d13e74c5fb537e315f8fc35a29670e9f6ee5e4427
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xacbba286abb2bb99580815ef5be5c20c
Wed Nov 14 19:07:39 2012 : Info: Finished request 17.
Wed Nov 14 19:07:39 2012 : Debug: Going to the next request
Wed Nov 14 19:07:39 2012 : Debug: Waking up in 0.6 seconds.
rad_recv: Access-Request packet from host 192.168.2.10 port 3079, id=39, length=217
User-Name = "remy"
NAS-IP-Address = 192.168.2.10
NAS-Identifier = "RalinkAP0"
NAS-Port = 0
Called-Station-Id = "00-14-D1-9D-0F-10"
Calling-Station-Id = "A0-0B-BA-D6-63-BE"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
EAP-Message = 0x0209005019001703010020340b82e8496b7eed5e5bbc0e022ee59e1bcbe20c770f1ec5234e2e9eca49e7dc1703010020bc91b7f0f6fe32721f912ea6d435e2a40a578d18dac32dbfdaac42814a686414
State = 0xacbba286abb2bb99580815ef5be5c20c
Message-Authenticator = 0x980f8da88d2589caa2e7cef19353f2d4
Wed Nov 14 19:07:39 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:39 2012 : Info: +- entering group authorize {...}
Wed Nov 14 19:07:39 2012 : Info: ++[preprocess] returns ok
Wed Nov 14 19:07:39 2012 : Info: ++[chap] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[mschap] returns noop
Wed Nov 14 19:07:39 2012 : Info: ++[digest] returns noop
Wed Nov 14 19:07:39 2012 : Info: [suffix] No '@' in User-Name = "remy", looking up realm NULL
Wed Nov 14 19:07:39 2012 : Info: [suffix] No such realm "NULL"
Wed Nov 14 19:07:39 2012 : Info: ++[suffix] returns noop
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP packet type response id 9 length 80
Wed Nov 14 19:07:39 2012 : Info: [eap] Continuing tunnel setup.
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns ok
Wed Nov 14 19:07:39 2012 : Info: Found Auth-Type = EAP
Wed Nov 14 19:07:39 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:39 2012 : Info: +- entering group authenticate {...}
Wed Nov 14 19:07:39 2012 : Info: [eap] Request found, released from the list
Wed Nov 14 19:07:39 2012 : Info: [eap] EAP/peap
Wed Nov 14 19:07:39 2012 : Info: [eap] processing type peap
Wed Nov 14 19:07:39 2012 : Info: [peap] processing EAP-TLS
Wed Nov 14 19:07:39 2012 : Info: [peap] eaptls_verify returned 7
Wed Nov 14 19:07:39 2012 : Info: [peap] Done initial handshake
Wed Nov 14 19:07:39 2012 : Info: [peap] eaptls_process returned 7
Wed Nov 14 19:07:39 2012 : Info: [peap] EAPTLS_OK
Wed Nov 14 19:07:39 2012 : Info: [peap] Session established. Decoding tunneled attributes.
Wed Nov 14 19:07:39 2012 : Info: [peap] Peap state send tlv failure
Wed Nov 14 19:07:39 2012 : Info: [peap] Received EAP-TLV response.
Wed Nov 14 19:07:39 2012 : Info: [peap] The users session was previously rejected: returning reject (again.)
Wed Nov 14 19:07:39 2012 : Info: [peap] *** This means you need to read the PREVIOUS messages in the debug output
Wed Nov 14 19:07:39 2012 : Info: [peap] *** to find out the reason why the user was rejected.
Wed Nov 14 19:07:39 2012 : Info: [peap] *** Look for "reject" or "fail". Those earlier messages will tell you.
Wed Nov 14 19:07:39 2012 : Info: [peap] *** what went wrong, and how to fix the problem.
Wed Nov 14 19:07:39 2012 : Info: [eap] Handler failed in EAP/peap
Wed Nov 14 19:07:39 2012 : Info: [eap] Failed in EAP select
Wed Nov 14 19:07:39 2012 : Info: ++[eap] returns invalid
Wed Nov 14 19:07:39 2012 : Info: Failed to authenticate the user.
Wed Nov 14 19:07:39 2012 : Auth: Login incorrect: [remy/<via Auth-Type = EAP>] (from client remywifi port 0 cli A0-0B-BA-D6-63-BE)
Wed Nov 14 19:07:39 2012 : Info: Using Post-Auth-Type Reject
Wed Nov 14 19:07:39 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Nov 14 19:07:39 2012 : Info: +- entering group REJECT {...}
Wed Nov 14 19:07:39 2012 : Info: [attr_filter.access_reject] expand: %{User-Name} -> remy
Wed Nov 14 19:07:39 2012 : Debug: attr_filter: Matched entry DEFAULT at line 11
Wed Nov 14 19:07:39 2012 : Info: ++[attr_filter.access_reject] returns updated
Wed Nov 14 19:07:39 2012 : Info: Delaying reject of request 18 for 1 seconds
Wed Nov 14 19:07:39 2012 : Debug: Going to the next request
Wed Nov 14 19:07:39 2012 : Debug: Waking up in 0.6 seconds.
rad_recv: Access-Request packet from host 192.168.2.10 port 3079, id=39, length=217
Wed Nov 14 19:07:40 2012 : Info: Waiting to send Access-Reject to client remywifi port 3079 - ID: 39
Wed Nov 14 19:07:40 2012 : Debug: Waking up in 0.1 seconds.
Wed Nov 14 19:07:40 2012 : Info: Cleaning up request 0 ID 22 with timestamp +105
Wed Nov 14 19:07:41 2012 : Info: Sending delayed reject for request 12
Sending Access-Reject of id 17 to 192.168.2.10 port 3079
Wed Nov 14 19:07:41 2012 : Info: Cleaning up request 1 ID 23 with timestamp +105
Wed Nov 14 19:07:41 2012 : Info: Cleaning up request 2 ID 24 with timestamp +105
Wed Nov 14 19:07:41 2012 : Info: Cleaning up request 3 ID 25 with timestamp +105
Wed Nov 14 19:07:41 2012 : Info: Cleaning up request 4 ID 26 with timestamp +105
Wed Nov 14 19:07:41 2012 : Info: Sending delayed reject for request 18
Sending Access-Reject of id 39 to 192.168.2.10 port 3079
EAP-Message = 0x04090004
Message-Authenticator = 0x00000000000000000000000000000000
Wed Nov 14 19:07:41 2012 : Info: Cleaning up request 5 ID 27 with timestamp +105
Wed Nov 14 19:07:41 2012 : Info: Cleaning up request 6 ID 28 with timestamp +105
Wed Nov 14 19:07:41 2012 : Info: Cleaning up request 7 ID 29 with timestamp +105
Wed Nov 14 19:07:41 2012 : Info: Cleaning up request 8 ID 30 with timestamp +105
Wed Nov 14 19:07:41 2012 : Debug: Waking up in 2.0 seconds.
Wed Nov 14 19:07:44 2012 : Info: Cleaning up request 9 ID 31 with timestamp +109
Wed Nov 14 19:07:44 2012 : Info: Cleaning up request 10 ID 32 with timestamp +109
Wed Nov 14 19:07:44 2012 : Debug: Waking up in 0.1 seconds.
Wed Nov 14 19:07:44 2012 : Info: Cleaning up request 11 ID 33 with timestamp +109
Wed Nov 14 19:07:44 2012 : Info: Cleaning up request 13 ID 34 with timestamp +109
Wed Nov 14 19:07:44 2012 : Info: Cleaning up request 14 ID 35 with timestamp +109
Wed Nov 14 19:07:44 2012 : Info: Cleaning up request 15 ID 36 with timestamp +109
Wed Nov 14 19:07:44 2012 : Info: Cleaning up request 16 ID 37 with timestamp +109
Wed Nov 14 19:07:44 2012 : Info: Cleaning up request 17 ID 38 with timestamp +109
Wed Nov 14 19:07:44 2012 : Debug: Waking up in 0.6 seconds.
Wed Nov 14 19:07:45 2012 : Info: Cleaning up request 12 ID 17 with timestamp +109
Wed Nov 14 19:07:45 2012 : Debug: Waking up in 0.3 seconds.
Wed Nov 14 19:07:45 2012 : Info: Cleaning up request 18 ID 39 with timestamp +109
Wed Nov 14 19:07:45 2012 : Info: Ready to process requests.
