RE: EAP problem

2 Aug 2012

      Alan,

Let me know if this debug is the latest master.  It should be but I don't
have personal verification.  The EAP issue is persisting as of this version:

rad@radserv:~$ sudo radiusd -Xxx
Thu Aug  2 12:28:36 2012 : Info: FreeRADIUS Version 3.0.0, for host
i686-pc-linux-gnu, built on Aug  1 2012 at 16:18:04
Thu Aug  2 12:28:36 2012 : Info: Copyright (C) 1999-2012 The FreeRADIUS
server project and contributors.
Thu Aug  2 12:28:36 2012 : Info: There is NO warranty; not even for
MERCHANTABILITY or FITNESS FOR A
Thu Aug  2 12:28:36 2012 : Info: PARTICULAR PURPOSE.
Thu Aug  2 12:28:36 2012 : Info: You may redistribute copies of FreeRADIUS
under the terms of the
Thu Aug  2 12:28:36 2012 : Info: GNU General Public License v2.
Thu Aug  2 12:28:36 2012 : Info:
Thu Aug  2 12:28:36 2012 : Info: Starting - reading configuration files ...
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/radiusd.conf
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/proxy.conf
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/clients.conf
Thu Aug  2 12:28:36 2012 : Debug: including files in directory
/usr/local/etc/raddb/modules/
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/expiration
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/dynamic_clients
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/preprocess
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/radutmp
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/files
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/attr_filter
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/realm
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/perl
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/sql_log
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/mschap
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/replicate
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/pam
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/detail
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/sradutmp
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/cui
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/echo
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/sqlcounter_expire_on_login
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/mac2ip
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/inner-eap
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/opendirectory
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/detail.example.com
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/checkval
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/etc_group
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/wimax
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/passwd
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/chap
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/detail.log
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/digest
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/attr_rewrite
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/linelog
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/pap
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/smbpasswd
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/ntlm_auth
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/otp
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/unix
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/rediswho
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/ippool
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/counter
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/acct_unique
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/krb5
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/redis
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/mac2vlan
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/expr
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/exec
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/logintime
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/policy
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/soh
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/ldap
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/smsotp
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/modules/always
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/eap.conf
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/policy.conf
Thu Aug  2 12:28:36 2012 : Debug: including files in directory
/usr/local/etc/raddb/sites-enabled/
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/sites-enabled/control-socket
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/sites-enabled/default
Thu Aug  2 12:28:36 2012 : Debug: including configuration file
/usr/local/etc/raddb/sites-enabled/inner-tunnel
Thu Aug  2 12:28:36 2012 : Debug: main {
Thu Aug  2 12:28:36 2012 : Debug:  security {
Thu Aug  2 12:28:36 2012 : Debug:       allow_core_dumps = no
Thu Aug  2 12:28:36 2012 : Debug:  }
Thu Aug  2 12:28:36 2012 : Error: /usr/local/etc/raddb/radiusd.conf[0]:
"allow_core_dumps" is deprecated.  Please replace it with the up-to-date
configuration
Thu Aug  2 12:28:36 2012 : Debug:       allow_core_dumps = no
Thu Aug  2 12:28:36 2012 : Debug: }
Thu Aug  2 12:28:36 2012 : Debug: including dictionary file
/usr/local/etc/raddb/dictionary
Thu Aug  2 12:28:36 2012 : Debug: main {
Thu Aug  2 12:28:36 2012 : Debug:       name = "radiusd"
Thu Aug  2 12:28:36 2012 : Debug:       prefix = "/usr/local"
Thu Aug  2 12:28:36 2012 : Debug:       localstatedir = "/usr/local/var"
Thu Aug  2 12:28:36 2012 : Debug:       sbindir = "/usr/local/sbin"
Thu Aug  2 12:28:36 2012 : Debug:       logdir = "/usr/local/var/log/radius"
Thu Aug  2 12:28:36 2012 : Debug:       run_dir =
"/usr/local/var/run/radiusd"
Thu Aug  2 12:28:36 2012 : Debug:       libdir =
"/usr/local/lib:/usr/local/lib"
Thu Aug  2 12:28:36 2012 : Debug:       radacctdir =
"/usr/local/var/log/radius/radacct"
Thu Aug  2 12:28:36 2012 : Debug:       hostname_lookups = no
Thu Aug  2 12:28:36 2012 : Debug:       max_request_time = 30
Thu Aug  2 12:28:36 2012 : Debug:       cleanup_delay = 5
Thu Aug  2 12:28:36 2012 : Debug:       max_requests = 1024
Thu Aug  2 12:28:36 2012 : Debug:       pidfile =
"/usr/local/var/run/radiusd/radiusd.pid"
Thu Aug  2 12:28:36 2012 : Debug:       checkrad =
"/usr/local/sbin/checkrad"
Thu Aug  2 12:28:36 2012 : Debug:       debug_level = 0
Thu Aug  2 12:28:36 2012 : Debug:       proxy_requests = yes
Thu Aug  2 12:28:36 2012 : Debug:  log {
Thu Aug  2 12:28:36 2012 : Debug:       stripped_names = no
Thu Aug  2 12:28:36 2012 : Debug:       auth = no
Thu Aug  2 12:28:36 2012 : Debug:       auth_badpass = no
Thu Aug  2 12:28:36 2012 : Debug:       auth_goodpass = no
Thu Aug  2 12:28:36 2012 : Debug:  }
Thu Aug  2 12:28:36 2012 : Debug:  security {
Thu Aug  2 12:28:36 2012 : Debug:       max_attributes = 200
Thu Aug  2 12:28:36 2012 : Debug:       reject_delay = 1
Thu Aug  2 12:28:36 2012 : Debug:       status_server = yes
Thu Aug  2 12:28:36 2012 : Debug:  }
Thu Aug  2 12:28:36 2012 : Debug: }
Thu Aug  2 12:28:36 2012 : Debug: radiusd: #### Loading Realms and Home
Servers ####
Thu Aug  2 12:28:36 2012 : Debug:  proxy server {
Thu Aug  2 12:28:36 2012 : Debug:       retry_delay = 5
Thu Aug  2 12:28:36 2012 : Debug:       retry_count = 3
Thu Aug  2 12:28:36 2012 : Debug:       default_fallback = no
Thu Aug  2 12:28:36 2012 : Debug:       dead_time = 120
Thu Aug  2 12:28:36 2012 : Debug:       wake_all_if_all_dead = no
Thu Aug  2 12:28:36 2012 : Debug:  }
Thu Aug  2 12:28:36 2012 : Debug:  home_server localhost {
Thu Aug  2 12:28:36 2012 : Debug:       ipaddr = 127.0.0.1
Thu Aug  2 12:28:36 2012 : Debug:       port = 1812
Thu Aug  2 12:28:36 2012 : Debug:       type = "auth"
Thu Aug  2 12:28:36 2012 : Debug:       secret = "testing123"
Thu Aug  2 12:28:36 2012 : Debug:       response_window = 20
Thu Aug  2 12:28:36 2012 : Debug:       max_outstanding = 65536
Thu Aug  2 12:28:36 2012 : Debug:       require_message_authenticator = yes
Thu Aug  2 12:28:36 2012 : Debug:       zombie_period = 40
Thu Aug  2 12:28:36 2012 : Debug:       status_check = "status-server"
Thu Aug  2 12:28:36 2012 : Debug:       ping_interval = 30
Thu Aug  2 12:28:36 2012 : Debug:       check_interval = 30
Thu Aug  2 12:28:36 2012 : Debug:       num_answers_to_alive = 3
Thu Aug  2 12:28:36 2012 : Debug:       num_pings_to_alive = 3
Thu Aug  2 12:28:36 2012 : Debug:       revive_interval = 120
Thu Aug  2 12:28:36 2012 : Debug:       status_check_timeout = 4
Thu Aug  2 12:28:36 2012 : Debug:   coa {
Thu Aug  2 12:28:36 2012 : Debug:       irt = 2
Thu Aug  2 12:28:36 2012 : Debug:       mrt = 16
Thu Aug  2 12:28:36 2012 : Debug:       mrc = 5
Thu Aug  2 12:28:36 2012 : Debug:       mrd = 30
Thu Aug  2 12:28:36 2012 : Debug:   }
Thu Aug  2 12:28:36 2012 : Debug:  }
Thu Aug  2 12:28:36 2012 : Debug:  home_server_pool my_auth_failover {
Thu Aug  2 12:28:36 2012 : Debug:       type = fail-over
Thu Aug  2 12:28:36 2012 : Debug:       home_server = localhost
Thu Aug  2 12:28:36 2012 : Debug:  }
Thu Aug  2 12:28:36 2012 : Debug:  realm example.com {
Thu Aug  2 12:28:36 2012 : Debug:       auth_pool = my_auth_failover
Thu Aug  2 12:28:36 2012 : Debug:  }
Thu Aug  2 12:28:36 2012 : Debug:  realm LOCAL {
Thu Aug  2 12:28:36 2012 : Debug:  }
Thu Aug  2 12:28:36 2012 : Debug: radiusd: #### Loading Clients ####
Thu Aug  2 12:28:36 2012 : Debug:  client localhost {
Thu Aug  2 12:28:36 2012 : Debug:       ipaddr = 127.0.0.1
Thu Aug  2 12:28:36 2012 : Debug:       require_message_authenticator = no
Thu Aug  2 12:28:36 2012 : Debug:       secret = "testing123"
Thu Aug  2 12:28:36 2012 : Debug:       nastype = "other"
Thu Aug  2 12:28:36 2012 : Debug:  }
Thu Aug  2 12:28:36 2012 : Debug:  client 1.1.1.23 {
Thu Aug  2 12:28:36 2012 : Debug:       require_message_authenticator = no
Thu Aug  2 12:28:36 2012 : Debug:       secret = "test"
Thu Aug  2 12:28:36 2012 : Debug:       shortname = "RadiusServer"
Thu Aug  2 12:28:36 2012 : Debug:  }
Thu Aug  2 12:28:36 2012 : Debug: radiusd: #### Instantiating modules ####
Thu Aug  2 12:28:36 2012 : Debug:  instantiate {
Thu Aug  2 12:28:36 2012 : Debug:     (Loaded rlm_exec, checking if it's
valid)
Thu Aug  2 12:28:36 2012 : Debug:  Module: Linked to module rlm_exec
Thu Aug  2 12:28:36 2012 : Debug:  Module: Instantiating module "exec" from
file /usr/local/etc/raddb/modules/exec
Thu Aug  2 12:28:36 2012 : Debug:   exec {
Thu Aug  2 12:28:36 2012 : Debug:       wait = no
Thu Aug  2 12:28:36 2012 : Debug:       input_pairs = "request"
Thu Aug  2 12:28:36 2012 : Debug:       shell_escape = yes
Thu Aug  2 12:28:36 2012 : Debug:   }
Thu Aug  2 12:28:36 2012 : Debug:     (Loaded rlm_expr, checking if it's
valid)
Thu Aug  2 12:28:36 2012 : Debug:  Module: Linked to module rlm_expr
Thu Aug  2 12:28:36 2012 : Debug:  Module: Instantiating module "expr" from
file /usr/local/etc/raddb/modules/expr
Thu Aug  2 12:28:36 2012 : Debug:     (Loaded rlm_expiration, checking if
it's valid)
Thu Aug  2 12:28:36 2012 : Debug:  Module: Linked to module rlm_expiration
Thu Aug  2 12:28:36 2012 : Debug:  Module: Instantiating module "expiration"
from file /usr/local/etc/raddb/modules/expiration
Thu Aug  2 12:28:36 2012 : Debug:   expiration {
Thu Aug  2 12:28:36 2012 : Debug:       reply-message = "Password Has
Expired  "
Thu Aug  2 12:28:36 2012 : Debug:   }
Thu Aug  2 12:28:36 2012 : Debug:     (Loaded rlm_logintime, checking if
it's valid)
Thu Aug  2 12:28:36 2012 : Debug:  Module: Linked to module rlm_logintime
Thu Aug  2 12:28:36 2012 : Debug:  Module: Instantiating module "logintime"
from file /usr/local/etc/raddb/modules/logintime
Thu Aug  2 12:28:36 2012 : Debug:   logintime {
Thu Aug  2 12:28:36 2012 : Debug:       reply-message = "You are calling
outside your allowed timespan  "
Thu Aug  2 12:28:36 2012 : Debug:       minimum-timeout = 60
Thu Aug  2 12:28:36 2012 : Debug:   }
Thu Aug  2 12:28:36 2012 : Debug:  }
Thu Aug  2 12:28:36 2012 : Debug: radiusd: #### Loading Virtual Servers ####
Thu Aug  2 12:28:36 2012 : Debug: server { # from file
/usr/local/etc/raddb/radiusd.conf
Thu Aug  2 12:28:36 2012 : Debug:  modules {
Thu Aug  2 12:28:36 2012 : Debug:   Module: Creating Auth-Type = digest
Thu Aug  2 12:28:36 2012 : Debug:  Module: Checking authenticate {...} for
more modules to load
Thu Aug  2 12:28:36 2012 : Debug:     (Loaded rlm_eap, checking if it's
valid)
Thu Aug  2 12:28:36 2012 : Debug:  Module: Linked to module rlm_eap
Thu Aug  2 12:28:36 2012 : Debug:  Module: Instantiating module "eap" from
file /usr/local/etc/raddb/eap.conf
Thu Aug  2 12:28:36 2012 : Debug:   eap {
Thu Aug  2 12:28:36 2012 : Debug:       default_eap_type = "ttls"
Thu Aug  2 12:28:36 2012 : Debug:       timer_expire = 60
Thu Aug  2 12:28:36 2012 : Debug:       ignore_unknown_eap_types = no
Thu Aug  2 12:28:36 2012 : Debug:       cisco_accounting_username_bug = no
Thu Aug  2 12:28:36 2012 : Debug:       max_sessions = 4096
Thu Aug  2 12:28:36 2012 : Debug:   }
Thu Aug  2 12:28:36 2012 : Debug:  Module: Linked to sub-module rlm_eap_tls
Thu Aug  2 12:28:36 2012 : Debug:  Module: Instantiating eap-tls
Thu Aug  2 12:28:36 2012 : Debug:    tls {
Thu Aug  2 12:28:36 2012 : Debug:    }
Thu Aug  2 12:28:36 2012 : Info: debug: 'tls' option missing, trying to use
legacy configuration
Thu Aug  2 12:28:36 2012 : Debug:    tls {
Thu Aug  2 12:28:36 2012 : Debug:       rsa_key_exchange = no
Thu Aug  2 12:28:36 2012 : Debug:       dh_key_exchange = yes
Thu Aug  2 12:28:36 2012 : Debug:       rsa_key_length = 512
Thu Aug  2 12:28:36 2012 : Debug:       dh_key_length = 512
Thu Aug  2 12:28:36 2012 : Debug:       verify_depth = 0
Thu Aug  2 12:28:36 2012 : Debug:       CA_path =
"/usr/local/etc/raddb/certs"
Thu Aug  2 12:28:36 2012 : Debug:       pem_file_type = yes
Thu Aug  2 12:28:36 2012 : Debug:       private_key_file =
"/usr/local/etc/raddb/certs/server.pem"
Thu Aug  2 12:28:36 2012 : Debug:       certificate_file =
"/usr/local/etc/raddb/certs/server.pem"
Thu Aug  2 12:28:36 2012 : Debug:       CA_file =
"/usr/local/etc/raddb/certs/ca.pem"
Thu Aug  2 12:28:36 2012 : Debug:       private_key_password = "whatever"
Thu Aug  2 12:28:36 2012 : Debug:       dh_file =
"/usr/local/etc/raddb/certs/dh"
Thu Aug  2 12:28:36 2012 : Debug:       random_file =
"/usr/local/etc/raddb/certs/random"
Thu Aug  2 12:28:36 2012 : Debug:       fragment_size = 1024
Thu Aug  2 12:28:36 2012 : Debug:       include_length = yes
Thu Aug  2 12:28:36 2012 : Debug:       check_crl = no
Thu Aug  2 12:28:36 2012 : Debug:       cipher_list = "DEFAULT"
Thu Aug  2 12:28:36 2012 : Debug:       make_cert_command =
"/usr/local/etc/raddb/certs/bootstrap"
Thu Aug  2 12:28:36 2012 : Debug:       ecdh_curve = "prime256v1"
Thu Aug  2 12:28:36 2012 : Debug:     cache {
Thu Aug  2 12:28:36 2012 : Debug:       enable = no
Thu Aug  2 12:28:36 2012 : Debug:       lifetime = 24
Thu Aug  2 12:28:36 2012 : Debug:       max_entries = 255
Thu Aug  2 12:28:36 2012 : Debug:     }
Thu Aug  2 12:28:36 2012 : Debug:     verify {
Thu Aug  2 12:28:36 2012 : Debug:     }
Thu Aug  2 12:28:36 2012 : Debug:     ocsp {
Thu Aug  2 12:28:36 2012 : Debug:       enable = no
Thu Aug  2 12:28:36 2012 : Debug:       override_cert_url = yes
Thu Aug  2 12:28:36 2012 : Debug:       url = "http://127.0.0.1/ocsp/"
Thu Aug  2 12:28:36 2012 : Debug:       use_nonce = yes
Thu Aug  2 12:28:36 2012 : Debug:       timeout = 0
Thu Aug  2 12:28:36 2012 : Debug:       softfail = yes
Thu Aug  2 12:28:36 2012 : Debug:     }
Thu Aug  2 12:28:36 2012 : Debug:    }
Thu Aug  2 12:28:36 2012 : Debug:  Module: Linked to sub-module rlm_eap_ttls
Thu Aug  2 12:28:36 2012 : Debug:  Module: Instantiating eap-ttls
Thu Aug  2 12:28:36 2012 : Debug:    ttls {
Thu Aug  2 12:28:36 2012 : Debug:       default_eap_type = "md5"
Thu Aug  2 12:28:36 2012 : Debug:       copy_request_to_tunnel = no
Thu Aug  2 12:28:36 2012 : Debug:       use_tunneled_reply = yes
Thu Aug  2 12:28:36 2012 : Debug:       virtual_server = "inner-tunnel"
Thu Aug  2 12:28:36 2012 : Debug:       include_length = yes
Thu Aug  2 12:28:36 2012 : Debug:    }
Thu Aug  2 12:28:36 2012 : Info: debug: 'tls' option missing, trying to use
legacy configuration
Thu Aug  2 12:28:36 2012 : Debug:  debug: Using cached TLS configuration
from previous invocation
Thu Aug  2 12:28:36 2012 : Debug:  Module: Linked to sub-module
rlm_eap_mschapv2
Thu Aug  2 12:28:36 2012 : Debug:  Module: Instantiating eap-mschapv2
Thu Aug  2 12:28:36 2012 : Debug:    mschapv2 {
Thu Aug  2 12:28:36 2012 : Debug:       with_ntdomain_hack = no
Thu Aug  2 12:28:36 2012 : Debug:       send_error = no
Thu Aug  2 12:28:36 2012 : Debug:    }
Thu Aug  2 12:28:36 2012 : Debug:     (Loaded rlm_pap, checking if it's
valid)
Thu Aug  2 12:28:36 2012 : Debug:  Module: Linked to module rlm_pap
Thu Aug  2 12:28:36 2012 : Debug:  Module: Instantiating module "pap" from
file /usr/local/etc/raddb/modules/pap
Thu Aug  2 12:28:36 2012 : Debug:   pap {
Thu Aug  2 12:28:36 2012 : Debug:       encryption_scheme = "auto"
Thu Aug  2 12:28:36 2012 : Debug:       auto_header = no
Thu Aug  2 12:28:36 2012 : Debug:   }
Thu Aug  2 12:28:36 2012 : Debug:     (Loaded rlm_chap, checking if it's
valid)
Thu Aug  2 12:28:36 2012 : Debug:  Module: Linked to module rlm_chap
Thu Aug  2 12:28:36 2012 : Debug:  Module: Instantiating module "chap" from
file /usr/local/etc/raddb/modules/chap
Thu Aug  2 12:28:36 2012 : Debug:     (Loaded rlm_mschap, checking if it's
valid)
Thu Aug  2 12:28:36 2012 : Debug:  Module: Linked to module rlm_mschap
Thu Aug  2 12:28:36 2012 : Debug:  Module: Instantiating module "mschap"
from file /usr/local/etc/raddb/modules/mschap
Thu Aug  2 12:28:36 2012 : Debug:   mschap {
Thu Aug  2 12:28:36 2012 : Debug:       use_mppe = yes
Thu Aug  2 12:28:36 2012 : Debug:       require_encryption = no
Thu Aug  2 12:28:36 2012 : Debug:       require_strong = no
Thu Aug  2 12:28:36 2012 : Debug:       with_ntdomain_hack = no
Thu Aug  2 12:28:36 2012 : Debug:       allow_retry = yes
Thu Aug  2 12:28:36 2012 : Debug:   }
Thu Aug  2 12:28:36 2012 : Debug:     (Loaded rlm_digest, checking if it's
valid)
Thu Aug  2 12:28:36 2012 : Debug:  Module: Linked to module rlm_digest
Thu Aug  2 12:28:36 2012 : Debug:  Module: Instantiating module "digest"
from file /usr/local/etc/raddb/modules/digest
Thu Aug  2 12:28:36 2012 : Debug:     (Loaded rlm_unix, checking if it's
valid)
Thu Aug  2 12:28:36 2012 : Debug:  Module: Linked to module rlm_unix
Thu Aug  2 12:28:36 2012 : Debug:  Module: Instantiating module "unix" from
file /usr/local/etc/raddb/modules/unix
Thu Aug  2 12:28:36 2012 : Debug:   unix {
Thu Aug  2 12:28:36 2012 : Debug:       radwtmp =
"/usr/local/var/log/radius/radwtmp"
Thu Aug  2 12:28:36 2012 : Debug:   }
Thu Aug  2 12:28:36 2012 : Debug:  Module: Checking authorize {...} for more
modules to load
Thu Aug  2 12:28:36 2012 : Debug:     (Loaded rlm_preprocess, checking if
it's valid)
Thu Aug  2 12:28:36 2012 : Debug:  Module: Linked to module rlm_preprocess
Thu Aug  2 12:28:36 2012 : Debug:  Module: Instantiating module "preprocess"
from file /usr/local/etc/raddb/modules/preprocess
Thu Aug  2 12:28:36 2012 : Debug:   preprocess {
Thu Aug  2 12:28:36 2012 : Debug:       huntgroups =
"/usr/local/etc/raddb/huntgroups"
Thu Aug  2 12:28:36 2012 : Debug:       hints = "/usr/local/etc/raddb/hints"
Thu Aug  2 12:28:36 2012 : Debug:       with_ascend_hack = no
Thu Aug  2 12:28:36 2012 : Debug:       ascend_channels_per_line = 23
Thu Aug  2 12:28:36 2012 : Debug:       with_ntdomain_hack = no
Thu Aug  2 12:28:36 2012 : Debug:       with_specialix_jetstream_hack = no
Thu Aug  2 12:28:36 2012 : Debug:       with_cisco_vsa_hack = no
Thu Aug  2 12:28:36 2012 : Debug:       with_alvarion_vsa_hack = no
Thu Aug  2 12:28:36 2012 : Debug:   }
Thu Aug  2 12:28:36 2012 : Debug:     (Loaded rlm_realm, checking if it's
valid)
Thu Aug  2 12:28:36 2012 : Debug:  Module: Linked to module rlm_realm
Thu Aug  2 12:28:36 2012 : Debug:  Module: Instantiating module "suffix"
from file /usr/local/etc/raddb/modules/realm
Thu Aug  2 12:28:36 2012 : Debug:   realm suffix {
Thu Aug  2 12:28:36 2012 : Debug:       format = "suffix"
Thu Aug  2 12:28:36 2012 : Debug:       delimiter = "@"
Thu Aug  2 12:28:36 2012 : Debug:       ignore_default = no
Thu Aug  2 12:28:36 2012 : Debug:       ignore_null = no
Thu Aug  2 12:28:36 2012 : Debug:   }
Thu Aug  2 12:28:36 2012 : Debug:     (Loaded rlm_files, checking if it's
valid)
Thu Aug  2 12:28:36 2012 : Debug:  Module: Linked to module rlm_files
Thu Aug  2 12:28:36 2012 : Debug:  Module: Instantiating module "files" from
file /usr/local/etc/raddb/modules/files
Thu Aug  2 12:28:36 2012 : Debug:   files {
Thu Aug  2 12:28:36 2012 : Debug:       usersfile =
"/usr/local/etc/raddb/users"
Thu Aug  2 12:28:36 2012 : Debug:       acctusersfile =
"/usr/local/etc/raddb/acct_users"
Thu Aug  2 12:28:36 2012 : Debug:       preproxy_usersfile =
"/usr/local/etc/raddb/preproxy_users"
Thu Aug  2 12:28:36 2012 : Debug:       compat = "no"
Thu Aug  2 12:28:36 2012 : Debug:   }
Thu Aug  2 12:28:36 2012 : Debug:  Module: Checking preacct {...} for more
modules to load
Thu Aug  2 12:28:36 2012 : Debug:     (Loaded rlm_acct_unique, checking if
it's valid)
Thu Aug  2 12:28:36 2012 : Debug:  Module: Linked to module rlm_acct_unique
Thu Aug  2 12:28:36 2012 : Debug:  Module: Instantiating module
"acct_unique" from file /usr/local/etc/raddb/modules/acct_unique
Thu Aug  2 12:28:36 2012 : Debug:   acct_unique {
Thu Aug  2 12:28:36 2012 : Debug:       key = "User-Name, Acct-Session-Id,
NAS-IP-Address, Client-IP-Address, NAS-Port"
Thu Aug  2 12:28:36 2012 : Debug:   }
Thu Aug  2 12:28:36 2012 : Debug:  Module: Checking accounting {...} for
more modules to load
Thu Aug  2 12:28:36 2012 : Debug:     (Loaded rlm_detail, checking if it's
valid)
Thu Aug  2 12:28:36 2012 : Debug:  Module: Linked to module rlm_detail
Thu Aug  2 12:28:36 2012 : Debug:  Module: Instantiating module "detail"
from file /usr/local/etc/raddb/modules/detail
Thu Aug  2 12:28:36 2012 : Debug:   detail {
Thu Aug  2 12:28:36 2012 : Debug:       detailfile =
"/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-
IPv6-Address}}/detail-%Y%m%d"
Thu Aug  2 12:28:36 2012 : Debug:       header = "%t"
Thu Aug  2 12:28:36 2012 : Debug:       detailperm = 384
Thu Aug  2 12:28:36 2012 : Debug:       dirperm = 493
Thu Aug  2 12:28:36 2012 : Debug:       locking = no
Thu Aug  2 12:28:36 2012 : Debug:       log_packet_header = no
Thu Aug  2 12:28:36 2012 : Debug:   }
Thu Aug  2 12:28:36 2012 : Debug:     (Loaded rlm_radutmp, checking if it's
valid)
Thu Aug  2 12:28:36 2012 : Debug:  Module: Linked to module rlm_radutmp
Thu Aug  2 12:28:36 2012 : Debug:  Module: Instantiating module "radutmp"
from file /usr/local/etc/raddb/modules/radutmp
Thu Aug  2 12:28:36 2012 : Debug:   radutmp {
Thu Aug  2 12:28:36 2012 : Debug:       filename =
"/usr/local/var/log/radius/radutmp"
Thu Aug  2 12:28:36 2012 : Debug:       username = "%{User-Name}"
Thu Aug  2 12:28:36 2012 : Debug:       case_sensitive = yes
Thu Aug  2 12:28:36 2012 : Debug:       check_with_nas = yes
Thu Aug  2 12:28:36 2012 : Debug:       perm = 384
Thu Aug  2 12:28:36 2012 : Debug:       callerid = yes
Thu Aug  2 12:28:36 2012 : Debug:   }
Thu Aug  2 12:28:36 2012 : Debug:     (Loaded rlm_attr_filter, checking if
it's valid)
Thu Aug  2 12:28:36 2012 : Debug:  Module: Linked to module rlm_attr_filter
Thu Aug  2 12:28:36 2012 : Debug:  Module: Instantiating module
"attr_filter.accounting_response" from file
/usr/local/etc/raddb/modules/attr_filter
Thu Aug  2 12:28:36 2012 : Debug:   attr_filter
attr_filter.accounting_response {
Thu Aug  2 12:28:36 2012 : Debug:       attrsfile =
"/usr/local/etc/raddb/attrs.accounting_response"
Thu Aug  2 12:28:36 2012 : Debug:       key = "%{User-Name}"
Thu Aug  2 12:28:36 2012 : Debug:       relaxed = no
Thu Aug  2 12:28:36 2012 : Debug:   }
Thu Aug  2 12:28:36 2012 : Debug:  Module: Checking session {...} for more
modules to load
Thu Aug  2 12:28:36 2012 : Debug:  Module: Checking post-proxy {...} for
more modules to load
Thu Aug  2 12:28:36 2012 : Debug:  Module: Checking post-auth {...} for more
modules to load
Thu Aug  2 12:28:36 2012 : Debug:  Module: Instantiating module
"attr_filter.access_reject" from file
/usr/local/etc/raddb/modules/attr_filter
Thu Aug  2 12:28:36 2012 : Debug:   attr_filter attr_filter.access_reject {
Thu Aug  2 12:28:36 2012 : Debug:       attrsfile =
"/usr/local/etc/raddb/attrs.access_reject"
Thu Aug  2 12:28:36 2012 : Debug:       key = "%{User-Name}"
Thu Aug  2 12:28:36 2012 : Debug:       relaxed = no
Thu Aug  2 12:28:36 2012 : Debug:   }
Thu Aug  2 12:28:36 2012 : Debug:  } # modules
Thu Aug  2 12:28:36 2012 : Debug: } # server
Thu Aug  2 12:28:36 2012 : Debug: server inner-tunnel { # from file
/usr/local/etc/raddb/sites-enabled/inner-tunnel
Thu Aug  2 12:28:36 2012 : Debug:  modules {
Thu Aug  2 12:28:36 2012 : Debug:  Module: Checking authenticate {...} for
more modules to load
Thu Aug  2 12:28:36 2012 : Debug:  Module: Checking authorize {...} for more
modules to load
Thu Aug  2 12:28:36 2012 : Debug:  Module: Checking session {...} for more
modules to load
Thu Aug  2 12:28:36 2012 : Debug:  Module: Checking post-proxy {...} for
more modules to load
Thu Aug  2 12:28:36 2012 : Debug:  Module: Checking post-auth {...} for more
modules to load
Thu Aug  2 12:28:36 2012 : Debug:     (Loaded rlm_wimax, checking if it's
valid)
Thu Aug  2 12:28:36 2012 : Debug:  Module: Linked to module rlm_wimax
Thu Aug  2 12:28:36 2012 : Debug:  Module: Instantiating module "wimax" from
file /usr/local/etc/raddb/modules/wimax
Thu Aug  2 12:28:36 2012 : Debug:   wimax {
Thu Aug  2 12:28:36 2012 : Debug:       delete_mppe_keys = no
Thu Aug  2 12:28:36 2012 : Debug:   }
Thu Aug  2 12:28:36 2012 : Debug:  } # modules
Thu Aug  2 12:28:36 2012 : Debug: } # server
Thu Aug  2 12:28:36 2012 : Debug: radiusd: #### Opening IP addresses and
Ports ####
Thu Aug  2 12:28:36 2012 : Debug: listen {
Thu Aug  2 12:28:36 2012 : Debug:       type = "auth"
Thu Aug  2 12:28:36 2012 : Debug:       ipaddr = *
Thu Aug  2 12:28:36 2012 : Debug:       port = 0
Thu Aug  2 12:28:36 2012 : Debug:       max_pps = 0
Thu Aug  2 12:28:36 2012 : Debug: }
Thu Aug  2 12:28:36 2012 : Debug: listen {
Thu Aug  2 12:28:36 2012 : Debug:       type = "acct"
Thu Aug  2 12:28:36 2012 : Debug:       ipaddr = *
Thu Aug  2 12:28:36 2012 : Debug:       port = 0
Thu Aug  2 12:28:36 2012 : Debug:       max_pps = 0
Thu Aug  2 12:28:36 2012 : Debug: }
Thu Aug  2 12:28:36 2012 : Debug: listen {
Thu Aug  2 12:28:36 2012 : Debug:       type = "control"
Thu Aug  2 12:28:36 2012 : Debug:  listen {
Thu Aug  2 12:28:36 2012 : Debug:       socket =
"/usr/local/var/run/radiusd/radiusd.sock"
Thu Aug  2 12:28:36 2012 : Debug:  }
Thu Aug  2 12:28:36 2012 : Debug: }
Thu Aug  2 12:28:36 2012 : Debug: listen {
Thu Aug  2 12:28:36 2012 : Debug:       type = "auth"
Thu Aug  2 12:28:36 2012 : Debug:       ipaddr = 127.0.0.1
Thu Aug  2 12:28:36 2012 : Debug:       port = 18120
Thu Aug  2 12:28:36 2012 : Debug:       max_pps = 0
Thu Aug  2 12:28:36 2012 : Debug: }
Thu Aug  2 12:28:36 2012 : Debug: Listening on authentication address * port
1812
Thu Aug  2 12:28:36 2012 : Debug: Listening on accounting address * port
1813
Thu Aug  2 12:28:36 2012 : Debug: Listening on command file
/usr/local/var/run/radiusd/radiusd.sock
Thu Aug  2 12:28:36 2012 : Debug: Listening on authentication address
127.0.0.1 port 18120 as server inner-tunnel
Thu Aug  2 12:28:36 2012 : Debug: Opening new proxy address * port 1814
Thu Aug  2 12:28:36 2012 : Debug: Listening on proxy address * port 1814
Thu Aug  2 12:28:36 2012 : Debug: No trigger subsection: ignoring trigger
server.start
Thu Aug  2 12:28:36 2012 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 1.1.1.23 port 49154, id=171,
length=181
  Code:         1
  Id:           171
  Length:       181
  Vector:       5a2da5bf874c5a6058e5d3712a536f1a
  Data:         01  1e  4b 65 65 70 41 6c 69 76 65 55 73 65 72 4e 61 6d
                        65 41 6e 64 50 61 73 73 77 6f 72 64
                04  06  01 01 01 17
                3d  06  00 00 00 1b
                05  06  00 00 00 00
                1f  08  00 00 00 00 00 00
                20  14  30 30 31 30 30 31 30 30 31 30 30 30 30 33 32 30
                        30 30
                1a  0d  000060b5 (24757)  03 07 00 00 00 00 00
                50  12  0c 76 2e 2d d3 c7 1e c5 c4 01 6e af ac bd 4f d0
                2c  14  4b 65 65 70 41 6c 69 76 65 53 65 73 73 69 6f 6e
                        49 64
                02  22  f0 77 59 ff 2e 5c 61 15 8b 95 24 ec b5 51 60 75
                        3f 60 bd 90 60 01 80 e0 3d 82 d7 3d c2 b8 64 3f
        User-Name = "KeepAliveUserNameAndPassword"
        NAS-IP-Address = 1.1.1.23
        NAS-Port-Type = Wireless-802.16
        NAS-Port = 0
        Calling-Station-Id = "\000\000\000\000\000"
        NAS-Identifier = "001001001000032000"
        WiMAX-GMT-Timezone-offset = 0
        Message-Authenticator = 0x0c762e2dd3c71ec5c4016eafacbd4fd0
        Acct-Session-Id = "KeepAliveSessionId"
        User-Password = "KeepAliveUserNameAndPassword"
Thu Aug  2 12:28:59 2012 : Info: (0) # Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
Thu Aug  2 12:28:59 2012 : Info: (0)   group authorize {
Thu Aug  2 12:28:59 2012 : Info: (0)  - entering group authorize {...}
Thu Aug  2 12:28:59 2012 : Info: (0)   [preprocess] = ok
Thu Aug  2 12:28:59 2012 : Info: (0) eap : No EAP-Message, not doing EAP
Thu Aug  2 12:28:59 2012 : Info: (0)   [eap] = noop
Thu Aug  2 12:28:59 2012 : Info: (0)   [chap] = noop
Thu Aug  2 12:28:59 2012 : Info: (0)   [mschap] = noop
Thu Aug  2 12:28:59 2012 : Info: (0)   [digest] = noop
Thu Aug  2 12:28:59 2012 : Info: (0) suffix : No '@' in User-Name =
"KeepAliveUserNameAndPassword", looking up realm NULL
Thu Aug  2 12:28:59 2012 : Info: (0) suffix : No such realm "NULL"
Thu Aug  2 12:28:59 2012 : Info: (0)   [suffix] = noop
Thu Aug  2 12:28:59 2012 : Info: (0) eap : No EAP-Message, not doing EAP
Thu Aug  2 12:28:59 2012 : Info: (0)   [eap] = noop
Thu Aug  2 12:28:59 2012 : Info: (0)   [files] = noop
Thu Aug  2 12:28:59 2012 : Info: (0)   [expiration] = noop
Thu Aug  2 12:28:59 2012 : Info: (0)   [logintime] = noop
Thu Aug  2 12:28:59 2012 : Info: (0) pap : WARNING! No "known good" password
found for the user.  Authentication may fail because of this.
Thu Aug  2 12:28:59 2012 : Info: (0)   [pap] = noop
Thu Aug  2 12:28:59 2012 : Info: (0) ERROR: No authenticate method
(Auth-Type) found for the request: Rejecting the user
Thu Aug  2 12:28:59 2012 : Info: (0) Failed to authenticate the user.
Thu Aug  2 12:28:59 2012 : Info: (0) Using Post-Auth-Type Reject
Thu Aug  2 12:28:59 2012 : Info: (0) # Executing group from file
/usr/local/etc/raddb/sites-enabled/default
Thu Aug  2 12:28:59 2012 : Info: (0)   group REJECT {
Thu Aug  2 12:28:59 2012 : Info: (0)  - entering group REJECT {...}
Thu Aug  2 12:28:59 2012 : Info: (0) attr_filter.access_reject :
expand: %{User-Name} -> KeepAliveUserNameAndPassword
Thu Aug  2 12:28:59 2012 : Info: (0) attr_filter.access_reject : Matched
entry DEFAULT at line 11
Thu Aug  2 12:28:59 2012 : Info: (0)   [attr_filter.access_reject] = updated
Thu Aug  2 12:28:59 2012 : Info: (0) Finished request 0.
Thu Aug  2 12:28:59 2012 : Debug: Waking up in 0.3 seconds.
Thu Aug  2 12:28:59 2012 : Debug: Waking up in 0.6 seconds.
Thu Aug  2 12:29:00 2012 : Info: (0) Sending delayed reject
Sending Access-Reject of id 171 to 1.1.1.23 port 49154
  Code:         3
  Id:           171
  Length:       20
  Vector:       4e76ef4ee3b98653d02ba15da31dc6d1
Thu Aug  2 12:29:00 2012 : Debug: Waking up in 4.9 seconds.
Thu Aug  2 12:29:05 2012 : Info: (0) Cleaning up request packet ID 171 with
timestamp +23
Thu Aug  2 12:29:05 2012 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 1.1.1.23 port 49154, id=172,
length=258
  Code:         1
  Id:           172
  Length:       258
  Vector:       494b492dae5e07a5dd0cfd3d4e94ae7f
  Data:         01  32  7b 61 6d 3d 31 7d 37 32 65 39 39 32 39 33 34 33
                        63 66 66 65 61 39 33 66 33 38 62 33 63 30 32 38
                        30 62 34 61 38 31 40 57 69 4d 61 78 2e 63 6f 6d
                04  06  01 01 01 17
                3d  06  00 00 00 1b
                05  06  00 00 00 01
                1f  08  00 10 e7 61 0e 46
                20  14  30 30 31 30 30 31 30 30 31 30 30 30 30 33 32 30
                        30 30
                1a  0d  000060b5 (24757)  03 07 00 00 00 00 00
                0c  06  00 00 05 d2
                06  06  00 00 00 02
                1a  11  000060b5 (24757)  01 0b 00 01 05 31 2e 30 02 03 01
                1a  1b  000060b5 (24757)  2e 15 00 30 30 31 30 30 31 30 30
31 30 30 30 30
                        33 32 30 30 30
                4f  37  02 01 00 35 01 7b 61 6d 3d 31 7d 37 32 65 39 39
                        32 39 33 34 33 63 66 66 65 61 39 33 66 33 38 62
                        33 63 30 32 38 30 62 34 61 38 31 40 57 69 4d 61
                        78 2e 63 6f 6d
                50  12  e4 94 d6 6b 0e 8e 9b 7f 5a 24 50 b6 12 b5 31 5b
        User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com"
        NAS-IP-Address = 1.1.1.23
        NAS-Port-Type = Wireless-802.16
        NAS-Port = 1
        Calling-Station-Id = "\000\020\347a\016F"
        NAS-Identifier = "001001001000032000"
        WiMAX-GMT-Timezone-offset = 0
        Framed-MTU = 1490
        Service-Type = Framed-User
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-BS-Id = 0x303031303031303031303030303332303030
        EAP-Message =
0x02010035017b616d3d317d3732653939323933343363666665613933663338623363303238
3062346138314057694d61782e636f6d
        Message-Authenticator = 0xe494d66b0e8e9b7f5a2450b612b5315b
Thu Aug  2 12:29:16 2012 : Info: (1) # Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
Thu Aug  2 12:29:16 2012 : Info: (1)   group authorize {
Thu Aug  2 12:29:16 2012 : Info: (1)  - entering group authorize {...}
Thu Aug  2 12:29:16 2012 : Info: (1)   [preprocess] = ok
Thu Aug  2 12:29:16 2012 : Info: (1) eap : EAP packet type response id 1
length 53
Thu Aug  2 12:29:16 2012 : Info: (1) eap : EAP-Identity reply, returning
'ok' so we can short-circuit the rest of authorize
Thu Aug  2 12:29:16 2012 : Info: (1)   [eap] = ok
Thu Aug  2 12:29:16 2012 : Info: (1)   [chap] = noop
Thu Aug  2 12:29:16 2012 : Info: (1)   [mschap] = noop
Thu Aug  2 12:29:16 2012 : Info: (1)   [digest] = noop
Thu Aug  2 12:29:16 2012 : Info: (1) suffix : Looking up realm "WiMax.com"
for User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com"
Thu Aug  2 12:29:16 2012 : Info: (1) suffix : No such realm "WiMax.com"
Thu Aug  2 12:29:16 2012 : Info: (1)   [suffix] = noop
Thu Aug  2 12:29:16 2012 : Info: (1) eap : EAP packet type response id 1
length 53
Thu Aug  2 12:29:16 2012 : Info: (1) eap : EAP-Identity reply, returning
'ok' so we can short-circuit the rest of authorize
Thu Aug  2 12:29:16 2012 : Info: (1)   [eap] = ok
Thu Aug  2 12:29:16 2012 : Info: (1) Found Auth-Type = EAP
Thu Aug  2 12:29:16 2012 : Info: (1) Found Auth-Type = EAP
Thu Aug  2 12:29:16 2012 : Error: (1) Warning:  Found 2 auth-types on
request for user '{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com'
Thu Aug  2 12:29:16 2012 : Info: (1) # Executing group from file
/usr/local/etc/raddb/sites-enabled/default
Thu Aug  2 12:29:16 2012 : Info: (1)   group authenticate {
Thu Aug  2 12:29:16 2012 : Info: (1)  - entering group authenticate {...}
Thu Aug  2 12:29:16 2012 : Info: (1) eap : EAP Identity
Thu Aug  2 12:29:16 2012 : Info: (1) eap : processing type ttls
Thu Aug  2 12:29:16 2012 : Info: (1) ttls : Initiate
Thu Aug  2 12:29:16 2012 : Info: (1) ttls : Start returned 1
Thu Aug  2 12:29:16 2012 : Info: (1)   [eap] = handled
Sending Access-Challenge of id 172 to 1.1.1.23 port 49154
        EAP-Message = 0x010200061520
                4f 08  01 02 00 06 15 20
        Message-Authenticator = 0x00000000000000000000000000000000
                50 12 ...
        State = 0x70e4843670e691af7954d6edd228f499
                18 12  70 e4 84 36 70 e6 91 af 79 54 d6 ed d2 28 f4 99
  Code:         11
  Id:           172
  Length:       64
  Vector:       f7c21b63bc52e2d2dc556561df03df96
  Data:         4f  08  01 02 00 06 15 20
                50  12  17 45 52 de 5d 0e fe d8 51 54 2b 21 80 c6 61 3c
                18  12  70 e4 84 36 70 e6 91 af 79 54 d6 ed d2 28 f4 99
Thu Aug  2 12:29:16 2012 : Info: (1) Finished request 1.
Thu Aug  2 12:29:16 2012 : Debug: Waking up in 0.3 seconds.
rad_recv: Access-Request packet from host 1.1.1.23 port 49154, id=173,
length=285
  Code:         1
  Id:           173
  Length:       285
  Vector:       6f6f3cf16e46f0891c1ea4402a89a17c
  Data:         01  32  7b 61 6d 3d 31 7d 37 32 65 39 39 32 39 33 34 33
                        63 66 66 65 61 39 33 66 33 38 62 33 63 30 32 38
                        30 62 34 61 38 31 40 57 69 4d 61 78 2e 63 6f 6d
                04  06  01 01 01 17
                3d  06  00 00 00 1b
                05  06  00 00 00 01
                1f  08  00 10 e7 61 0e 46
                20  14  30 30 31 30 30 31 30 30 31 30 30 30 30 33 32 30
                        30 30
                1a  0d  000060b5 (24757)  03 07 00 00 00 00 00
                0c  06  00 00 05 d2
                06  06  00 00 00 02
                18  12  70 e4 84 36 70 e6 91 af 79 54 d6 ed d2 28 f4 99
                1a  11  000060b5 (24757)  01 0b 00 01 05 31 2e 30 02 03 01
                1a  1b  000060b5 (24757)  2e 15 00 30 30 31 30 30 31 30 30
31 30 30 30 30
                        33 32 30 30 30
                4f  40  02 02 00 3e 15 00 16 03 01 00 33 01 00 00 2f 03
                        01 00 00 01 15 6d c0 ed 3c 1f 1a 26 c1 d4 ac f7
                        d6 49 a5 2c a5 5e 51 36 61 8a 47 71 5a fc 3a 11
                        b2 00 00 08 00 2f 00 0a 00 05 00 04 01 00
                50  12  b9 23 7b 86 d0 bf 80 f4 47 72 7b fd fb bb 09 4a
        User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com"
        NAS-IP-Address = 1.1.1.23
        NAS-Port-Type = Wireless-802.16
        NAS-Port = 1
        Calling-Station-Id = "\000\020\347a\016F"
        NAS-Identifier = "001001001000032000"
        WiMAX-GMT-Timezone-offset = 0
        Framed-MTU = 1490
        Service-Type = Framed-User
        State = 0x70e4843670e691af7954d6edd228f499
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-BS-Id = 0x303031303031303031303030303332303030
        EAP-Message =
0x0202003e150016030100330100002f0301000001156dc0ed3c1f1a26c1d4acf7d649a52ca5
5e5136618a47715afc3a11b2000008002f000a000500040100
        Message-Authenticator = 0xb9237b86d0bf80f447727bfdfbbb094a
Thu Aug  2 12:29:17 2012 : Info: (2) # Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
Thu Aug  2 12:29:17 2012 : Info: (2)   group authorize {
Thu Aug  2 12:29:17 2012 : Info: (2)  - entering group authorize {...}
Thu Aug  2 12:29:17 2012 : Info: (2)   [preprocess] = ok
Thu Aug  2 12:29:17 2012 : Info: (2) eap : EAP packet type response id 2
length 62
Thu Aug  2 12:29:17 2012 : Info: (2) eap : Continuing tunnel setup.
Thu Aug  2 12:29:17 2012 : Info: (2)   [eap] = ok
Thu Aug  2 12:29:17 2012 : Info: (2)   [chap] = noop
Thu Aug  2 12:29:17 2012 : Info: (2)   [mschap] = noop
Thu Aug  2 12:29:17 2012 : Info: (2)   [digest] = noop
Thu Aug  2 12:29:17 2012 : Info: (2) suffix : Looking up realm "WiMax.com"
for User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com"
Thu Aug  2 12:29:17 2012 : Info: (2) suffix : No such realm "WiMax.com"
Thu Aug  2 12:29:17 2012 : Info: (2)   [suffix] = noop
Thu Aug  2 12:29:17 2012 : Info: (2) eap : EAP packet type response id 2
length 62
Thu Aug  2 12:29:17 2012 : Info: (2) eap : Continuing tunnel setup.
Thu Aug  2 12:29:17 2012 : Info: (2)   [eap] = ok
Thu Aug  2 12:29:17 2012 : Info: (2) Found Auth-Type = EAP
Thu Aug  2 12:29:17 2012 : Info: (2) Found Auth-Type = EAP
Thu Aug  2 12:29:17 2012 : Error: (2) Warning:  Found 2 auth-types on
request for user '{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com'
Thu Aug  2 12:29:17 2012 : Info: (2) # Executing group from file
/usr/local/etc/raddb/sites-enabled/default
Thu Aug  2 12:29:17 2012 : Info: (2)   group authenticate {
Thu Aug  2 12:29:17 2012 : Info: (2)  - entering group authenticate {...}
Thu Aug  2 12:29:17 2012 : Info: (2) eap : Request found, released from the
list
Thu Aug  2 12:29:17 2012 : Info: (2) eap : EAP/ttls
Thu Aug  2 12:29:17 2012 : Info: (2) eap : processing type ttls
Thu Aug  2 12:29:17 2012 : Info: (2) ttls : Authenticate
Thu Aug  2 12:29:17 2012 : Info: (2) ttls : processing EAP-TLS
Thu Aug  2 12:29:17 2012 : Info: (2) ttls : eaptls_verify returned 7
Thu Aug  2 12:29:17 2012 : Info: (2) ttls : Done initial handshake
Thu Aug  2 12:29:17 2012 : Info: (2) ttls :     (other): before/accept
initialization
Thu Aug  2 12:29:17 2012 : Info: (2) ttls :     TLS_accept: before/accept
initialization
Thu Aug  2 12:29:17 2012 : Info: (2) ttls : <<< TLS 1.0 Handshake [length
0033], ClientHello
Thu Aug  2 12:29:17 2012 : Info: (2) ttls :     TLS_accept: SSLv3 read
client hello A
Thu Aug  2 12:29:17 2012 : Info: (2) ttls : >>> TLS 1.0 Handshake [length
002a], ServerHello
Thu Aug  2 12:29:17 2012 : Info: (2) ttls :     TLS_accept: SSLv3 write
server hello A
Thu Aug  2 12:29:17 2012 : Info: (2) ttls : >>> TLS 1.0 Handshake [length
085e], Certificate
Thu Aug  2 12:29:17 2012 : Info: (2) ttls :     TLS_accept: SSLv3 write
certificate A
Thu Aug  2 12:29:17 2012 : Info: (2) ttls : >>> TLS 1.0 Handshake [length
0004], ServerHelloDone
Thu Aug  2 12:29:17 2012 : Info: (2) ttls :     TLS_accept: SSLv3 write
server done A
Thu Aug  2 12:29:17 2012 : Info: (2) ttls :     TLS_accept: SSLv3 flush data
Thu Aug  2 12:29:17 2012 : Info: (2) ttls :     TLS_accept: Need to read
more data: SSLv3 read client certificate A
Thu Aug  2 12:29:17 2012 : Debug: In SSL Handshake Phase
Thu Aug  2 12:29:17 2012 : Debug: In SSL Accept mode
Thu Aug  2 12:29:17 2012 : Info: (2) ttls : eaptls_process returned 13
Thu Aug  2 12:29:17 2012 : Info: (2)   [eap] = handled
Sending Access-Challenge of id 173 to 1.1.1.23 port 49154
        EAP-Message =
0x010303f615c00000089b160301002a020000260301501aaaddbe1c6131fd8d227e7b6a571a
9f6033b1ead17f1ec7e5d5bf828a052d00002f00160301085e0b00085a0008570003a6308203
a23082028aa003020102020101300d06092a864886f70d0101040500308193310b3009060355
040613024652310f300d060355040813065261646975733112301006035504071309536f6d65
776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886
f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d457861
6d706c6520436572746966696361746520417574686f72697479
                4f ff  01 03 03 f6 15 c0 00 00 08 9b 16 03 01 00 2a 02
                        00 00 26 03 01 50 1a aa dd be 1c 61 31 fd 8d 22
                        7e 7b 6a 57 1a 9f 60 33 b1 ea d1 7f 1e c7 e5 d5
                        bf 82 8a 05 2d 00 00 2f 00 16 03 01 08 5e 0b 00
                        08 5a 00 08 57 00 03 a6 30 82 03 a2 30 82 02 8a
                        a0 03 02 01 02 02 01 01 30 0d 06 09 2a 86 48 86
                        f7 0d 01 01 04 05 00 30 81 93 31 0b 30 09 06 03
                        55 04 06 13 02 46 52 31 0f 30 0d 06 03 55 04 08
                        13 06 52 61 64 69 75 73 31 12 30 10 06 03 55 04
                        07 13 09 53 6f 6d 65 77 68 65 72 65 31 15 30 13
                        06 03 55 04 0a 13 0c 45 78 61 6d 70 6c 65 20 49
                        6e 63 2e 31 20 30 1e 06 09 2a 86 48 86 f7 0d 01
                        09 01 16 11 61 64 6d 69 6e 40 65 78 61 6d 70 6c
                        65 2e 63 6f 6d 31 26 30 24 06 03 55 04 03 13 1d
                        45 78 61 6d 70 6c 65 20 43 65 72 74 69 66 69 63
                        61 74 65 20 41 75 74 68 6f 72 69 74 79
        EAP-Message =
0x301e170d3132303830313230323230385a170d3133303830313230323230385a307c310b30
09060355040613024652310f300d0603550408130652616469757331153013060355040a130c
4578616d706c6520496e632e312330210603550403131a4578616d706c652053657276657220
43657274696669636174653120301e06092a864886f70d010901161161646d696e406578616d
706c652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a028201
0100de0bf920a502100daec1e015143e02a445842403aa8e7cdcf1a4a80687f770e9ddc5e424
2d0bf7e59c85bfa3b6ae9c0c0ec038a8db5f990352281e855f16
                4f ff  30 1e 17 0d 31 32 30 38 30 31 32 30 32 32 30 38
                        5a 17 0d 31 33 30 38 30 31 32 30 32 32 30 38 5a
                        30 7c 31 0b 30 09 06 03 55 04 06 13 02 46 52 31
                        0f 30 0d 06 03 55 04 08 13 06 52 61 64 69 75 73
                        31 15 30 13 06 03 55 04 0a 13 0c 45 78 61 6d 70
                        6c 65 20 49 6e 63 2e 31 23 30 21 06 03 55 04 03
                        13 1a 45 78 61 6d 70 6c 65 20 53 65 72 76 65 72
                        20 43 65 72 74 69 66 69 63 61 74 65 31 20 30 1e
                        06 09 2a 86 48 86 f7 0d 01 09 01 16 11 61 64 6d
                        69 6e 40 65 78 61 6d 70 6c 65 2e 63 6f 6d 30 82
                        01 22 30 0d 06 09 2a 86 48 86 f7 0d 01 01 01 05
                        00 03 82 01 0f 00 30 82 01 0a 02 82 01 01 00 de
                        0b f9 20 a5 02 10 0d ae c1 e0 15 14 3e 02 a4 45
                        84 24 03 aa 8e 7c dc f1 a4 a8 06 87 f7 70 e9 dd
                        c5 e4 24 2d 0b f7 e5 9c 85 bf a3 b6 ae 9c 0c 0e
                        c0 38 a8 db 5f 99 03 52 28 1e 85 5f 16
        EAP-Message =
0x01589cdf68659ee0166aa92a64f5a8779e3f301007668b0d1e0490054b7979dc6ccef24e11
4fa9554e2908d7919d3f92d41dda67fe63fc1a789349b6ef7b0012939e6f36815750dcb6668d
9e4f3eca7fdc978517c0fd5edba70aab9564e4705d8cf28594b62c7e6809b8e88f39781c0348
8d08c536c7b6ddb538cc62920c9b5d975a79dfd361efc550161719d97ed3c4daf98fb67eed7e
914e956d125a6ec7bf02dfd112863d026c3b74ec84ff506e57586e8a4f821616514f6aec29c9
62593ab9510203010001a317301530130603551d25040c300a06082b06010505070301300d06
092a864886f70d0101040500038201010007b6a418336f5c5482
                4f ff  01 58 9c df 68 65 9e e0 16 6a a9 2a 64 f5 a8 77
                        9e 3f 30 10 07 66 8b 0d 1e 04 90 05 4b 79 79 dc
                        6c ce f2 4e 11 4f a9 55 4e 29 08 d7 91 9d 3f 92
                        d4 1d da 67 fe 63 fc 1a 78 93 49 b6 ef 7b 00 12
                        93 9e 6f 36 81 57 50 dc b6 66 8d 9e 4f 3e ca 7f
                        dc 97 85 17 c0 fd 5e db a7 0a ab 95 64 e4 70 5d
                        8c f2 85 94 b6 2c 7e 68 09 b8 e8 8f 39 78 1c 03
                        48 8d 08 c5 36 c7 b6 dd b5 38 cc 62 92 0c 9b 5d
                        97 5a 79 df d3 61 ef c5 50 16 17 19 d9 7e d3 c4
                        da f9 8f b6 7e ed 7e 91 4e 95 6d 12 5a 6e c7 bf
                        02 df d1 12 86 3d 02 6c 3b 74 ec 84 ff 50 6e 57
                        58 6e 8a 4f 82 16 16 51 4f 6a ec 29 c9 62 59 3a
                        b9 51 02 03 01 00 01 a3 17 30 15 30 13 06 03 55
                        1d 25 04 0c 30 0a 06 08 2b 06 01 05 05 07 03 01
                        30 0d 06 09 2a 86 48 86 f7 0d 01 01 04 05 00 03
                        82 01 01 00 07 b6 a4 18 33 6f 5c 54 82
        EAP-Message =
0xf6266fe22bca35d6b7564ab695480fa8b837c81ada436935ac4ba28fb57fcc2cb007aeb8ec
14ab7373fa4a37b3c2c5f1dafc2b76332935d35af145caf72d952dd9d37e41377d467a376cb3
c8763cff128f98b0fbfc51f6ee919371bdcd4b4d3629d59e4ae6755ca9c63e6d15b480cbb58a
b15ef3666572ab45b926cee83d3db9a5cbfdd2c5bfcbeb5227fcff493b324c83da3288df7705
ded4e9fe144fcab708fa3852071320c803323585fb7a86c2062f7ad64bc23bc692c6a4197058
1833a0f342dcd91c97ce878610ea59ab34863f55f8d835dea77c3b2d5962a1672fc233c2eac7
7a58fa624dcc12ec38fc8f343233fbfdf24789750004ab308204
                4f ff  f6 26 6f e2 2b ca 35 d6 b7 56 4a b6 95 48 0f a8
                        b8 37 c8 1a da 43 69 35 ac 4b a2 8f b5 7f cc 2c
                        b0 07 ae b8 ec 14 ab 73 73 fa 4a 37 b3 c2 c5 f1
                        da fc 2b 76 33 29 35 d3 5a f1 45 ca f7 2d 95 2d
                        d9 d3 7e 41 37 7d 46 7a 37 6c b3 c8 76 3c ff 12
                        8f 98 b0 fb fc 51 f6 ee 91 93 71 bd cd 4b 4d 36
                        29 d5 9e 4a e6 75 5c a9 c6 3e 6d 15 b4 80 cb b5
                        8a b1 5e f3 66 65 72 ab 45 b9 26 ce e8 3d 3d b9
                        a5 cb fd d2 c5 bf cb eb 52 27 fc ff 49 3b 32 4c
                        83 da 32 88 df 77 05 de d4 e9 fe 14 4f ca b7 08
                        fa 38 52 07 13 20 c8 03 32 35 85 fb 7a 86 c2 06
                        2f 7a d6 4b c2 3b c6 92 c6 a4 19 70 58 18 33 a0
                        f3 42 dc d9 1c 97 ce 87 86 10 ea 59 ab 34 86 3f
                        55 f8 d8 35 de a7 7c 3b 2d 59 62 a1 67 2f c2 33
                        c2 ea c7 7a 58 fa 62 4d cc 12 ec 38 fc 8f 34 32
                        33 fb fd f2 47 89 75 00 04 ab 30 82 04
        EAP-Message = 0xa730
                4f 04  a7 30
        Message-Authenticator = 0x00000000000000000000000000000000
                50 12 ...
        State = 0x70e4843671e791af7954d6edd228f499
                18 12  70 e4 84 36 71 e7 91 af 79 54 d6 ed d2 28 f4 99
  Code:         11
  Id:           173
  Length:       1080
  Vector:       faccd8f2a1be3142843b1f6d47a36e2d
  Data:         4f  ff  01 03 03 f6 15 c0 00 00 08 9b 16 03 01 00 2a 02
                        00 00 26 03 01 50 1a aa dd be 1c 61 31 fd 8d 22
                        7e 7b 6a 57 1a 9f 60 33 b1 ea d1 7f 1e c7 e5 d5
                        bf 82 8a 05 2d 00 00 2f 00 16 03 01 08 5e 0b 00
                        08 5a 00 08 57 00 03 a6 30 82 03 a2 30 82 02 8a
                        a0 03 02 01 02 02 01 01 30 0d 06 09 2a 86 48 86
                        f7 0d 01 01 04 05 00 30 81 93 31 0b 30 09 06 03
                        55 04 06 13 02 46 52 31 0f 30 0d 06 03 55 04 08
                        13 06 52 61 64 69 75 73 31 12 30 10 06 03 55 04
                        07 13 09 53 6f 6d 65 77 68 65 72 65 31 15 30 13
                        06 03 55 04 0a 13 0c 45 78 61 6d 70 6c 65 20 49
                        6e 63 2e 31 20 30 1e 06 09 2a 86 48 86 f7 0d 01
                        09 01 16 11 61 64 6d 69 6e 40 65 78 61 6d 70 6c
                        65 2e 63 6f 6d 31 26 30 24 06 03 55 04 03 13 1d
                        45 78 61 6d 70 6c 65 20 43 65 72 74 69 66 69 63
                        61 74 65 20 41 75 74 68 6f 72 69 74 79
                4f  ff  30 1e 17 0d 31 32 30 38 30 31 32 30 32 32 30 38
                        5a 17 0d 31 33 30 38 30 31 32 30 32 32 30 38 5a
                        30 7c 31 0b 30 09 06 03 55 04 06 13 02 46 52 31
                        0f 30 0d 06 03 55 04 08 13 06 52 61 64 69 75 73
                        31 15 30 13 06 03 55 04 0a 13 0c 45 78 61 6d 70
                        6c 65 20 49 6e 63 2e 31 23 30 21 06 03 55 04 03
                        13 1a 45 78 61 6d 70 6c 65 20 53 65 72 76 65 72
                        20 43 65 72 74 69 66 69 63 61 74 65 31 20 30 1e
                        06 09 2a 86 48 86 f7 0d 01 09 01 16 11 61 64 6d
                        69 6e 40 65 78 61 6d 70 6c 65 2e 63 6f 6d 30 82
                        01 22 30 0d 06 09 2a 86 48 86 f7 0d 01 01 01 05
                        00 03 82 01 0f 00 30 82 01 0a 02 82 01 01 00 de
                        0b f9 20 a5 02 10 0d ae c1 e0 15 14 3e 02 a4 45
                        84 24 03 aa 8e 7c dc f1 a4 a8 06 87 f7 70 e9 dd
                        c5 e4 24 2d 0b f7 e5 9c 85 bf a3 b6 ae 9c 0c 0e
                        c0 38 a8 db 5f 99 03 52 28 1e 85 5f 16
                4f  ff  01 58 9c df 68 65 9e e0 16 6a a9 2a 64 f5 a8 77
                        9e 3f 30 10 07 66 8b 0d 1e 04 90 05 4b 79 79 dc
                        6c ce f2 4e 11 4f a9 55 4e 29 08 d7 91 9d 3f 92
                        d4 1d da 67 fe 63 fc 1a 78 93 49 b6 ef 7b 00 12
                        93 9e 6f 36 81 57 50 dc b6 66 8d 9e 4f 3e ca 7f
                        dc 97 85 17 c0 fd 5e db a7 0a ab 95 64 e4 70 5d
                        8c f2 85 94 b6 2c 7e 68 09 b8 e8 8f 39 78 1c 03
                        48 8d 08 c5 36 c7 b6 dd b5 38 cc 62 92 0c 9b 5d
                        97 5a 79 df d3 61 ef c5 50 16 17 19 d9 7e d3 c4
                        da f9 8f b6 7e ed 7e 91 4e 95 6d 12 5a 6e c7 bf
                        02 df d1 12 86 3d 02 6c 3b 74 ec 84 ff 50 6e 57
                        58 6e 8a 4f 82 16 16 51 4f 6a ec 29 c9 62 59 3a
                        b9 51 02 03 01 00 01 a3 17 30 15 30 13 06 03 55
                        1d 25 04 0c 30 0a 06 08 2b 06 01 05 05 07 03 01
                        30 0d 06 09 2a 86 48 86 f7 0d 01 01 04 05 00 03
                        82 01 01 00 07 b6 a4 18 33 6f 5c 54 82
                4f  ff  f6 26 6f e2 2b ca 35 d6 b7 56 4a b6 95 48 0f a8
                        b8 37 c8 1a da 43 69 35 ac 4b a2 8f b5 7f cc 2c
                        b0 07 ae b8 ec 14 ab 73 73 fa 4a 37 b3 c2 c5 f1
                        da fc 2b 76 33 29 35 d3 5a f1 45 ca f7 2d 95 2d
                        d9 d3 7e 41 37 7d 46 7a 37 6c b3 c8 76 3c ff 12
                        8f 98 b0 fb fc 51 f6 ee 91 93 71 bd cd 4b 4d 36
                        29 d5 9e 4a e6 75 5c a9 c6 3e 6d 15 b4 80 cb b5
                        8a b1 5e f3 66 65 72 ab 45 b9 26 ce e8 3d 3d b9
                        a5 cb fd d2 c5 bf cb eb 52 27 fc ff 49 3b 32 4c
                        83 da 32 88 df 77 05 de d4 e9 fe 14 4f ca b7 08
                        fa 38 52 07 13 20 c8 03 32 35 85 fb 7a 86 c2 06
                        2f 7a d6 4b c2 3b c6 92 c6 a4 19 70 58 18 33 a0
                        f3 42 dc d9 1c 97 ce 87 86 10 ea 59 ab 34 86 3f
                        55 f8 d8 35 de a7 7c 3b 2d 59 62 a1 67 2f c2 33
                        c2 ea c7 7a 58 fa 62 4d cc 12 ec 38 fc 8f 34 32
                        33 fb fd f2 47 89 75 00 04 ab 30 82 04
                4f  04  a7 30
                50  12  ce b9 f2 7b 61 8f 83 ce 3f 78 31 0a 03 02 23 e9
                18  12  70 e4 84 36 71 e7 91 af 79 54 d6 ed d2 28 f4 99
Thu Aug  2 12:29:17 2012 : Info: (2) Finished request 2.
Thu Aug  2 12:29:17 2012 : Debug: Waking up in 0.1 seconds.
Thu Aug  2 12:29:17 2012 : Debug: Waking up in 0.1 seconds.
rad_recv: Access-Request packet from host 1.1.1.23 port 49154, id=174,
length=229
  Code:         1
  Id:           174
  Length:       229
  Vector:       596f86dcff924f82458193daf60083c2
  Data:         01  32  7b 61 6d 3d 31 7d 37 32 65 39 39 32 39 33 34 33
                        63 66 66 65 61 39 33 66 33 38 62 33 63 30 32 38
                        30 62 34 61 38 31 40 57 69 4d 61 78 2e 63 6f 6d
                04  06  01 01 01 17
                3d  06  00 00 00 1b
                05  06  00 00 00 01
                1f  08  00 10 e7 61 0e 46
                20  14  30 30 31 30 30 31 30 30 31 30 30 30 30 33 32 30
                        30 30
                1a  0d  000060b5 (24757)  03 07 00 00 00 00 00
                0c  06  00 00 05 d2
                06  06  00 00 00 02
                18  12  70 e4 84 36 71 e7 91 af 79 54 d6 ed d2 28 f4 99
                1a  11  000060b5 (24757)  01 0b 00 01 05 31 2e 30 02 03 01
                1a  1b  000060b5 (24757)  2e 15 00 30 30 31 30 30 31 30 30
31 30 30 30 30
                        33 32 30 30 30
                4f  08  02 03 00 06 15 00
                50  12  ff 32 50 8e 14 a8 86 1f 81 62 12 8c c8 95 8a 51
        User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com"
        NAS-IP-Address = 1.1.1.23
        NAS-Port-Type = Wireless-802.16
        NAS-Port = 1
        Calling-Station-Id = "\000\020\347a\016F"
        NAS-Identifier = "001001001000032000"
        WiMAX-GMT-Timezone-offset = 0
        Framed-MTU = 1490
        Service-Type = Framed-User
        State = 0x70e4843671e791af7954d6edd228f499
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-BS-Id = 0x303031303031303031303030303332303030
        EAP-Message = 0x020300061500
        Message-Authenticator = 0xff32508e14a8861f8162128cc8958a51
Thu Aug  2 12:29:17 2012 : Info: (3) # Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
Thu Aug  2 12:29:17 2012 : Info: (3)   group authorize {
Thu Aug  2 12:29:17 2012 : Info: (3)  - entering group authorize {...}
Thu Aug  2 12:29:17 2012 : Info: (3)   [preprocess] = ok
Thu Aug  2 12:29:17 2012 : Info: (3) eap : EAP packet type response id 3
length 6
Thu Aug  2 12:29:17 2012 : Info: (3) eap : Continuing tunnel setup.
Thu Aug  2 12:29:17 2012 : Info: (3)   [eap] = ok
Thu Aug  2 12:29:17 2012 : Info: (3)   [chap] = noop
Thu Aug  2 12:29:17 2012 : Info: (3)   [mschap] = noop
Thu Aug  2 12:29:17 2012 : Info: (3)   [digest] = noop
Thu Aug  2 12:29:17 2012 : Info: (3) suffix : Looking up realm "WiMax.com"
for User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com"
Thu Aug  2 12:29:17 2012 : Info: (3) suffix : No such realm "WiMax.com"
Thu Aug  2 12:29:17 2012 : Info: (3)   [suffix] = noop
Thu Aug  2 12:29:17 2012 : Info: (3) eap : EAP packet type response id 3
length 6
Thu Aug  2 12:29:17 2012 : Info: (3) eap : Continuing tunnel setup.
Thu Aug  2 12:29:17 2012 : Info: (3)   [eap] = ok
Thu Aug  2 12:29:17 2012 : Info: (3) Found Auth-Type = EAP
Thu Aug  2 12:29:17 2012 : Info: (3) Found Auth-Type = EAP
Thu Aug  2 12:29:17 2012 : Error: (3) Warning:  Found 2 auth-types on
request for user '{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com'
Thu Aug  2 12:29:17 2012 : Info: (3) # Executing group from file
/usr/local/etc/raddb/sites-enabled/default
Thu Aug  2 12:29:17 2012 : Info: (3)   group authenticate {
Thu Aug  2 12:29:17 2012 : Info: (3)  - entering group authenticate {...}
Thu Aug  2 12:29:17 2012 : Info: (3) eap : Request found, released from the
list
Thu Aug  2 12:29:17 2012 : Info: (3) eap : EAP/ttls
Thu Aug  2 12:29:17 2012 : Info: (3) eap : processing type ttls
Thu Aug  2 12:29:17 2012 : Info: (3) ttls : Authenticate
Thu Aug  2 12:29:17 2012 : Info: (3) ttls : processing EAP-TLS
Thu Aug  2 12:29:17 2012 : Info: (3) ttls : Received TLS ACK
Thu Aug  2 12:29:17 2012 : Info: (3) ttls : Received TLS ACK
Thu Aug  2 12:29:17 2012 : Info: (3) ttls : ACK handshake fragment handler
Thu Aug  2 12:29:17 2012 : Info: (3) ttls : eaptls_verify returned 1
Thu Aug  2 12:29:17 2012 : Info: (3) ttls : eaptls_process returned 13
Thu Aug  2 12:29:17 2012 : Info: (3)   [eap] = handled
Sending Access-Challenge of id 174 to 1.1.1.23 port 49154
        EAP-Message =
0x010403f615c00000089b82038fa0030201020209008b3ae4d24b0d8074300d06092a864886
f70d0101050500308193310b3009060355040613024652310f300d0603550408130652616469
75733112301006035504071309536f6d65776865726531153013060355040a130c4578616d70
6c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e
636f6d312630240603550403131d4578616d706c652043657274696669636174652041757468
6f72697479301e170d3132303830313230323230385a170d3133303830313230323230385a30
8193310b3009060355040613024652310f300d06035504081306
                4f ff  01 04 03 f6 15 c0 00 00 08 9b 82 03 8f a0 03 02
                        01 02 02 09 00 8b 3a e4 d2 4b 0d 80 74 30 0d 06
                        09 2a 86 48 86 f7 0d 01 01 05 05 00 30 81 93 31
                        0b 30 09 06 03 55 04 06 13 02 46 52 31 0f 30 0d
                        06 03 55 04 08 13 06 52 61 64 69 75 73 31 12 30
                        10 06 03 55 04 07 13 09 53 6f 6d 65 77 68 65 72
                        65 31 15 30 13 06 03 55 04 0a 13 0c 45 78 61 6d
                        70 6c 65 20 49 6e 63 2e 31 20 30 1e 06 09 2a 86
                        48 86 f7 0d 01 09 01 16 11 61 64 6d 69 6e 40 65
                        78 61 6d 70 6c 65 2e 63 6f 6d 31 26 30 24 06 03
                        55 04 03 13 1d 45 78 61 6d 70 6c 65 20 43 65 72
                        74 69 66 69 63 61 74 65 20 41 75 74 68 6f 72 69
                        74 79 30 1e 17 0d 31 32 30 38 30 31 32 30 32 32
                        30 38 5a 17 0d 31 33 30 38 30 31 32 30 32 32 30
                        38 5a 30 81 93 31 0b 30 09 06 03 55 04 06 13 02
                        46 52 31 0f 30 0d 06 03 55 04 08 13 06
        EAP-Message =
0x5261646975733112301006035504071309536f6d65776865726531153013060355040a130c
4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e40657861
6d706c652e636f6d312630240603550403131d4578616d706c65204365727469666963617465
20417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a
0282010100c36abc7f1f7fab4f42bccc205eda320e1aac97851162a59ff4a233bd684d6c898a
8de8b1977a54cebd25142c5231b85b9abf4dda8802f68e9ca90578ded2717a7119f5c380e09c
eff603a2c3aaa7defdc7a2a81f1de5d542377274df33c057e680
                4f ff  52 61 64 69 75 73 31 12 30 10 06 03 55 04 07 13
                        09 53 6f 6d 65 77 68 65 72 65 31 15 30 13 06 03
                        55 04 0a 13 0c 45 78 61 6d 70 6c 65 20 49 6e 63
                        2e 31 20 30 1e 06 09 2a 86 48 86 f7 0d 01 09 01
                        16 11 61 64 6d 69 6e 40 65 78 61 6d 70 6c 65 2e
                        63 6f 6d 31 26 30 24 06 03 55 04 03 13 1d 45 78
                        61 6d 70 6c 65 20 43 65 72 74 69 66 69 63 61 74
                        65 20 41 75 74 68 6f 72 69 74 79 30 82 01 22 30
                        0d 06 09 2a 86 48 86 f7 0d 01 01 01 05 00 03 82
                        01 0f 00 30 82 01 0a 02 82 01 01 00 c3 6a bc 7f
                        1f 7f ab 4f 42 bc cc 20 5e da 32 0e 1a ac 97 85
                        11 62 a5 9f f4 a2 33 bd 68 4d 6c 89 8a 8d e8 b1
                        97 7a 54 ce bd 25 14 2c 52 31 b8 5b 9a bf 4d da
                        88 02 f6 8e 9c a9 05 78 de d2 71 7a 71 19 f5 c3
                        80 e0 9c ef f6 03 a2 c3 aa a7 de fd c7 a2 a8 1f
                        1d e5 d5 42 37 72 74 df 33 c0 57 e6 80
        EAP-Message =
0x5c8c7753a3df62de87c009399a7751c1ffae25ae1bf357835db0ceeae188a093ea0249293d
dc62a620666e64cf3d6f53fc51bba0f73bea03496cd0113555b1d87f05837f8ce1067e4f936e
6e4b025fb4ab50e23462b003e94984d2910781fd566c77348e4f48fa15a4ca7c8e24f2228e56
d6a55d64c94d9181d30a823e5aa88b26d29b4f6500aacdba4791c98f34a968275d8dcaaeaf87
bd0f14f7411774350203010001a381fb3081f8301d0603551d0e0416041435b8ba9717c526ff
332deed9f3736708c70d27d43081c80603551d230481c03081bd801435b8ba9717c526ff332d
eed9f3736708c70d27d4a18199a48196308193310b3009060355
                4f ff  5c 8c 77 53 a3 df 62 de 87 c0 09 39 9a 77 51 c1
                        ff ae 25 ae 1b f3 57 83 5d b0 ce ea e1 88 a0 93
                        ea 02 49 29 3d dc 62 a6 20 66 6e 64 cf 3d 6f 53
                        fc 51 bb a0 f7 3b ea 03 49 6c d0 11 35 55 b1 d8
                        7f 05 83 7f 8c e1 06 7e 4f 93 6e 6e 4b 02 5f b4
                        ab 50 e2 34 62 b0 03 e9 49 84 d2 91 07 81 fd 56
                        6c 77 34 8e 4f 48 fa 15 a4 ca 7c 8e 24 f2 22 8e
                        56 d6 a5 5d 64 c9 4d 91 81 d3 0a 82 3e 5a a8 8b
                        26 d2 9b 4f 65 00 aa cd ba 47 91 c9 8f 34 a9 68
                        27 5d 8d ca ae af 87 bd 0f 14 f7 41 17 74 35 02
                        03 01 00 01 a3 81 fb 30 81 f8 30 1d 06 03 55 1d
                        0e 04 16 04 14 35 b8 ba 97 17 c5 26 ff 33 2d ee
                        d9 f3 73 67 08 c7 0d 27 d4 30 81 c8 06 03 55 1d
                        23 04 81 c0 30 81 bd 80 14 35 b8 ba 97 17 c5 26
                        ff 33 2d ee d9 f3 73 67 08 c7 0d 27 d4 a1 81 99
                        a4 81 96 30 81 93 31 0b 30 09 06 03 55
        EAP-Message =
0x040613024652310f300d060355040813065261646975733112301006035504071309536f6d
65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a8648
86f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578
616d706c6520436572746966696361746520417574686f726974798209008b3ae4d24b0d8074
300c0603551d13040530030101ff300d06092a864886f70d010105050003820101006d4d67c0
893fe75e0ebd115e29d05dc12ffc3999cbb4ffaf025190077c68cfc7a7ec9cca671cf4534106
6957c347aa5cb3943fc2c46439989b290a76ff2559ba5e0a7b1c
                4f ff  04 06 13 02 46 52 31 0f 30 0d 06 03 55 04 08 13
                        06 52 61 64 69 75 73 31 12 30 10 06 03 55 04 07
                        13 09 53 6f 6d 65 77 68 65 72 65 31 15 30 13 06
                        03 55 04 0a 13 0c 45 78 61 6d 70 6c 65 20 49 6e
                        63 2e 31 20 30 1e 06 09 2a 86 48 86 f7 0d 01 09
                        01 16 11 61 64 6d 69 6e 40 65 78 61 6d 70 6c 65
                        2e 63 6f 6d 31 26 30 24 06 03 55 04 03 13 1d 45
                        78 61 6d 70 6c 65 20 43 65 72 74 69 66 69 63 61
                        74 65 20 41 75 74 68 6f 72 69 74 79 82 09 00 8b
                        3a e4 d2 4b 0d 80 74 30 0c 06 03 55 1d 13 04 05
                        30 03 01 01 ff 30 0d 06 09 2a 86 48 86 f7 0d 01
                        01 05 05 00 03 82 01 01 00 6d 4d 67 c0 89 3f e7
                        5e 0e bd 11 5e 29 d0 5d c1 2f fc 39 99 cb b4 ff
                        af 02 51 90 07 7c 68 cf c7 a7 ec 9c ca 67 1c f4
                        53 41 06 69 57 c3 47 aa 5c b3 94 3f c2 c4 64 39
                        98 9b 29 0a 76 ff 25 59 ba 5e 0a 7b 1c
        EAP-Message = 0xe142
                4f 04  e1 42
        Message-Authenticator = 0x00000000000000000000000000000000
                50 12 ...
        State = 0x70e4843672e091af7954d6edd228f499
                18 12  70 e4 84 36 72 e0 91 af 79 54 d6 ed d2 28 f4 99
  Code:         11
  Id:           174
  Length:       1080
  Vector:       2d1d93905ba1e947b6eb8e1e53da285a
  Data:         4f  ff  01 04 03 f6 15 c0 00 00 08 9b 82 03 8f a0 03 02
                        01 02 02 09 00 8b 3a e4 d2 4b 0d 80 74 30 0d 06
                        09 2a 86 48 86 f7 0d 01 01 05 05 00 30 81 93 31
                        0b 30 09 06 03 55 04 06 13 02 46 52 31 0f 30 0d
                        06 03 55 04 08 13 06 52 61 64 69 75 73 31 12 30
                        10 06 03 55 04 07 13 09 53 6f 6d 65 77 68 65 72
                        65 31 15 30 13 06 03 55 04 0a 13 0c 45 78 61 6d
                        70 6c 65 20 49 6e 63 2e 31 20 30 1e 06 09 2a 86
                        48 86 f7 0d 01 09 01 16 11 61 64 6d 69 6e 40 65
                        78 61 6d 70 6c 65 2e 63 6f 6d 31 26 30 24 06 03
                        55 04 03 13 1d 45 78 61 6d 70 6c 65 20 43 65 72
                        74 69 66 69 63 61 74 65 20 41 75 74 68 6f 72 69
                        74 79 30 1e 17 0d 31 32 30 38 30 31 32 30 32 32
                        30 38 5a 17 0d 31 33 30 38 30 31 32 30 32 32 30
                        38 5a 30 81 93 31 0b 30 09 06 03 55 04 06 13 02
                        46 52 31 0f 30 0d 06 03 55 04 08 13 06
                4f  ff  52 61 64 69 75 73 31 12 30 10 06 03 55 04 07 13
                        09 53 6f 6d 65 77 68 65 72 65 31 15 30 13 06 03
                        55 04 0a 13 0c 45 78 61 6d 70 6c 65 20 49 6e 63
                        2e 31 20 30 1e 06 09 2a 86 48 86 f7 0d 01 09 01
                        16 11 61 64 6d 69 6e 40 65 78 61 6d 70 6c 65 2e
                        63 6f 6d 31 26 30 24 06 03 55 04 03 13 1d 45 78
                        61 6d 70 6c 65 20 43 65 72 74 69 66 69 63 61 74
                        65 20 41 75 74 68 6f 72 69 74 79 30 82 01 22 30
                        0d 06 09 2a 86 48 86 f7 0d 01 01 01 05 00 03 82
                        01 0f 00 30 82 01 0a 02 82 01 01 00 c3 6a bc 7f
                        1f 7f ab 4f 42 bc cc 20 5e da 32 0e 1a ac 97 85
                        11 62 a5 9f f4 a2 33 bd 68 4d 6c 89 8a 8d e8 b1
                        97 7a 54 ce bd 25 14 2c 52 31 b8 5b 9a bf 4d da
                        88 02 f6 8e 9c a9 05 78 de d2 71 7a 71 19 f5 c3
                        80 e0 9c ef f6 03 a2 c3 aa a7 de fd c7 a2 a8 1f
                        1d e5 d5 42 37 72 74 df 33 c0 57 e6 80
                4f  ff  5c 8c 77 53 a3 df 62 de 87 c0 09 39 9a 77 51 c1
                        ff ae 25 ae 1b f3 57 83 5d b0 ce ea e1 88 a0 93
                        ea 02 49 29 3d dc 62 a6 20 66 6e 64 cf 3d 6f 53
                        fc 51 bb a0 f7 3b ea 03 49 6c d0 11 35 55 b1 d8
                        7f 05 83 7f 8c e1 06 7e 4f 93 6e 6e 4b 02 5f b4
                        ab 50 e2 34 62 b0 03 e9 49 84 d2 91 07 81 fd 56
                        6c 77 34 8e 4f 48 fa 15 a4 ca 7c 8e 24 f2 22 8e
                        56 d6 a5 5d 64 c9 4d 91 81 d3 0a 82 3e 5a a8 8b
                        26 d2 9b 4f 65 00 aa cd ba 47 91 c9 8f 34 a9 68
                        27 5d 8d ca ae af 87 bd 0f 14 f7 41 17 74 35 02
                        03 01 00 01 a3 81 fb 30 81 f8 30 1d 06 03 55 1d
                        0e 04 16 04 14 35 b8 ba 97 17 c5 26 ff 33 2d ee
                        d9 f3 73 67 08 c7 0d 27 d4 30 81 c8 06 03 55 1d
                        23 04 81 c0 30 81 bd 80 14 35 b8 ba 97 17 c5 26
                        ff 33 2d ee d9 f3 73 67 08 c7 0d 27 d4 a1 81 99
                        a4 81 96 30 81 93 31 0b 30 09 06 03 55
                4f  ff  04 06 13 02 46 52 31 0f 30 0d 06 03 55 04 08 13
                        06 52 61 64 69 75 73 31 12 30 10 06 03 55 04 07
                        13 09 53 6f 6d 65 77 68 65 72 65 31 15 30 13 06
                        03 55 04 0a 13 0c 45 78 61 6d 70 6c 65 20 49 6e
                        63 2e 31 20 30 1e 06 09 2a 86 48 86 f7 0d 01 09
                        01 16 11 61 64 6d 69 6e 40 65 78 61 6d 70 6c 65
                        2e 63 6f 6d 31 26 30 24 06 03 55 04 03 13 1d 45
                        78 61 6d 70 6c 65 20 43 65 72 74 69 66 69 63 61
                        74 65 20 41 75 74 68 6f 72 69 74 79 82 09 00 8b
                        3a e4 d2 4b 0d 80 74 30 0c 06 03 55 1d 13 04 05
                        30 03 01 01 ff 30 0d 06 09 2a 86 48 86 f7 0d 01
                        01 05 05 00 03 82 01 01 00 6d 4d 67 c0 89 3f e7
                        5e 0e bd 11 5e 29 d0 5d c1 2f fc 39 99 cb b4 ff
                        af 02 51 90 07 7c 68 cf c7 a7 ec 9c ca 67 1c f4
                        53 41 06 69 57 c3 47 aa 5c b3 94 3f c2 c4 64 39
                        98 9b 29 0a 76 ff 25 59 ba 5e 0a 7b 1c
                4f  04  e1 42
                50  12  df b5 f1 bd 7a 51 d4 a5 d3 58 be 77 ac 02 b0 17
                18  12  70 e4 84 36 72 e0 91 af 79 54 d6 ed d2 28 f4 99
Thu Aug  2 12:29:17 2012 : Info: (3) Finished request 3.
Thu Aug  2 12:29:17 2012 : Debug: Waking up in 0.1 seconds.
Thu Aug  2 12:29:17 2012 : Debug: Waking up in 0.1 seconds.
rad_recv: Access-Request packet from host 1.1.1.23 port 49154, id=175,
length=229
  Code:         1
  Id:           175
  Length:       229
  Vector:       f0f4171ca8b272d64760ccee915518e7
  Data:         01  32  7b 61 6d 3d 31 7d 37 32 65 39 39 32 39 33 34 33
                        63 66 66 65 61 39 33 66 33 38 62 33 63 30 32 38
                        30 62 34 61 38 31 40 57 69 4d 61 78 2e 63 6f 6d
                04  06  01 01 01 17
                3d  06  00 00 00 1b
                05  06  00 00 00 01
                1f  08  00 10 e7 61 0e 46
                20  14  30 30 31 30 30 31 30 30 31 30 30 30 30 33 32 30
                        30 30
                1a  0d  000060b5 (24757)  03 07 00 00 00 00 00
                0c  06  00 00 05 d2
                06  06  00 00 00 02
                18  12  70 e4 84 36 72 e0 91 af 79 54 d6 ed d2 28 f4 99
                1a  11  000060b5 (24757)  01 0b 00 01 05 31 2e 30 02 03 01
                1a  1b  000060b5 (24757)  2e 15 00 30 30 31 30 30 31 30 30
31 30 30 30 30
                        33 32 30 30 30
                4f  08  02 04 00 06 15 00
                50  12  b1 c1 2f 42 50 e8 69 88 bf 90 f7 39 75 d6 ec 16
        User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com"
        NAS-IP-Address = 1.1.1.23
        NAS-Port-Type = Wireless-802.16
        NAS-Port = 1
        Calling-Station-Id = "\000\020\347a\016F"
        NAS-Identifier = "001001001000032000"
        WiMAX-GMT-Timezone-offset = 0
        Framed-MTU = 1490
        Service-Type = Framed-User
        State = 0x70e4843672e091af7954d6edd228f499
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-BS-Id = 0x303031303031303031303030303332303030
        EAP-Message = 0x020400061500
        Message-Authenticator = 0xb1c12f4250e86988bf90f73975d6ec16
Thu Aug  2 12:29:17 2012 : Info: (4) # Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
Thu Aug  2 12:29:17 2012 : Info: (4)   group authorize {
Thu Aug  2 12:29:17 2012 : Info: (4)  - entering group authorize {...}
Thu Aug  2 12:29:17 2012 : Info: (4)   [preprocess] = ok
Thu Aug  2 12:29:17 2012 : Info: (4) eap : EAP packet type response id 4
length 6
Thu Aug  2 12:29:17 2012 : Info: (4) eap : Continuing tunnel setup.
Thu Aug  2 12:29:17 2012 : Info: (4)   [eap] = ok
Thu Aug  2 12:29:17 2012 : Info: (4)   [chap] = noop
Thu Aug  2 12:29:17 2012 : Info: (4)   [mschap] = noop
Thu Aug  2 12:29:17 2012 : Info: (4)   [digest] = noop
Thu Aug  2 12:29:17 2012 : Info: (4) suffix : Looking up realm "WiMax.com"
for User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com"
Thu Aug  2 12:29:17 2012 : Info: (4) suffix : No such realm "WiMax.com"
Thu Aug  2 12:29:17 2012 : Info: (4)   [suffix] = noop
Thu Aug  2 12:29:17 2012 : Info: (4) eap : EAP packet type response id 4
length 6
Thu Aug  2 12:29:17 2012 : Info: (4) eap : Continuing tunnel setup.
Thu Aug  2 12:29:17 2012 : Info: (4)   [eap] = ok
Thu Aug  2 12:29:17 2012 : Info: (4) Found Auth-Type = EAP
Thu Aug  2 12:29:17 2012 : Info: (4) Found Auth-Type = EAP
Thu Aug  2 12:29:17 2012 : Error: (4) Warning:  Found 2 auth-types on
request for user '{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com'
Thu Aug  2 12:29:17 2012 : Info: (4) # Executing group from file
/usr/local/etc/raddb/sites-enabled/default
Thu Aug  2 12:29:17 2012 : Info: (4)   group authenticate {
Thu Aug  2 12:29:17 2012 : Info: (4)  - entering group authenticate {...}
Thu Aug  2 12:29:17 2012 : Info: (4) eap : Request found, released from the
list
Thu Aug  2 12:29:17 2012 : Info: (4) eap : EAP/ttls
Thu Aug  2 12:29:17 2012 : Info: (4) eap : processing type ttls
Thu Aug  2 12:29:17 2012 : Info: (4) ttls : Authenticate
Thu Aug  2 12:29:17 2012 : Info: (4) ttls : processing EAP-TLS
Thu Aug  2 12:29:17 2012 : Info: (4) ttls : Received TLS ACK
Thu Aug  2 12:29:17 2012 : Info: (4) ttls : Received TLS ACK
Thu Aug  2 12:29:17 2012 : Info: (4) ttls : ACK handshake fragment handler
Thu Aug  2 12:29:17 2012 : Info: (4) ttls : eaptls_verify returned 1
Thu Aug  2 12:29:17 2012 : Info: (4) ttls : eaptls_process returned 13
Thu Aug  2 12:29:17 2012 : Info: (4)   [eap] = handled
Sending Access-Challenge of id 175 to 1.1.1.23 port 49154
        EAP-Message =
0x010500cd15800000089b8e2c29c529afee1893f22707e590467c7f212dc4857e1d83de9431
23f37fb0bcbde5cbc2724a695917e090cbce71bba8bba9c3d0559cfc0d5c8c94c00d9ab8389a
1885a38e4bb9f8763f86919c4ec24822384416b628838022578c034341be186092afabaaf40e
fb44d8f6f3b07e7b1a8743c5535d4b0e3b35d32d32d0caaae6d978ed996884fb92a0c84f0960
f32e79d8fc531918e8fe7988e3064cdafb741d03a2e2aecd10bc62552d6f1a0b1871567a1101
99f574aa4ebfe316030100040e000000
                4f cf  01 05 00 cd 15 80 00 00 08 9b 8e 2c 29 c5 29 af
                        ee 18 93 f2 27 07 e5 90 46 7c 7f 21 2d c4 85 7e
                        1d 83 de 94 31 23 f3 7f b0 bc bd e5 cb c2 72 4a
                        69 59 17 e0 90 cb ce 71 bb a8 bb a9 c3 d0 55 9c
                        fc 0d 5c 8c 94 c0 0d 9a b8 38 9a 18 85 a3 8e 4b
                        b9 f8 76 3f 86 91 9c 4e c2 48 22 38 44 16 b6 28
                        83 80 22 57 8c 03 43 41 be 18 60 92 af ab aa f4
                        0e fb 44 d8 f6 f3 b0 7e 7b 1a 87 43 c5 53 5d 4b
                        0e 3b 35 d3 2d 32 d0 ca aa e6 d9 78 ed 99 68 84
                        fb 92 a0 c8 4f 09 60 f3 2e 79 d8 fc 53 19 18 e8
                        fe 79 88 e3 06 4c da fb 74 1d 03 a2 e2 ae cd 10
                        bc 62 55 2d 6f 1a 0b 18 71 56 7a 11 01 99 f5 74
                        aa 4e bf e3 16 03 01 00 04 0e 00 00 00
        Message-Authenticator = 0x00000000000000000000000000000000
                50 12 ...
        State = 0x70e4843673e191af7954d6edd228f499
                18 12  70 e4 84 36 73 e1 91 af 79 54 d6 ed d2 28 f4 99
  Code:         11
  Id:           175
  Length:       263
  Vector:       4ea588aa6bfd47fea96d500d07bc45e5
  Data:         4f  cf  01 05 00 cd 15 80 00 00 08 9b 8e 2c 29 c5 29 af
                        ee 18 93 f2 27 07 e5 90 46 7c 7f 21 2d c4 85 7e
                        1d 83 de 94 31 23 f3 7f b0 bc bd e5 cb c2 72 4a
                        69 59 17 e0 90 cb ce 71 bb a8 bb a9 c3 d0 55 9c
                        fc 0d 5c 8c 94 c0 0d 9a b8 38 9a 18 85 a3 8e 4b
                        b9 f8 76 3f 86 91 9c 4e c2 48 22 38 44 16 b6 28
                        83 80 22 57 8c 03 43 41 be 18 60 92 af ab aa f4
                        0e fb 44 d8 f6 f3 b0 7e 7b 1a 87 43 c5 53 5d 4b
                        0e 3b 35 d3 2d 32 d0 ca aa e6 d9 78 ed 99 68 84
                        fb 92 a0 c8 4f 09 60 f3 2e 79 d8 fc 53 19 18 e8
                        fe 79 88 e3 06 4c da fb 74 1d 03 a2 e2 ae cd 10
                        bc 62 55 2d 6f 1a 0b 18 71 56 7a 11 01 99 f5 74
                        aa 4e bf e3 16 03 01 00 04 0e 00 00 00
                50  12  95 ea dc 03 4c 6e 80 7e 67 6f 10 83 9f f1 dc 51
                18  12  70 e4 84 36 73 e1 91 af 79 54 d6 ed d2 28 f4 99
Thu Aug  2 12:29:17 2012 : Info: (4) Finished request 4.
Thu Aug  2 12:29:17 2012 : Debug: Waking up in 0.1 seconds.
Thu Aug  2 12:29:17 2012 : Debug: Waking up in 0.1 seconds.
Thu Aug  2 12:29:17 2012 : Debug: Waking up in 4.1 seconds.
rad_recv: Access-Request packet from host 1.1.1.23 port 49154, id=176,
length=557
  Code:         1
  Id:           176
  Length:       557
  Vector:       1a6cad37bcb8f543399498dab26ed07b
  Data:         01  32  7b 61 6d 3d 31 7d 37 32 65 39 39 32 39 33 34 33
                        63 66 66 65 61 39 33 66 33 38 62 33 63 30 32 38
                        30 62 34 61 38 31 40 57 69 4d 61 78 2e 63 6f 6d
                04  06  01 01 01 17
                3d  06  00 00 00 1b
                05  06  00 00 00 01
                1f  08  00 10 e7 61 0e 46
                20  14  30 30 31 30 30 31 30 30 31 30 30 30 30 33 32 30
                        30 30
                1a  0d  000060b5 (24757)  03 07 00 00 00 00 00
                0c  06  00 00 05 d2
                06  06  00 00 00 02
                18  12  70 e4 84 36 73 e1 91 af 79 54 d6 ed d2 28 f4 99
                1a  11  000060b5 (24757)  01 0b 00 01 05 31 2e 30 02 03 01
                1a  1b  000060b5 (24757)  2e 15 00 30 30 31 30 30 31 30 30
31 30 30 30 30
                        33 32 30 30 30
                4f  ff  02 05 01 4c 15 00 16 03 01 01 06 10 00 01 02 01
                        00 1d 15 6d 23 92 5e 99 3d d6 c9 09 f5 d0 c0 13
                        12 0a 4e 3a e4 1a 0b fc ac be 55 e2 66 ea f0 22
                        9e 5d 80 d1 21 c0 aa a9 89 c0 5a b9 f0 a3 51 53
                        71 32 4b 71 54 9e da 9f 28 e5 75 f4 10 76 71 63
                        d7 36 1b 91 f4 f4 07 b0 8d 28 68 3e 73 1b c4 c4
                        ca ad 00 06 0a e9 f2 5f e3 f6 b1 8c 09 7b 08 f4
                        f3 fd 9f 12 a1 cd 3a 00 f3 dc f4 69 55 57 98 4d
                        34 1d 2c dd 54 bc 4f 57 fd 99 59 42 f5 59 b7 08
                        a1 5e ed d4 66 85 a9 8f 24 94 84 ec 5c 03 62 1f
                        58 c4 f4 6a a3 25 db 2c 71 ce 5c a6 a3 de 75 f7
                        a7 56 0e 23 8f 21 8d af 2a 99 25 04 e8 0b a5 f6
                        e0 15 56 28 21 41 1b 7d ae 52 71 d5 ef f2 6e d8
                        c0 b9 09 42 dd 3d 2a 78 2a bc 20 5a 92 5b 82 0f
                        da 14 16 9c ad c9 75 18 c8 c6 37 c5 3d ca 29 63
                        aa 38 83 07 d5 3e c2 8d ae 9a 6c 85 d1
                4f  51  77 59 d9 4a d8 9f d9 7a af 68 f7 1f b9 66 6b fd
                        9e 66 28 f6 14 03 01 00 01 01 16 03 01 00 30 fc
                        64 74 e6 a0 ec 55 29 14 e2 cb ad eb 93 18 00 2a
                        f5 8d 46 9a 27 43 f8 6e 65 90 8d ec b9 51 0f 10
                        16 37 e9 ae dd d0 e6 b4 0a 65 78 c3 c8 3c 5b
                50  12  cd 68 25 7e 3d 6b 57 b8 6b 87 dd e4 8b f1 27 bc
        User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com"
        NAS-IP-Address = 1.1.1.23
        NAS-Port-Type = Wireless-802.16
        NAS-Port = 1
        Calling-Station-Id = "\000\020\347a\016F"
        NAS-Identifier = "001001001000032000"
        WiMAX-GMT-Timezone-offset = 0
        Framed-MTU = 1490
        Service-Type = Framed-User
        State = 0x70e4843673e191af7954d6edd228f499
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-BS-Id = 0x303031303031303031303030303332303030
        EAP-Message =
0x0205014c150016030101061000010201001d156d23925e993dd6c909f5d0c013120a4e3ae4
1a0bfcacbe55e266eaf0229e5d80d121c0aaa989c05ab9f0a3515371324b71549eda9f28e575
f410767163d7361b91f4f407b08d28683e731bc4c4caad00060ae9f25fe3f6b18c097b08f4f3
fd9f12a1cd3a00f3dcf4695557984d341d2cdd54bc4f57fd995942f559b708a15eedd46685a9
8f249484ec5c03621f58c4f46aa325db2c71ce5ca6a3de75f7a7560e238f218daf2a992504e8
0ba5f6e015562821411b7dae5271d5eff26ed8c0b90942dd3d2a782abc205a925b820fda1416
9cadc97518c8c637c53dca2963aa388307d53ec28dae9a6c85d1
        EAP-Message =
0x7759d94ad89fd97aaf68f71fb9666bfd9e6628f61403010001011603010030fc6474e6a0ec
552914e2cbadeb9318002af58d469a2743f86e65908decb9510f101637e9aeddd0e6b40a6578
c3c83c5b
        Message-Authenticator = 0xcd68257e3d6b57b86b87dde48bf127bc
Thu Aug  2 12:29:17 2012 : Info: (5) # Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
Thu Aug  2 12:29:17 2012 : Info: (5)   group authorize {
Thu Aug  2 12:29:17 2012 : Info: (5)  - entering group authorize {...}
Thu Aug  2 12:29:17 2012 : Info: (5)   [preprocess] = ok
Thu Aug  2 12:29:17 2012 : Info: (5) eap : EAP packet type response id 5
length 253
Thu Aug  2 12:29:17 2012 : Info: (5) eap : Continuing tunnel setup.
Thu Aug  2 12:29:17 2012 : Info: (5)   [eap] = ok
Thu Aug  2 12:29:17 2012 : Info: (5)   [chap] = noop
Thu Aug  2 12:29:17 2012 : Info: (5)   [mschap] = noop
Thu Aug  2 12:29:17 2012 : Info: (5)   [digest] = noop
Thu Aug  2 12:29:17 2012 : Info: (5) suffix : Looking up realm "WiMax.com"
for User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com"
Thu Aug  2 12:29:17 2012 : Info: (5) suffix : No such realm "WiMax.com"
Thu Aug  2 12:29:17 2012 : Info: (5)   [suffix] = noop
Thu Aug  2 12:29:17 2012 : Info: (5) eap : EAP packet type response id 5
length 253
Thu Aug  2 12:29:17 2012 : Info: (5) eap : Continuing tunnel setup.
Thu Aug  2 12:29:17 2012 : Info: (5)   [eap] = ok
Thu Aug  2 12:29:17 2012 : Info: (5) Found Auth-Type = EAP
Thu Aug  2 12:29:17 2012 : Info: (5) Found Auth-Type = EAP
Thu Aug  2 12:29:17 2012 : Error: (5) Warning:  Found 2 auth-types on
request for user '{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com'
Thu Aug  2 12:29:17 2012 : Info: (5) # Executing group from file
/usr/local/etc/raddb/sites-enabled/default
Thu Aug  2 12:29:17 2012 : Info: (5)   group authenticate {
Thu Aug  2 12:29:17 2012 : Info: (5)  - entering group authenticate {...}
Thu Aug  2 12:29:17 2012 : Info: (5) eap : Request found, released from the
list
Thu Aug  2 12:29:17 2012 : Info: (5) eap : EAP/ttls
Thu Aug  2 12:29:17 2012 : Info: (5) eap : processing type ttls
Thu Aug  2 12:29:17 2012 : Info: (5) ttls : Authenticate
Thu Aug  2 12:29:17 2012 : Info: (5) ttls : processing EAP-TLS
Thu Aug  2 12:29:17 2012 : Info: (5) ttls : eaptls_verify returned 7
Thu Aug  2 12:29:17 2012 : Info: (5) ttls : Done initial handshake
Thu Aug  2 12:29:17 2012 : Info: (5) ttls : <<< TLS 1.0 Handshake [length
0106], ClientKeyExchange
Thu Aug  2 12:29:17 2012 : Info: (5) ttls :     TLS_accept: SSLv3 read
client key exchange A
Thu Aug  2 12:29:17 2012 : Info: (5) ttls : <<< TLS 1.0 ChangeCipherSpec
[length 0001]
Thu Aug  2 12:29:17 2012 : Info: (5) ttls : <<< TLS 1.0 Handshake [length
0010], Finished
Thu Aug  2 12:29:17 2012 : Info: (5) ttls :     TLS_accept: SSLv3 read
finished A
Thu Aug  2 12:29:17 2012 : Info: (5) ttls : >>> TLS 1.0 ChangeCipherSpec
[length 0001]
Thu Aug  2 12:29:17 2012 : Info: (5) ttls :     TLS_accept: SSLv3 write
change cipher spec A
Thu Aug  2 12:29:17 2012 : Info: (5) ttls : >>> TLS 1.0 Handshake [length
0010], Finished
Thu Aug  2 12:29:17 2012 : Info: (5) ttls :     TLS_accept: SSLv3 write
finished A
Thu Aug  2 12:29:17 2012 : Info: (5) ttls :     TLS_accept: SSLv3 flush data
Thu Aug  2 12:29:17 2012 : Info: (5) ttls :     (other): SSL negotiation
finished successfully
Thu Aug  2 12:29:17 2012 : Debug: SSL Connection Established
Thu Aug  2 12:29:17 2012 : Info: (5) ttls : eaptls_process returned 13
Thu Aug  2 12:29:17 2012 : Info: (5)   [eap] = handled
Sending Access-Challenge of id 176 to 1.1.1.23 port 49154
        EAP-Message =
0x0106004515800000003b140301000101160301003078867353a3e23b0d6503baf380805acb
af23c2e5571baaf434c40742575994f889a63d740f43bd60b0df81bda4452aa7
                4f 47  01 06 00 45 15 80 00 00 00 3b 14 03 01 00 01 01
                        16 03 01 00 30 78 86 73 53 a3 e2 3b 0d 65 03 ba
                        f3 80 80 5a cb af 23 c2 e5 57 1b aa f4 34 c4 07
                        42 57 59 94 f8 89 a6 3d 74 0f 43 bd 60 b0 df 81
                        bd a4 45 2a a7
        Message-Authenticator = 0x00000000000000000000000000000000
                50 12 ...
        State = 0x70e4843674e291af7954d6edd228f499
                18 12  70 e4 84 36 74 e2 91 af 79 54 d6 ed d2 28 f4 99
  Code:         11
  Id:           176
  Length:       127
  Vector:       632aea85d7e8bc609e929d9df6432b88
  Data:         4f  47  01 06 00 45 15 80 00 00 00 3b 14 03 01 00 01 01
                        16 03 01 00 30 78 86 73 53 a3 e2 3b 0d 65 03 ba
                        f3 80 80 5a cb af 23 c2 e5 57 1b aa f4 34 c4 07
                        42 57 59 94 f8 89 a6 3d 74 0f 43 bd 60 b0 df 81
                        bd a4 45 2a a7
                50  12  59 56 90 75 a5 4d b0 10 66 a5 a5 9b f8 5b b9 e7
                18  12  70 e4 84 36 74 e2 91 af 79 54 d6 ed d2 28 f4 99
Thu Aug  2 12:29:17 2012 : Info: (5) Finished request 5.
Thu Aug  2 12:29:17 2012 : Debug: Waking up in 0.3 seconds.
rad_recv: Access-Request packet from host 1.1.1.23 port 49154, id=177,
length=394
  Code:         1
  Id:           177
  Length:       394
  Vector:       174e53706e00aeb0a3518f99dd483600
  Data:         01  32  7b 61 6d 3d 31 7d 37 32 65 39 39 32 39 33 34 33
                        63 66 66 65 61 39 33 66 33 38 62 33 63 30 32 38
                        30 62 34 61 38 31 40 57 69 4d 61 78 2e 63 6f 6d
                04  06  01 01 01 17
                3d  06  00 00 00 1b
                05  06  00 00 00 01
                1f  08  00 10 e7 61 0e 46
                20  14  30 30 31 30 30 31 30 30 31 30 30 30 30 33 32 30
                        30 30
                1a  0d  000060b5 (24757)  03 07 00 00 00 00 00
                0c  06  00 00 05 d2
                06  06  00 00 00 02
                18  12  70 e4 84 36 74 e2 91 af 79 54 d6 ed d2 28 f4 99
                1a  11  000060b5 (24757)  01 0b 00 01 05 31 2e 30 02 03 01
                1a  1b  000060b5 (24757)  2e 15 00 30 30 31 30 30 31 30 30
31 30 30 30 30
                        33 32 30 30 30
                4f  ad  02 06 00 ab 15 00 17 03 01 00 a0 8e bd 16 77 8e
                        63 28 f0 2f f0 94 8d d1 d4 37 0e f0 2c 0b 83 35
                        10 f0 4a 04 8a 09 5b 03 7c fd bb b7 48 24 a2 ec
                        3b 44 d8 fd a1 41 26 37 a0 a2 2b 77 05 71 fe e2
                        e4 b0 d1 5b 67 86 dd 0a 48 6a 06 96 4a 71 58 75
                        61 e9 fe 64 d2 a7 9a 24 a6 61 fe 74 97 3d b1 06
                        da 80 2f fd 3b eb 5f 44 16 ab ea 6e 17 a0 9b 8f
                        8d 72 84 8e ee b6 76 eb b4 86 1b 0a 4b b0 0b 2e
                        5f 18 2a f3 49 ba 0d 7e 7f 7a 74 01 82 b4 c0 d5
                        74 2d bf 84 b0 77 5a 58 4f ad 34 4e f4 f7 86 76
                        47 85 81 7a 1c bf 4f 3b 57 ef 5b
                50  12  80 61 e0 ea 35 44 c5 6d 74 28 8f 86 e0 36 30 ae
        User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com"
        NAS-IP-Address = 1.1.1.23
        NAS-Port-Type = Wireless-802.16
        NAS-Port = 1
        Calling-Station-Id = "\000\020\347a\016F"
        NAS-Identifier = "001001001000032000"
        WiMAX-GMT-Timezone-offset = 0
        Framed-MTU = 1490
        Service-Type = Framed-User
        State = 0x70e4843674e291af7954d6edd228f499
        WiMAX-Release = "1.0"
        WiMAX-Accounting-Capabilities = IP-Session-Based
        WiMAX-BS-Id = 0x303031303031303031303030303332303030
        EAP-Message =
0x020600ab150017030100a08ebd16778e6328f02ff0948dd1d4370ef02c0b833510f04a048a
095b037cfdbbb74824a2ec3b44d8fda1412637a0a22b770571fee2e4b0d15b6786dd0a486a06
964a71587561e9fe64d2a79a24a661fe74973db106da802ffd3beb5f4416abea6e17a09b8f8d
72848eeeb676ebb4861b0a4bb00b2e5f182af349ba0d7e7f7a740182b4c0d5742dbf84b0775a
584fad344ef4f786764785817a1cbf4f3b57ef5b
        Message-Authenticator = 0x8061e0ea3544c56d74288f86e03630ae
Thu Aug  2 12:29:17 2012 : Info: (6) # Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
Thu Aug  2 12:29:17 2012 : Info: (6)   group authorize {
Thu Aug  2 12:29:17 2012 : Info: (6)  - entering group authorize {...}
Thu Aug  2 12:29:17 2012 : Info: (6)   [preprocess] = ok
Thu Aug  2 12:29:17 2012 : Info: (6) eap : EAP packet type response id 6
length 171
Thu Aug  2 12:29:17 2012 : Info: (6) eap : Continuing tunnel setup.
Thu Aug  2 12:29:17 2012 : Info: (6)   [eap] = ok
Thu Aug  2 12:29:17 2012 : Info: (6)   [chap] = noop
Thu Aug  2 12:29:17 2012 : Info: (6)   [mschap] = noop
Thu Aug  2 12:29:17 2012 : Info: (6)   [digest] = noop
Thu Aug  2 12:29:17 2012 : Info: (6) suffix : Looking up realm "WiMax.com"
for User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com"
Thu Aug  2 12:29:17 2012 : Info: (6) suffix : No such realm "WiMax.com"
Thu Aug  2 12:29:17 2012 : Info: (6)   [suffix] = noop
Thu Aug  2 12:29:17 2012 : Info: (6) eap : EAP packet type response id 6
length 171
Thu Aug  2 12:29:17 2012 : Info: (6) eap : Continuing tunnel setup.
Thu Aug  2 12:29:17 2012 : Info: (6)   [eap] = ok
Thu Aug  2 12:29:17 2012 : Info: (6) Found Auth-Type = EAP
Thu Aug  2 12:29:17 2012 : Info: (6) Found Auth-Type = EAP
Thu Aug  2 12:29:17 2012 : Error: (6) Warning:  Found 2 auth-types on
request for user '{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com'
Thu Aug  2 12:29:17 2012 : Info: (6) # Executing group from file
/usr/local/etc/raddb/sites-enabled/default
Thu Aug  2 12:29:17 2012 : Info: (6)   group authenticate {
Thu Aug  2 12:29:17 2012 : Info: (6)  - entering group authenticate {...}
Thu Aug  2 12:29:17 2012 : Info: (6) eap : Request found, released from the
list
Thu Aug  2 12:29:17 2012 : Info: (6) eap : EAP/ttls
Thu Aug  2 12:29:17 2012 : Info: (6) eap : processing type ttls
Thu Aug  2 12:29:17 2012 : Info: (6) ttls : Authenticate
Thu Aug  2 12:29:17 2012 : Info: (6) ttls : processing EAP-TLS
Thu Aug  2 12:29:17 2012 : Info: (6) ttls : eaptls_verify returned 7
Thu Aug  2 12:29:17 2012 : Info: (6) ttls : Done initial handshake
Thu Aug  2 12:29:17 2012 : Info: (6) ttls : eaptls_process returned 7
Thu Aug  2 12:29:17 2012 : Info: (6) ttls : Session established.  Proceeding
to decode tunneled attributes.
  TTLS tunnel data in 0000: 00 00 00 01 40 00 00 1e 30 30 31 30 45 37 36 31
  TTLS tunnel data in 0010: 30 45 34 35 40 57 69 4d 61 78 2e 63 6f 6d 00 00
  TTLS tunnel data in 0020: 00 00 00 0b c0 00 00 1c 00 00 01 37 e2 6f cf da
  TTLS tunnel data in 0030: c9 64 3f 44 48 52 2f ac 31 79 98 a1 00 00 00 19
  TTLS tunnel data in 0040: c0 00 00 3e 00 00 01 37 0e 00 75 79 89 be 55 26
  TTLS tunnel data in 0050: f3 c1 06 49 c8 94 ef ca 5e 5e 00 00 00 00 00 00
  TTLS tunnel data in 0060: 00 00 f3 1c d9 98 b7 cd e6 df 22 9b b5 08 9d b8
  TTLS tunnel data in 0070: ff 67 15 31 3c 62 68 c7 e8 9c 00 00
Thu Aug  2 12:29:17 2012 : Info: (6) ttls : Tunneled attribute 1 is too
short (1 < 12) to contain anything useful.
Thu Aug  2 12:29:17 2012 : Info: (6) eap : Handler failed in EAP/ttls
Thu Aug  2 12:29:17 2012 : Info: (6) eap : Failed in EAP select
Thu Aug  2 12:29:17 2012 : Info: (6)   [eap] = invalid
Thu Aug  2 12:29:17 2012 : Info: (6) Failed to authenticate the user.
Thu Aug  2 12:29:17 2012 : Info: (6) Using Post-Auth-Type Reject
Thu Aug  2 12:29:17 2012 : Info: (6) # Executing group from file
/usr/local/etc/raddb/sites-enabled/default
Thu Aug  2 12:29:17 2012 : Info: (6)   group REJECT {
Thu Aug  2 12:29:17 2012 : Info: (6)  - entering group REJECT {...}
Thu Aug  2 12:29:17 2012 : Info: (6) attr_filter.access_reject :
expand: %{User-Name} -> {am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com
Thu Aug  2 12:29:17 2012 : Info: (6) attr_filter.access_reject : Matched
entry DEFAULT at line 11
Thu Aug  2 12:29:17 2012 : Info: (6)   [attr_filter.access_reject] = updated
Thu Aug  2 12:29:17 2012 : Info: (6) Finished request 6.
Thu Aug  2 12:29:17 2012 : Debug: Waking up in 0.1 seconds.
Thu Aug  2 12:29:18 2012 : Debug: Waking up in 0.1 seconds.
Thu Aug  2 12:29:18 2012 : Debug: Waking up in 0.6 seconds.
Thu Aug  2 12:29:18 2012 : Info: (6) Sending delayed reject
Sending Access-Reject of id 177 to 1.1.1.23 port 49154
        EAP-Message = 0x04060004
                4f 06  04 06 00 04
        Message-Authenticator = 0x00000000000000000000000000000000
                50 12 ...
  Code:         3
  Id:           177
  Length:       44
  Vector:       2acbbf58b3f1495a359f3feaaab30f99
  Data:         4f  06  04 06 00 04
                50  12  f7 d3 49 74 25 76 14 38 35 de 60 31 c0 8a c7 8e
Thu Aug  2 12:29:18 2012 : Debug: Waking up in 2.9 seconds.
Thu Aug  2 12:29:21 2012 : Info: (1) Cleaning up request packet ID 172 with
timestamp +40
Thu Aug  2 12:29:21 2012 : Debug: Waking up in 0.1 seconds.
Thu Aug  2 12:29:22 2012 : Info: (2) Cleaning up request packet ID 173 with
timestamp +41
Thu Aug  2 12:29:22 2012 : Debug: Waking up in 0.1 seconds.
Thu Aug  2 12:29:22 2012 : Info: (3) Cleaning up request packet ID 174 with
timestamp +41
Thu Aug  2 12:29:22 2012 : Debug: Waking up in 0.1 seconds.
Thu Aug  2 12:29:22 2012 : Info: (4) Cleaning up request packet ID 175 with
timestamp +41
Thu Aug  2 12:29:22 2012 : Debug: Waking up in 0.3 seconds.
Thu Aug  2 12:29:22 2012 : Info: (5) Cleaning up request packet ID 176 with
timestamp +41
Thu Aug  2 12:29:22 2012 : Debug: Waking up in 1.1 seconds.
Thu Aug  2 12:29:23 2012 : Info: (6) Cleaning up request packet ID 177 with
timestamp +41
Thu Aug  2 12:29:23 2012 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 1.1.1.23 port 49154, id=178,
length=181
  Code:         1
  Id:           178
  Length:       181
  Vector:       610a3a428887dc445ff90c63281da6a0
  Data:         01  1e  4b 65 65 70 41 6c 69 76 65 55 73 65 72 4e 61 6d
                        65 41 6e 64 50 61 73 73 77 6f 72 64
                04  06  01 01 01 17
                3d  06  00 00 00 1b
                05  06  00 00 00 00
                1f  08  00 00 00 00 00 00
                20  14  30 30 31 30 30 31 30 30 31 30 30 30 30 33 32 30
                        30 30
                1a  0d  000060b5 (24757)  03 07 00 00 00 00 00
                50  12  a0 3a 1d 62 f0 42 df 89 67 b9 a8 d3 2c 66 fc ad
                2c  14  4b 65 65 70 41 6c 69 76 65 53 65 73 73 69 6f 6e
                        49 64
                02  22  9f 61 f5 36 12 e1 5d 38 cf 6b 68 14 d6 69 2a 91
                        ce a6 8e 76 02 58 56 9a 0c 47 35 39 6c bb 5f 19
        User-Name = "KeepAliveUserNameAndPassword"
        NAS-IP-Address = 1.1.1.23
        NAS-Port-Type = Wireless-802.16
        NAS-Port = 0
        Calling-Station-Id = "\000\000\000\000\000"
        NAS-Identifier = "001001001000032000"
        WiMAX-GMT-Timezone-offset = 0
        Message-Authenticator = 0xa03a1d62f042df8967b9a8d32c66fcad
        Acct-Session-Id = "KeepAliveSessionId"
        User-Password = "KeepAliveUserNameAndPassword"
Thu Aug  2 12:30:00 2012 : Info: (7) # Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
Thu Aug  2 12:30:00 2012 : Info: (7)   group authorize {
Thu Aug  2 12:30:00 2012 : Info: (7)  - entering group authorize {...}
Thu Aug  2 12:30:00 2012 : Info: (7)   [preprocess] = ok
Thu Aug  2 12:30:00 2012 : Info: (7) eap : No EAP-Message, not doing EAP
Thu Aug  2 12:30:00 2012 : Info: (7)   [eap] = noop
Thu Aug  2 12:30:00 2012 : Info: (7)   [chap] = noop
Thu Aug  2 12:30:00 2012 : Info: (7)   [mschap] = noop
Thu Aug  2 12:30:00 2012 : Info: (7)   [digest] = noop
Thu Aug  2 12:30:00 2012 : Info: (7) suffix : No '@' in User-Name =
"KeepAliveUserNameAndPassword", looking up realm NULL
Thu Aug  2 12:30:00 2012 : Info: (7) suffix : No such realm "NULL"
Thu Aug  2 12:30:00 2012 : Info: (7)   [suffix] = noop
Thu Aug  2 12:30:00 2012 : Info: (7) eap : No EAP-Message, not doing EAP
Thu Aug  2 12:30:00 2012 : Info: (7)   [eap] = noop
Thu Aug  2 12:30:00 2012 : Info: (7)   [files] = noop
Thu Aug  2 12:30:00 2012 : Info: (7)   [expiration] = noop
Thu Aug  2 12:30:00 2012 : Info: (7)   [logintime] = noop
Thu Aug  2 12:30:00 2012 : Info: (7) pap : WARNING! No "known good" password
found for the user.  Authentication may fail because of this.
Thu Aug  2 12:30:00 2012 : Info: (7)   [pap] = noop
Thu Aug  2 12:30:00 2012 : Info: (7) ERROR: No authenticate method
(Auth-Type) found for the request: Rejecting the user
Thu Aug  2 12:30:00 2012 : Info: (7) Failed to authenticate the user.
Thu Aug  2 12:30:00 2012 : Info: (7) Using Post-Auth-Type Reject
Thu Aug  2 12:30:00 2012 : Info: (7) # Executing group from file
/usr/local/etc/raddb/sites-enabled/default
Thu Aug  2 12:30:00 2012 : Info: (7)   group REJECT {
Thu Aug  2 12:30:00 2012 : Info: (7)  - entering group REJECT {...}
Thu Aug  2 12:30:00 2012 : Info: (7) attr_filter.access_reject :
expand: %{User-Name} -> KeepAliveUserNameAndPassword
Thu Aug  2 12:30:00 2012 : Info: (7) attr_filter.access_reject : Matched
entry DEFAULT at line 11
Thu Aug  2 12:30:00 2012 : Info: (7)   [attr_filter.access_reject] = updated
Thu Aug  2 12:30:00 2012 : Info: (7) Finished request 7.
Thu Aug  2 12:30:00 2012 : Debug: Waking up in 0.3 seconds.
Thu Aug  2 12:30:01 2012 : Debug: Waking up in 0.6 seconds.
Thu Aug  2 12:30:01 2012 : Info: (7) Sending delayed reject
Sending Access-Reject of id 178 to 1.1.1.23 port 49154
  Code:         3
  Id:           178
  Length:       20
  Vector:       a15722909dd087c3543477518d0fe639
Thu Aug  2 12:30:01 2012 : Debug: Waking up in 4.9 seconds.
Thu Aug  2 12:30:06 2012 : Info: (7) Cleaning up request packet ID 178 with
timestamp +84
Thu Aug  2 12:30:06 2012 : Info: Ready to process requests.
^Crad@radserv:~$

-----Original Message-----
From:
freeradius-users-bounces+david.peterson=acc-corp.net@lists.freeradius.org
[mailto:freeradius-users-bounces+david.peterson=acc-corp.net@lists.freeradiu
s.org] On Behalf Of Alan DeKok
Sent: Wednesday, August 1, 2012 12:00 PM
To: FreeRadius users mailing list
Subject: Re: EAP problem

marco perugini wrote:
...
hi list!
i think we found same issue as david: something fails in eap-ttls. my 
supplicant is a huawei wimax cpe [that obviously works great on my 
other radius server but not the new one...]. we noticed some commit 
about ttls so we built master branch from git in the afternoon but 
still we have this problem; are we wrong about new eap-ttls 
configuration section? you can find my "radiusd -Xxx" as attachment.
Could you grab the latest version from "master"?  I added a patch to print
out the contents of the tunnel.  This lets me know *what* is in the tunnel,
so I know how to fix it.

  Thanks.

  Alan DeKok.
-
List info/subscribe/unsubscribe? See
http://www.freeradius.org/list/users.html

RE: EAP problem

David Peterson