New subject: FR2 - proxying inner tunnel

30 Jan 2008

      Hi!

I'm trying to setup the following scheme:

[win_xp]-----[Wi-Fi AP with WPA]-------[FreeRADIUS]--------[home RADIUS server]

FreeRADIUS: 1.1.7

Users being connected to access point must be authenticated against EAP-PEAP-MS-CHAPv2 protocol.
Home RADIUS server can do only MS-CHAPv2 authorization and knows nothing about EAP.
To pass extracted MS-CHAPv2 request from PEAP tunnel I've turned off proxy_tunneled_request_as_eap:

---------eap.conf-------------
peap {
    default_eap_type = mschapv2
    copy_request_to_tunnel = yes
    use_tunneled_reply = yes
    proxy_tunneled_request_as_eap = no
}

--------users-----------------
aaa     FreeRADIUS-Proxied-To == 127.0.0.1, Proxy-To-Realm := "xxx"
         Fall-Through := No

--------proxy.conf------------
realm xxx {
         type            = radius 

         authhost        = 192.168.2.80:1812
         accthost        = 192.168.2.80:1813
         secret          = pretty_secret
} 

------------------------------

Authorization requests are being proxied from FreeRADIUS to home RADIUS server as plain MS-CHAPv2.
Home server authorizes client and passes back MS-MPPE-*-Keys. But FreeRADIUS discards all MS-CHAPv2 attributes from
proxy reply just saying "rlm_eap_mschapv2: Authentication succeeded.".

Here is the response from home server:

rad_recv: Access-Accept packet from host 192.168.2.80:1812, id=0, length=262
Wed Jan 30 15:03:33 2008 : Debug:  proxy: de-allocating 5002a8c0:1812 0
Reply-Message = "ACCESS: GRANTED"
Reply-Message = "AGREEMENT-ID: 587986"
Framed-IP-Address = 192.168.2.56
Framed-IP-Netmask = 255.255.255.255
Framed-Protocol = PPP
MS-CHAP2-Success = 0x00533d37354142314531443945333538353133414541334245443244314630344333384533363742384232
MS-MPPE-Encryption-Policy = 0x00000001
MS-MPPE-Encryption-Types = 0x00000006
MS-MPPE-Recv-Key = 0xadfa59550658460011ffff6aee8df748
MS-MPPE-Send-Key = 0x2f62bd6b536d9e6141790bf5c477a5b8
Service-Type = Framed-User
Reply-Message = "STATUS: 0.00000000"

and the response to Wi-Fi AP before tunnel:

PEAP: Final reply from tunneled session code 11
Reply-Message = "ACCESS: GRANTED"
Reply-Message = "AGREEMENT-ID: 587986"
Framed-IP-Address = 192.168.2.56
Framed-IP-Netmask = 255.255.255.255
Framed-Protocol = PPP
Service-Type = Framed-User
Reply-Message = "STATUS: 0.00000000"
EAP-Message = 0x010700331a0306002e533d37354142314531443945333538353133414541334245443244314630344333384533363742384232
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xbb336a79c074253ad516aa753953f8aa

There is no MS-CHAP2-Success attribute here. So no "rlm_eap_peap: Success" at the end of challenge and no
Access-Accept packet being sent to Wi-Fi AP.

When username is configured locally (i.e. with no proxying request to home server), everything works fine.

Does anyone have such working scheme here?
Please find complete log attached.

-- 
Best wishes,
Dmitry Sergienko (SDA104-RIPE)
Trifle Co., Ltd.

Wed Jan 30 16:21:17 2008 : Info: Starting - reading configuration files ...
Wed Jan 30 16:21:17 2008 : Debug: reread_config:  reading radiusd.conf
Wed Jan 30 16:21:17 2008 : Debug: Config:   including file: /etc/freeradius/proxy.conf
Wed Jan 30 16:21:17 2008 : Debug: Config:   including file: /etc/freeradius/clients.conf
Wed Jan 30 16:21:17 2008 : Debug: Config:   including file: /etc/freeradius/snmp.conf
Wed Jan 30 16:21:17 2008 : Debug: Config:   including file: /etc/freeradius/eap.conf
Wed Jan 30 16:21:17 2008 : Debug: Config:   including file: /etc/freeradius/sql.conf
Wed Jan 30 16:21:17 2008 : Debug:  main: prefix = "/usr"
Wed Jan 30 16:21:17 2008 : Debug:  main: localstatedir = "/var"
Wed Jan 30 16:21:17 2008 : Debug:  main: logdir = "/var/log/freeradius"
Wed Jan 30 16:21:17 2008 : Debug:  main: libdir = "/usr/lib/freeradius"
Wed Jan 30 16:21:17 2008 : Debug:  main: radacctdir = "/var/log/freeradius/radacct"
Wed Jan 30 16:21:17 2008 : Debug:  main: hostname_lookups = no
Wed Jan 30 16:21:17 2008 : Debug:  main: snmp = no
Wed Jan 30 16:21:17 2008 : Debug:  main: max_request_time = 30
Wed Jan 30 16:21:17 2008 : Debug:  main: cleanup_delay = 5
Wed Jan 30 16:21:17 2008 : Debug:  main: max_requests = 1024
Wed Jan 30 16:21:17 2008 : Debug:  main: delete_blocked_requests = 0
Wed Jan 30 16:21:17 2008 : Debug:  main: port = 0
Wed Jan 30 16:21:17 2008 : Debug:  main: allow_core_dumps = no
Wed Jan 30 16:21:17 2008 : Debug:  main: log_stripped_names = no
Wed Jan 30 16:21:17 2008 : Debug:  main: log_file = "/var/log/freeradius/radius.log"
Wed Jan 30 16:21:17 2008 : Debug:  main: log_auth = no
Wed Jan 30 16:21:17 2008 : Debug:  main: log_auth_badpass = no
Wed Jan 30 16:21:17 2008 : Debug:  main: log_auth_goodpass = no
Wed Jan 30 16:21:17 2008 : Debug:  main: pidfile = "/var/run/freeradius/freeradius.pid"
Wed Jan 30 16:21:17 2008 : Debug:  main: user = "freerad"
Wed Jan 30 16:21:17 2008 : Debug:  main: group = "freerad"
Wed Jan 30 16:21:17 2008 : Debug:  main: usercollide = no
Wed Jan 30 16:21:17 2008 : Debug:  main: lower_user = "no"
Wed Jan 30 16:21:17 2008 : Debug:  main: lower_pass = "no"
Wed Jan 30 16:21:17 2008 : Debug:  main: nospace_user = "no"
Wed Jan 30 16:21:17 2008 : Debug:  main: nospace_pass = "no"
Wed Jan 30 16:21:17 2008 : Debug:  main: checkrad = "/usr/sbin/checkrad"
Wed Jan 30 16:21:17 2008 : Debug:  main: proxy_requests = yes
Wed Jan 30 16:21:17 2008 : Debug:  proxy: retry_delay = 5
Wed Jan 30 16:21:17 2008 : Debug:  proxy: retry_count = 3
Wed Jan 30 16:21:17 2008 : Debug:  proxy: synchronous = no
Wed Jan 30 16:21:17 2008 : Debug:  proxy: default_fallback = yes
Wed Jan 30 16:21:17 2008 : Debug:  proxy: dead_time = 120
Wed Jan 30 16:21:17 2008 : Debug:  proxy: post_proxy_authorize = no
Wed Jan 30 16:21:17 2008 : Debug:  proxy: wake_all_if_all_dead = no
Wed Jan 30 16:21:17 2008 : Debug:  security: max_attributes = 200
Wed Jan 30 16:21:17 2008 : Debug:  security: reject_delay = 1
Wed Jan 30 16:21:17 2008 : Debug:  security: status_server = no
Wed Jan 30 16:21:17 2008 : Debug:  main: debug_level = 0
Wed Jan 30 16:21:17 2008 : Debug: read_config_files:  reading dictionary
Wed Jan 30 16:21:17 2008 : Debug: read_config_files:  reading naslist
Wed Jan 30 16:21:17 2008 : Debug: read_config_files:  reading clients
Wed Jan 30 16:21:17 2008 : Debug: read_config_files:  reading realms
Wed Jan 30 16:21:17 2008 : Debug: radiusd:  entering modules setup
Wed Jan 30 16:21:17 2008 : Debug: Module: Library search path is /usr/lib/freeradius
Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded exec 
Wed Jan 30 16:21:17 2008 : Debug:  exec: wait = yes
Wed Jan 30 16:21:17 2008 : Debug:  exec: program = "(null)"
Wed Jan 30 16:21:17 2008 : Debug:  exec: input_pairs = "request"
Wed Jan 30 16:21:17 2008 : Debug:  exec: output_pairs = "(null)"
Wed Jan 30 16:21:17 2008 : Debug:  exec: packet_type = "(null)"
Wed Jan 30 16:21:17 2008 : Info: rlm_exec: Wait=yes but no output defined. Did you mean output=none?
Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated exec (exec) 
Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded expr 
Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated expr (expr) 
Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded PAP 
Wed Jan 30 16:21:17 2008 : Debug:  pap: encryption_scheme = "crypt"
Wed Jan 30 16:21:17 2008 : Debug:  pap: auto_header = yes
Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated pap (pap) 
Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded CHAP 
Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated chap (chap) 
Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded MS-CHAP 
Wed Jan 30 16:21:17 2008 : Debug:  mschap: use_mppe = yes
Wed Jan 30 16:21:17 2008 : Debug:  mschap: require_encryption = no
Wed Jan 30 16:21:17 2008 : Debug:  mschap: require_strong = no
Wed Jan 30 16:21:17 2008 : Debug:  mschap: with_ntdomain_hack = no
Wed Jan 30 16:21:17 2008 : Debug:  mschap: passwd = "(null)"
Wed Jan 30 16:21:17 2008 : Debug:  mschap: ntlm_auth = "(null)"
Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated mschap (mschap) 
Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded System 
Wed Jan 30 16:21:17 2008 : Debug:  unix: cache = no
Wed Jan 30 16:21:17 2008 : Debug:  unix: passwd = "(null)"
Wed Jan 30 16:21:17 2008 : Debug:  unix: shadow = "/etc/shadow"
Wed Jan 30 16:21:17 2008 : Debug:  unix: group = "(null)"
Wed Jan 30 16:21:17 2008 : Debug:  unix: radwtmp = "/var/log/freeradius/radwtmp"
Wed Jan 30 16:21:17 2008 : Debug:  unix: usegroup = no
Wed Jan 30 16:21:17 2008 : Debug:  unix: cache_reload = 600
Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated unix (unix) 
Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded eap 
Wed Jan 30 16:21:17 2008 : Debug:  eap: default_eap_type = "peap"
Wed Jan 30 16:21:17 2008 : Debug:  eap: timer_expire = 60
Wed Jan 30 16:21:17 2008 : Debug:  eap: ignore_unknown_eap_types = no
Wed Jan 30 16:21:17 2008 : Debug:  eap: cisco_accounting_username_bug = no
Wed Jan 30 16:21:17 2008 : Debug: rlm_eap: Loaded and initialized type md5
Wed Jan 30 16:21:17 2008 : Debug: rlm_eap: Loaded and initialized type leap
Wed Jan 30 16:21:17 2008 : Debug:  gtc: challenge = "Password: "
Wed Jan 30 16:21:17 2008 : Debug:  gtc: auth_type = "PAP"
Wed Jan 30 16:21:17 2008 : Debug: rlm_eap: Loaded and initialized type gtc
Wed Jan 30 16:21:17 2008 : Debug:  tls: rsa_key_exchange = no
Wed Jan 30 16:21:17 2008 : Debug:  tls: dh_key_exchange = yes
Wed Jan 30 16:21:17 2008 : Debug:  tls: rsa_key_length = 512
Wed Jan 30 16:21:17 2008 : Debug:  tls: dh_key_length = 512
Wed Jan 30 16:21:17 2008 : Debug:  tls: verify_depth = 0
Wed Jan 30 16:21:17 2008 : Debug:  tls: CA_path = "(null)"
Wed Jan 30 16:21:17 2008 : Debug:  tls: pem_file_type = yes
Wed Jan 30 16:21:17 2008 : Debug:  tls: private_key_file = "/etc/freeradius/certs/cert-srv.pem"
Wed Jan 30 16:21:17 2008 : Debug:  tls: certificate_file = "/etc/freeradius/certs/cert-srv.pem"
Wed Jan 30 16:21:17 2008 : Debug:  tls: CA_file = "/etc/freeradius/certs/demoCA/cacert.pem"
Wed Jan 30 16:21:17 2008 : Debug:  tls: private_key_password = "whatever"
Wed Jan 30 16:21:17 2008 : Debug:  tls: dh_file = "/etc/freeradius/certs/dh"
Wed Jan 30 16:21:17 2008 : Debug:  tls: random_file = "/etc/freeradius/certs/random"
Wed Jan 30 16:21:17 2008 : Debug:  tls: fragment_size = 1024
Wed Jan 30 16:21:17 2008 : Debug:  tls: include_length = yes
Wed Jan 30 16:21:17 2008 : Debug:  tls: check_crl = no
Wed Jan 30 16:21:17 2008 : Debug:  tls: check_cert_cn = "(null)"
Wed Jan 30 16:21:17 2008 : Debug:  tls: cipher_list = "(null)"
Wed Jan 30 16:21:17 2008 : Debug:  tls: check_cert_issuer = "(null)"
Wed Jan 30 16:21:17 2008 : Info: rlm_eap_tls: Loading the certificate file as a chain
Wed Jan 30 16:21:17 2008 : Info: WARNING: rlm_eap_tls: Unable to set DH parameters.  DH cipher suites may not work!
Wed Jan 30 16:21:17 2008 : Debug: WARNING: Fix this by running the OpenSSL command listed in eap.conf
Wed Jan 30 16:21:17 2008 : Debug: rlm_eap: Loaded and initialized type tls
Wed Jan 30 16:21:17 2008 : Debug:  peap: default_eap_type = "mschapv2"
Wed Jan 30 16:21:17 2008 : Debug:  peap: copy_request_to_tunnel = no
Wed Jan 30 16:21:17 2008 : Debug:  peap: use_tunneled_reply = no
Wed Jan 30 16:21:17 2008 : Debug:  peap: proxy_tunneled_request_as_eap = no
Wed Jan 30 16:21:17 2008 : Debug: rlm_eap: Loaded and initialized type peap
Wed Jan 30 16:21:17 2008 : Debug:  mschapv2: with_ntdomain_hack = no
Wed Jan 30 16:21:17 2008 : Debug: rlm_eap: Loaded and initialized type mschapv2
Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated eap (eap) 
Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded preprocess 
Wed Jan 30 16:21:17 2008 : Debug:  preprocess: huntgroups = "/etc/freeradius/huntgroups"
Wed Jan 30 16:21:17 2008 : Debug:  preprocess: hints = "/etc/freeradius/hints"
Wed Jan 30 16:21:17 2008 : Debug:  preprocess: with_ascend_hack = no
Wed Jan 30 16:21:17 2008 : Debug:  preprocess: ascend_channels_per_line = 23
Wed Jan 30 16:21:17 2008 : Debug:  preprocess: with_ntdomain_hack = no
Wed Jan 30 16:21:17 2008 : Debug:  preprocess: with_specialix_jetstream_hack = no
Wed Jan 30 16:21:17 2008 : Debug:  preprocess: with_cisco_vsa_hack = no
Wed Jan 30 16:21:17 2008 : Debug:  preprocess: with_alvarion_vsa_hack = no
Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated preprocess (preprocess) 
Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded detail 
Wed Jan 30 16:21:17 2008 : Debug:  detail: detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d"
Wed Jan 30 16:21:17 2008 : Debug:  detail: detailperm = 384
Wed Jan 30 16:21:17 2008 : Debug:  detail: dirperm = 493
Wed Jan 30 16:21:17 2008 : Debug:  detail: locking = no
Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated detail (auth_log) 
Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded attr_filter 
Wed Jan 30 16:21:17 2008 : Debug:  attr_filter: attrsfile = "/etc/freeradius/attrs"
Wed Jan 30 16:21:17 2008 : Error:  rlm_attr_filter: Authorize method will be deprecated.
Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated attr_filter (attr_filter) 
Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded realm 
Wed Jan 30 16:21:17 2008 : Debug:  realm: format = "suffix"
Wed Jan 30 16:21:17 2008 : Debug:  realm: delimiter = "@"
Wed Jan 30 16:21:17 2008 : Debug:  realm: ignore_default = no
Wed Jan 30 16:21:17 2008 : Debug:  realm: ignore_null = no
Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated realm (suffix) 
Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded files 
Wed Jan 30 16:21:17 2008 : Debug:  files: usersfile = "/etc/freeradius/users"
Wed Jan 30 16:21:17 2008 : Debug:  files: acctusersfile = "/etc/freeradius/acct_users"
Wed Jan 30 16:21:17 2008 : Debug:  files: preproxy_usersfile = "/etc/freeradius/preproxy_users"
Wed Jan 30 16:21:17 2008 : Debug:  files: compat = "no"
Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated files (files) 
Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded Acct-Unique-Session-Id 
Wed Jan 30 16:21:17 2008 : Debug:  acct_unique: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated acct_unique (acct_unique) 
Wed Jan 30 16:21:17 2008 : Debug:  detail: detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
Wed Jan 30 16:21:17 2008 : Debug:  detail: detailperm = 384
Wed Jan 30 16:21:17 2008 : Debug:  detail: dirperm = 493
Wed Jan 30 16:21:17 2008 : Debug:  detail: locking = no
Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated detail (detail) 
Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded radutmp 
Wed Jan 30 16:21:17 2008 : Debug:  radutmp: filename = "/var/log/freeradius/radutmp"
Wed Jan 30 16:21:17 2008 : Debug:  radutmp: username = "%{User-Name}"
Wed Jan 30 16:21:17 2008 : Debug:  radutmp: case_sensitive = yes
Wed Jan 30 16:21:17 2008 : Debug:  radutmp: check_with_nas = yes
Wed Jan 30 16:21:17 2008 : Debug:  radutmp: perm = 384
Wed Jan 30 16:21:17 2008 : Debug:  radutmp: callerid = yes
Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated radutmp (radutmp) 
Wed Jan 30 16:21:17 2008 : Debug:  detail: detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d"
Wed Jan 30 16:21:17 2008 : Debug:  detail: detailperm = 384
Wed Jan 30 16:21:17 2008 : Debug:  detail: dirperm = 493
Wed Jan 30 16:21:17 2008 : Debug:  detail: locking = no
Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated detail (pre_proxy_log) 
Wed Jan 30 16:21:17 2008 : Debug:  detail: detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d"
Wed Jan 30 16:21:17 2008 : Debug:  detail: detailperm = 384
Wed Jan 30 16:21:17 2008 : Debug:  detail: dirperm = 493
Wed Jan 30 16:21:17 2008 : Debug:  detail: locking = no
Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated detail (post_proxy_log) 
Wed Jan 30 16:21:17 2008 : Debug:  detail: detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d"
Wed Jan 30 16:21:17 2008 : Debug:  detail: detailperm = 384
Wed Jan 30 16:21:17 2008 : Debug:  detail: dirperm = 493
Wed Jan 30 16:21:17 2008 : Debug:  detail: locking = no
Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated detail (reply_log) 
Wed Jan 30 16:21:17 2008 : Debug: Listening on authentication *:1812
Wed Jan 30 16:21:17 2008 : Debug: Listening on accounting *:1813
Wed Jan 30 16:21:17 2008 : Debug: Listening on proxy *:1814
Wed Jan 30 16:21:17 2008 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 192.168.2.28:1032, id=0, length=184
	Message-Authenticator = 0x95738e03d1fb1c0ceba98dbdf1ab912f
	Service-Type = Framed-User
	User-Name = "aaa"
	Framed-MTU = 1488
	Called-Station-Id = "00-15-E9-AE-B2-BF:WLAN"
	Calling-Station-Id = "00-17-9A-82-C7-7B"
	NAS-Identifier = "WLAN Access Point"
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 54Mbps 802.11g"
	EAP-Message = 0x0200000801616161
	NAS-IP-Address = 192.168.2.28
	NAS-Port = 1
	NAS-Port-Id = "STA port # 1"
Wed Jan 30 16:21:23 2008 : Debug:   Processing the authorize section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authorize for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "preprocess" returns ok for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling auth_log (rlm_detail) for request 0
Wed Jan 30 16:21:23 2008 : Debug: radius_xlat:  '/var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130'
Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from auth_log (rlm_detail) for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "auth_log" returns ok for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling attr_filter (rlm_attr_filter) for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from attr_filter (rlm_attr_filter) for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "attr_filter" returns noop for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "chap" returns noop for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "mschap" returns noop for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 0
Wed Jan 30 16:21:23 2008 : Debug:     rlm_realm: No '@' in User-Name = "aaa", looking up realm NULL
Wed Jan 30 16:21:23 2008 : Debug:     rlm_realm: No such realm "NULL"
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "suffix" returns noop for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 0
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: EAP packet type response id 0 length 8
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "eap" returns updated for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling files (rlm_files) for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from files (rlm_files) for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "files" returns notfound for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling pap (rlm_pap) for request 0
Wed Jan 30 16:21:23 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user.  Authentication may fail because of this.
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from pap (rlm_pap) for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "pap" returns noop for request 0
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authorize (returns updated) for request 0
Wed Jan 30 16:21:23 2008 : Debug:   rad_check_password:  Found Auth-Type EAP
Wed Jan 30 16:21:23 2008 : Debug: auth: type "EAP"
Wed Jan 30 16:21:23 2008 : Debug:   Processing the authenticate section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authenticate for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 0
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: EAP Identity
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: processing type tls
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: Initiate
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: Start returned 1
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 0
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authenticate]: module "eap" returns handled for request 0
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 0
Sending Access-Challenge of id 0 to 192.168.2.28 port 1032
	EAP-Message = 0x010100061920
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x5db289aaf7d6fa0ebe901707a31e963c
Wed Jan 30 16:21:23 2008 : Debug: Finished request 0
Wed Jan 30 16:21:23 2008 : Debug: Going to the next request
Wed Jan 30 16:21:23 2008 : Debug: --- Walking the entire request list ---
Wed Jan 30 16:21:23 2008 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.2.28:1032, id=1, length=306
	Message-Authenticator = 0x47b000110073bbb08377c494b4bd16ef
	Service-Type = Framed-User
	User-Name = "aaa"
	Framed-MTU = 1488
	State = 0x5db289aaf7d6fa0ebe901707a31e963c
	Called-Station-Id = "00-15-E9-AE-B2-BF:WLAN"
	Calling-Station-Id = "00-17-9A-82-C7-7B"
	NAS-Identifier = "WLAN Access Point"
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 54Mbps 802.11g"
	EAP-Message = 0x0201007019800000006616030100610100005d030147a087e3be36eef7e3c8558ad9836ef8545a57ad4ecd31cb1dee537f0217d0a0203285b3ca15b5bc19c4dc749138750ef06e349d1b28dc3864c757ae2d531b31bb001600040005000a000900640062000300060013001200630100
	NAS-IP-Address = 192.168.2.28
	NAS-Port = 1
	NAS-Port-Id = "STA port # 1"
Wed Jan 30 16:21:23 2008 : Debug:   Processing the authorize section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authorize for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "preprocess" returns ok for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling auth_log (rlm_detail) for request 1
Wed Jan 30 16:21:23 2008 : Debug: radius_xlat:  '/var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130'
Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from auth_log (rlm_detail) for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "auth_log" returns ok for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling attr_filter (rlm_attr_filter) for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from attr_filter (rlm_attr_filter) for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "attr_filter" returns noop for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "chap" returns noop for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "mschap" returns noop for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 1
Wed Jan 30 16:21:23 2008 : Debug:     rlm_realm: No '@' in User-Name = "aaa", looking up realm NULL
Wed Jan 30 16:21:23 2008 : Debug:     rlm_realm: No such realm "NULL"
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "suffix" returns noop for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 1
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: EAP packet type response id 1 length 112
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "eap" returns updated for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling files (rlm_files) for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from files (rlm_files) for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "files" returns notfound for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling pap (rlm_pap) for request 1
Wed Jan 30 16:21:23 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user.  Authentication may fail because of this.
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from pap (rlm_pap) for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "pap" returns noop for request 1
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authorize (returns updated) for request 1
Wed Jan 30 16:21:23 2008 : Debug:   rad_check_password:  Found Auth-Type EAP
Wed Jan 30 16:21:23 2008 : Debug: auth: type "EAP"
Wed Jan 30 16:21:23 2008 : Debug:   Processing the authenticate section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authenticate for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 1
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: Request found, released from the list
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: EAP/peap
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: processing type peap
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: Authenticate
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: processing TLS
Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls:  Length Included
Wed Jan 30 16:21:23 2008 : Debug:   eaptls_verify returned 11 
Wed Jan 30 16:21:23 2008 : Debug:     (other): before/accept initialization 
Wed Jan 30 16:21:23 2008 : Debug:     TLS_accept: before/accept initialization 
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: <<< TLS 1.0 Handshake [length 0061], ClientHello  
Wed Jan 30 16:21:23 2008 : Debug:     TLS_accept: SSLv3 read client hello A 
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello  
Wed Jan 30 16:21:23 2008 : Debug:     TLS_accept: SSLv3 write server hello A 
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: >>> TLS 1.0 Handshake [length 0694], Certificate  
Wed Jan 30 16:21:23 2008 : Debug:     TLS_accept: SSLv3 write certificate A 
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone  
Wed Jan 30 16:21:23 2008 : Debug:     TLS_accept: SSLv3 write server done A 
Wed Jan 30 16:21:23 2008 : Debug:     TLS_accept: SSLv3 flush data 
Wed Jan 30 16:21:23 2008 : Debug:     TLS_accept: Need to read more data: SSLv3 read client certificate A
Wed Jan 30 16:21:23 2008 : Debug: In SSL Handshake Phase 
Wed Jan 30 16:21:23 2008 : Debug: In SSL Accept mode  
Wed Jan 30 16:21:23 2008 : Debug:   eaptls_process returned 13 
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: EAPTLS_HANDLED
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 1
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authenticate]: module "eap" returns handled for request 1
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 1
Sending Access-Challenge of id 1 to 192.168.2.28 port 1032
	EAP-Message = 0x0102040a19c0000006f1160301004a02000046030147a087e30fe5927afc6e913fc013cdd64421ade59e5e48e0081dec52246dfb5620406d860bab150a348618c2468f0782195f2b7bad6e69a157ff5bbefb9bf70b6e00040016030106940b00069000068d0002cd308202c930820232a003020102020102300d06092a864886f70d010104050030819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e74206365
	EAP-Message = 0x7274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c652e636f6d301e170d3034303132353133323631305a170d3035303132343133323631305a30819b310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f73743119301706035504031310526f6f74206365727469666963617465311f301d06092a864886f70d0109011610726f6f74406578616d706c652e636f6d30819f300d06092a864886f70d010101050003
	EAP-Message = 0x818d0030818902818100dac525422bfedb082629a2cba44b3449c90d0ab462fb72c8434a782098863d7eb7d7e70028c2b7ad555a51cc756cf4fa1d7091615ab450d5289553ae6616aff014a55085d6b8fb4aee98638e426175cdd36c665c63cda177d34920eb30585edc8773999c2980f81ad4638bbbea1c82d054023db7ef24a3ec1c3f6241a903d7f30203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d0101040500038181007a2d921b1cf13bf2982a9178ec9ede6d88edc178a2e8bd40a0a06fb6f0769957884cd7084537083496fd184165293f583c8e8240eb68e042c94b15752e4c07e80d09
	EAP-Message = 0x779afa3dd55c24fa54ac292d77205d1c2477ed30d59f57caf9bd21ff2a8d16cc0911c50e4f295763fcb60efa3c3d2d0e43850f6e6fbe284902f6e83503650003ba308203b63082031fa003020102020100300d06092a864886f70d010104050030819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e742063657274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c
	EAP-Message = 0x652e636f6d301e170d3034303132353133323630375a
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x5708202a97e43ae72b2b2c71ba80ada9
Wed Jan 30 16:21:23 2008 : Debug: Finished request 1
Wed Jan 30 16:21:23 2008 : Debug: Going to the next request
Wed Jan 30 16:21:23 2008 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.2.28:1032, id=2, length=200
	Message-Authenticator = 0xc8c00d8115a81d1ef2d1975cd7b7815b
	Service-Type = Framed-User
	User-Name = "aaa"
	Framed-MTU = 1488
	State = 0x5708202a97e43ae72b2b2c71ba80ada9
	Called-Station-Id = "00-15-E9-AE-B2-BF:WLAN"
	Calling-Station-Id = "00-17-9A-82-C7-7B"
	NAS-Identifier = "WLAN Access Point"
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 54Mbps 802.11g"
	EAP-Message = 0x020200061900
	NAS-IP-Address = 192.168.2.28
	NAS-Port = 1
	NAS-Port-Id = "STA port # 1"
Wed Jan 30 16:21:23 2008 : Debug:   Processing the authorize section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authorize for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "preprocess" returns ok for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling auth_log (rlm_detail) for request 2
Wed Jan 30 16:21:23 2008 : Debug: radius_xlat:  '/var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130'
Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from auth_log (rlm_detail) for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "auth_log" returns ok for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling attr_filter (rlm_attr_filter) for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from attr_filter (rlm_attr_filter) for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "attr_filter" returns noop for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "chap" returns noop for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "mschap" returns noop for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 2
Wed Jan 30 16:21:23 2008 : Debug:     rlm_realm: No '@' in User-Name = "aaa", looking up realm NULL
Wed Jan 30 16:21:23 2008 : Debug:     rlm_realm: No such realm "NULL"
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "suffix" returns noop for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 2
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: EAP packet type response id 2 length 6
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "eap" returns updated for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling files (rlm_files) for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from files (rlm_files) for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "files" returns notfound for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling pap (rlm_pap) for request 2
Wed Jan 30 16:21:23 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user.  Authentication may fail because of this.
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from pap (rlm_pap) for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "pap" returns noop for request 2
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authorize (returns updated) for request 2
Wed Jan 30 16:21:23 2008 : Debug:   rad_check_password:  Found Auth-Type EAP
Wed Jan 30 16:21:23 2008 : Debug: auth: type "EAP"
Wed Jan 30 16:21:23 2008 : Debug:   Processing the authenticate section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authenticate for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 2
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: Request found, released from the list
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: EAP/peap
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: processing type peap
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: Authenticate
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: processing TLS
Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: Received EAP-TLS ACK message
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: ack handshake fragment handler
Wed Jan 30 16:21:23 2008 : Debug:   eaptls_verify returned 1 
Wed Jan 30 16:21:23 2008 : Debug:   eaptls_process returned 13 
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: EAPTLS_HANDLED
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 2
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authenticate]: module "eap" returns handled for request 2
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 2
Sending Access-Challenge of id 2 to 192.168.2.28 port 1032
	EAP-Message = 0x010302f71900170d3036303132343133323630375a30819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e742063657274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c652e636f6d30819f300d06092a864886f70d010101050003818d0030818902818100d4c5b19724f164acf1ffb189db1c8fbff4f14396ea7cb1e90f78d69451725377895dfe52ccb99b41e8
	EAP-Message = 0x0ddeb58b127a943f4f58cbc562878192fbdc6fece9f871e7c130d35cf5188817e9b133249edd2a1c75d31043ae87553cec7a77ef26aa7d74281db9b77e17c6446c5dd9b188b43250ca0229963722a123a726b00b4027fd0203010001a381ff3081fc301d0603551d0e0416041468d36d3e1ee7bc9d5a057021c363da1365d1ade33081cc0603551d230481c43081c1801468d36d3e1ee7bc9d5a057021c363da1365d1ade3a181a5a481a230819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010
	EAP-Message = 0x060355040b13096c6f63616c686f7374311b301906035504031312436c69656e742063657274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c652e636f6d820100300c0603551d13040530030101ff300d06092a864886f70d01010405000381810033c00b66b1e579ef73a06798252dab8d5e5511fc00fd276d80d12f834777c6743fdc2743fca1507704e4bc0979e4f60ac3ad9ee83e6f347369229d1f77229ba2e982359da563024a00163dba6d6c986c0bad28af85132ff8f0d76501bf1b7c2dff658ce1e62c01997b6e64e3e8d4373354ce9912847651539063b85bbc5485c516030100040e000000
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xe6496d844bf69bdcdb1602289e985d94
Wed Jan 30 16:21:23 2008 : Debug: Finished request 2
Wed Jan 30 16:21:23 2008 : Debug: Going to the next request
Wed Jan 30 16:21:23 2008 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.2.28:1032, id=3, length=386
	Message-Authenticator = 0x50eaac0ad7a2fe459a874501a98ac64b
	Service-Type = Framed-User
	User-Name = "aaa"
	Framed-MTU = 1488
	State = 0xe6496d844bf69bdcdb1602289e985d94
	Called-Station-Id = "00-15-E9-AE-B2-BF:WLAN"
	Calling-Station-Id = "00-17-9A-82-C7-7B"
	NAS-Identifier = "WLAN Access Point"
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 54Mbps 802.11g"
	EAP-Message = 0x020300c01980000000b61603010086100000820080bac89a3ea71151d7ad09a69ff4ea8bc2951547167c8ea167fa9c3650285c4b106263fbff6b6b52bbbd6ec2c9eb4b9eb1a19d949ed96f2d81ee59cde3e388b26f6bc5285b71dcf6965e8ced6b59007420c47ac570b12d170c3bf9d3d3a133004a8e7fe37bf4fe4e27ed41982a8eec19682e20fa680c9bd41339e28477bce1d0581403010001011603010020fea0deb5a460a2665fc5b24deae99e753a3ba1a12c198817bb33422ec05227ee
	NAS-IP-Address = 192.168.2.28
	NAS-Port = 1
	NAS-Port-Id = "STA port # 1"
Wed Jan 30 16:21:23 2008 : Debug:   Processing the authorize section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authorize for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "preprocess" returns ok for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling auth_log (rlm_detail) for request 3
Wed Jan 30 16:21:23 2008 : Debug: radius_xlat:  '/var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130'
Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from auth_log (rlm_detail) for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "auth_log" returns ok for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling attr_filter (rlm_attr_filter) for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from attr_filter (rlm_attr_filter) for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "attr_filter" returns noop for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "chap" returns noop for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "mschap" returns noop for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 3
Wed Jan 30 16:21:23 2008 : Debug:     rlm_realm: No '@' in User-Name = "aaa", looking up realm NULL
Wed Jan 30 16:21:23 2008 : Debug:     rlm_realm: No such realm "NULL"
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "suffix" returns noop for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 3
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: EAP packet type response id 3 length 192
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "eap" returns updated for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling files (rlm_files) for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from files (rlm_files) for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "files" returns notfound for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling pap (rlm_pap) for request 3
Wed Jan 30 16:21:23 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user.  Authentication may fail because of this.
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from pap (rlm_pap) for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "pap" returns noop for request 3
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authorize (returns updated) for request 3
Wed Jan 30 16:21:23 2008 : Debug:   rad_check_password:  Found Auth-Type EAP
Wed Jan 30 16:21:23 2008 : Debug: auth: type "EAP"
Wed Jan 30 16:21:23 2008 : Debug:   Processing the authenticate section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authenticate for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 3
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: Request found, released from the list
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: EAP/peap
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: processing type peap
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: Authenticate
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: processing TLS
Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls:  Length Included
Wed Jan 30 16:21:23 2008 : Debug:   eaptls_verify returned 11 
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange  
Wed Jan 30 16:21:23 2008 : Debug:     TLS_accept: SSLv3 read client key exchange A 
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001]  
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished  
Wed Jan 30 16:21:23 2008 : Debug:     TLS_accept: SSLv3 read finished A 
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001]  
Wed Jan 30 16:21:23 2008 : Debug:     TLS_accept: SSLv3 write change cipher spec A 
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished  
Wed Jan 30 16:21:23 2008 : Debug:     TLS_accept: SSLv3 write finished A 
Wed Jan 30 16:21:23 2008 : Debug:     TLS_accept: SSLv3 flush data 
Wed Jan 30 16:21:23 2008 : Debug:     (other): SSL negotiation finished successfully 
Wed Jan 30 16:21:23 2008 : Debug: SSL Connection Established 
Wed Jan 30 16:21:23 2008 : Debug:   eaptls_process returned 13 
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: EAPTLS_HANDLED
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 3
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authenticate]: module "eap" returns handled for request 3
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 3
Sending Access-Challenge of id 3 to 192.168.2.28 port 1032
	EAP-Message = 0x0104003119001403010001011603010020a562e906ef0e8bcc20bdf677cf9488ea9f72210f343b6b2764f4751c5ec28418
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x3882c9b17babca451a6ccc9e89a82d1e
Wed Jan 30 16:21:23 2008 : Debug: Finished request 3
Wed Jan 30 16:21:23 2008 : Debug: Going to the next request
Wed Jan 30 16:21:23 2008 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.2.28:1032, id=4, length=200
	Message-Authenticator = 0x3d2571581a9de91e3544ff7994b3bc4c
	Service-Type = Framed-User
	User-Name = "aaa"
	Framed-MTU = 1488
	State = 0x3882c9b17babca451a6ccc9e89a82d1e
	Called-Station-Id = "00-15-E9-AE-B2-BF:WLAN"
	Calling-Station-Id = "00-17-9A-82-C7-7B"
	NAS-Identifier = "WLAN Access Point"
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 54Mbps 802.11g"
	EAP-Message = 0x020400061900
	NAS-IP-Address = 192.168.2.28
	NAS-Port = 1
	NAS-Port-Id = "STA port # 1"
Wed Jan 30 16:21:23 2008 : Debug:   Processing the authorize section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authorize for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "preprocess" returns ok for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling auth_log (rlm_detail) for request 4
Wed Jan 30 16:21:23 2008 : Debug: radius_xlat:  '/var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130'
Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from auth_log (rlm_detail) for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "auth_log" returns ok for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling attr_filter (rlm_attr_filter) for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from attr_filter (rlm_attr_filter) for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "attr_filter" returns noop for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "chap" returns noop for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "mschap" returns noop for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 4
Wed Jan 30 16:21:23 2008 : Debug:     rlm_realm: No '@' in User-Name = "aaa", looking up realm NULL
Wed Jan 30 16:21:23 2008 : Debug:     rlm_realm: No such realm "NULL"
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "suffix" returns noop for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 4
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: EAP packet type response id 4 length 6
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "eap" returns updated for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling files (rlm_files) for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from files (rlm_files) for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "files" returns notfound for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling pap (rlm_pap) for request 4
Wed Jan 30 16:21:23 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user.  Authentication may fail because of this.
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from pap (rlm_pap) for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "pap" returns noop for request 4
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authorize (returns updated) for request 4
Wed Jan 30 16:21:23 2008 : Debug:   rad_check_password:  Found Auth-Type EAP
Wed Jan 30 16:21:23 2008 : Debug: auth: type "EAP"
Wed Jan 30 16:21:23 2008 : Debug:   Processing the authenticate section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authenticate for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 4
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: Request found, released from the list
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: EAP/peap
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: processing type peap
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: Authenticate
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: processing TLS
Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: Received EAP-TLS ACK message
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: ack handshake is finished
Wed Jan 30 16:21:23 2008 : Debug:   eaptls_verify returned 3 
Wed Jan 30 16:21:23 2008 : Debug:   eaptls_process returned 3 
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: EAPTLS_SUCCESS
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 4
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authenticate]: module "eap" returns handled for request 4
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 4
Sending Access-Challenge of id 4 to 192.168.2.28 port 1032
	EAP-Message = 0x0105002019001703010015a003beb410bd42441cf8049fc078150a1f62dc13a5
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x6472259ba53a52a47938bbb75daab0fc
Wed Jan 30 16:21:23 2008 : Debug: Finished request 4
Wed Jan 30 16:21:23 2008 : Debug: Going to the next request
Wed Jan 30 16:21:23 2008 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.2.28:1032, id=5, length=225
	Message-Authenticator = 0xfa8d3e5d9994f240fd0ef4158a8c9246
	Service-Type = Framed-User
	User-Name = "aaa"
	Framed-MTU = 1488
	State = 0x6472259ba53a52a47938bbb75daab0fc
	Called-Station-Id = "00-15-E9-AE-B2-BF:WLAN"
	Calling-Station-Id = "00-17-9A-82-C7-7B"
	NAS-Identifier = "WLAN Access Point"
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 54Mbps 802.11g"
	EAP-Message = 0x0205001f19001703010014f2094e78f3e975f48718cbb7d270c92bdeb7b1a5
	NAS-IP-Address = 192.168.2.28
	NAS-Port = 1
	NAS-Port-Id = "STA port # 1"
Wed Jan 30 16:21:23 2008 : Debug:   Processing the authorize section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authorize for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "preprocess" returns ok for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling auth_log (rlm_detail) for request 5
Wed Jan 30 16:21:23 2008 : Debug: radius_xlat:  '/var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130'
Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from auth_log (rlm_detail) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "auth_log" returns ok for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling attr_filter (rlm_attr_filter) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from attr_filter (rlm_attr_filter) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "attr_filter" returns noop for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "chap" returns noop for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "mschap" returns noop for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 5
Wed Jan 30 16:21:23 2008 : Debug:     rlm_realm: No '@' in User-Name = "aaa", looking up realm NULL
Wed Jan 30 16:21:23 2008 : Debug:     rlm_realm: No such realm "NULL"
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "suffix" returns noop for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: EAP packet type response id 5 length 31
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "eap" returns updated for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling files (rlm_files) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from files (rlm_files) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "files" returns notfound for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling pap (rlm_pap) for request 5
Wed Jan 30 16:21:23 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user.  Authentication may fail because of this.
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from pap (rlm_pap) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "pap" returns noop for request 5
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authorize (returns updated) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   rad_check_password:  Found Auth-Type EAP
Wed Jan 30 16:21:23 2008 : Debug: auth: type "EAP"
Wed Jan 30 16:21:23 2008 : Debug:   Processing the authenticate section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authenticate for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: Request found, released from the list
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: EAP/peap
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: processing type peap
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: Authenticate
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: processing TLS
Wed Jan 30 16:21:23 2008 : Debug:   eaptls_verify returned 7 
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: Done initial handshake
Wed Jan 30 16:21:23 2008 : Debug:   eaptls_process returned 7 
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: EAPTLS_OK
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: Session established.  Decoding tunneled attributes.
  PEAP tunnel data in 0000: 01 61 61 61 
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: Identity - aaa
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: Tunneled data is valid.
  PEAP: Got tunneled EAP-Message
	EAP-Message = 0x0205000801616161
Wed Jan 30 16:21:23 2008 : Debug:   PEAP: Got tunneled identity of aaa
Wed Jan 30 16:21:23 2008 : Debug:   PEAP: Setting default EAP type for tunneled EAP session.
Wed Jan 30 16:21:23 2008 : Debug:   PEAP: Setting User-Name to aaa
  PEAP: Sending tunneled request
	EAP-Message = 0x0205000801616161
	FreeRADIUS-Proxied-To = 127.0.0.1
	User-Name = "aaa"
Wed Jan 30 16:21:23 2008 : Debug:   Processing the authorize section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authorize for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "preprocess" returns ok for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling auth_log (rlm_detail) for request 5
Wed Jan 30 16:21:23 2008 : Debug: radius_xlat:  '/var/log/freeradius/radacct/127.0.0.1/auth-detail-20080130'
Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/127.0.0.1/auth-detail-20080130
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from auth_log (rlm_detail) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "auth_log" returns ok for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling attr_filter (rlm_attr_filter) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from attr_filter (rlm_attr_filter) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "attr_filter" returns noop for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "chap" returns noop for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "mschap" returns noop for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 5
Wed Jan 30 16:21:23 2008 : Debug:     rlm_realm: No '@' in User-Name = "aaa", looking up realm NULL
Wed Jan 30 16:21:23 2008 : Debug:     rlm_realm: No such realm "NULL"
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "suffix" returns noop for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: EAP packet type response id 5 length 8
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "eap" returns updated for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling files (rlm_files) for request 5
Wed Jan 30 16:21:23 2008 : Debug:     users: Matched entry aaa at line 85
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from files (rlm_files) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "files" returns ok for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling pap (rlm_pap) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from pap (rlm_pap) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "pap" returns noop for request 5
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authorize (returns updated) for request 5
  PEAP: Got tunneled reply RADIUS code 0
Wed Jan 30 16:21:23 2008 : Debug:   PEAP: Calling authenticate in order to initiate tunneled EAP session.
Wed Jan 30 16:21:23 2008 : Debug:   Processing the authenticate section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authenticate for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: EAP Identity
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: processing type mschapv2
Wed Jan 30 16:21:23 2008 : Info: rlm_eap_mschapv2: Issuing Challenge
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authenticate]: module "eap" returns handled for request 5
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 5
Wed Jan 30 16:21:23 2008 : Debug:     PEAP: Cancelling proxy to realm xxx until the tunneled EAP session has been established
  PEAP: Processing from tunneled session code 0x80147040 11
	EAP-Message = 0x0106001d1a0106001810d705730f12a9595b41ac811cc23eab54616161
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x767993fd4ad4ebf861acdf27ec0a3a8e
Wed Jan 30 16:21:23 2008 : Debug:   PEAP: Got tunneled Access-Challenge
  PEAP tunnel data out 0000: 1a 01 06 00 18 10 d7 05 73 0f 12 a9 59 5b 41 ac 
  PEAP tunnel data out 0010: 81 1c c2 3e ab 54 61 61 61 
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 5
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authenticate]: module "eap" returns handled for request 5
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 5
Sending Access-Challenge of id 5 to 192.168.2.28 port 1032
	EAP-Message = 0x01060034190017030100291f8fadaf8be94d9469a30a78fcc2ae5503135fb3588b426d80237b5bb96cd390128aaaeab9af12f9f3
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x46e3664e4d1315184ed1a50e6dc819b3
Wed Jan 30 16:21:23 2008 : Debug: Finished request 5
Wed Jan 30 16:21:23 2008 : Debug: Going to the next request
Wed Jan 30 16:21:23 2008 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.2.28:1032, id=6, length=279
	Message-Authenticator = 0xf24acb657d7e9f0ea425095ba74e861b
	Service-Type = Framed-User
	User-Name = "aaa"
	Framed-MTU = 1488
	State = 0x46e3664e4d1315184ed1a50e6dc819b3
	Called-Station-Id = "00-15-E9-AE-B2-BF:WLAN"
	Calling-Station-Id = "00-17-9A-82-C7-7B"
	NAS-Identifier = "WLAN Access Point"
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 54Mbps 802.11g"
	EAP-Message = 0x020600551900170301004aba2524bee95d3df9b8b22f2250e4c4314a0e52353fd9037b6d96d8010f9811be0f665cae244749d9b0f10fa2d28d5660564fe27284e1f3d92a4222360cf90d70f12d193a481852d84bbe
	NAS-IP-Address = 192.168.2.28
	NAS-Port = 1
	NAS-Port-Id = "STA port # 1"
Wed Jan 30 16:21:23 2008 : Debug:   Processing the authorize section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authorize for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "preprocess" returns ok for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling auth_log (rlm_detail) for request 6
Wed Jan 30 16:21:23 2008 : Debug: radius_xlat:  '/var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130'
Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from auth_log (rlm_detail) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "auth_log" returns ok for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling attr_filter (rlm_attr_filter) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from attr_filter (rlm_attr_filter) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "attr_filter" returns noop for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "chap" returns noop for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "mschap" returns noop for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 6
Wed Jan 30 16:21:23 2008 : Debug:     rlm_realm: No '@' in User-Name = "aaa", looking up realm NULL
Wed Jan 30 16:21:23 2008 : Debug:     rlm_realm: No such realm "NULL"
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "suffix" returns noop for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: EAP packet type response id 6 length 85
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "eap" returns updated for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling files (rlm_files) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from files (rlm_files) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "files" returns notfound for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling pap (rlm_pap) for request 6
Wed Jan 30 16:21:23 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user.  Authentication may fail because of this.
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from pap (rlm_pap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "pap" returns noop for request 6
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authorize (returns updated) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   rad_check_password:  Found Auth-Type EAP
Wed Jan 30 16:21:23 2008 : Debug: auth: type "EAP"
Wed Jan 30 16:21:23 2008 : Debug:   Processing the authenticate section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authenticate for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: Request found, released from the list
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: EAP/peap
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: processing type peap
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: Authenticate
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: processing TLS
Wed Jan 30 16:21:23 2008 : Debug:   eaptls_verify returned 7 
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: Done initial handshake
Wed Jan 30 16:21:23 2008 : Debug:   eaptls_process returned 7 
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: EAPTLS_OK
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: Session established.  Decoding tunneled attributes.
  PEAP tunnel data in 0000: 1a 02 06 00 39 31 54 3b ff a8 dd c0 94 f4 dd 7d 
  PEAP tunnel data in 0010: 68 d5 83 58 3c ef 00 00 00 00 00 00 00 00 37 cc 
  PEAP tunnel data in 0020: 3c cd 31 b8 76 ad 62 b6 16 4c bb b4 7f 0f 87 d0 
  PEAP tunnel data in 0030: 4f 4c 21 56 a1 3d 00 61 61 61 
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: EAP type mschapv2
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: Tunneled data is valid.
  PEAP: Got tunneled EAP-Message
	EAP-Message = 0x0206003e1a0206003931543bffa8ddc094f4dd7d68d583583cef000000000000000037cc3ccd31b876ad62b6164cbbb47f0f87d04f4c2156a13d00616161
Wed Jan 30 16:21:23 2008 : Debug:   PEAP: Setting User-Name to aaa
Wed Jan 30 16:21:23 2008 : Debug:   PEAP: Adding old state with 76 79
  PEAP: Sending tunneled request
	EAP-Message = 0x0206003e1a0206003931543bffa8ddc094f4dd7d68d583583cef000000000000000037cc3ccd31b876ad62b6164cbbb47f0f87d04f4c2156a13d00616161
	FreeRADIUS-Proxied-To = 127.0.0.1
	User-Name = "aaa"
	State = 0x767993fd4ad4ebf861acdf27ec0a3a8e
Wed Jan 30 16:21:23 2008 : Debug:   Processing the authorize section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authorize for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "preprocess" returns ok for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling auth_log (rlm_detail) for request 6
Wed Jan 30 16:21:23 2008 : Debug: radius_xlat:  '/var/log/freeradius/radacct/127.0.0.1/auth-detail-20080130'
Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/127.0.0.1/auth-detail-20080130
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from auth_log (rlm_detail) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "auth_log" returns ok for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling attr_filter (rlm_attr_filter) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from attr_filter (rlm_attr_filter) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "attr_filter" returns noop for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "chap" returns noop for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "mschap" returns noop for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 6
Wed Jan 30 16:21:23 2008 : Debug:     rlm_realm: No '@' in User-Name = "aaa", looking up realm NULL
Wed Jan 30 16:21:23 2008 : Debug:     rlm_realm: No such realm "NULL"
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "suffix" returns noop for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: EAP packet type response id 6 length 62
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "eap" returns updated for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling files (rlm_files) for request 6
Wed Jan 30 16:21:23 2008 : Debug:     users: Matched entry aaa at line 85
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from files (rlm_files) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "files" returns ok for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling pap (rlm_pap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from pap (rlm_pap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "pap" returns noop for request 6
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authorize (returns updated) for request 6
  PEAP: Got tunneled reply RADIUS code 0
Wed Jan 30 16:21:23 2008 : Debug:   PEAP: Calling authenticate in order to initiate tunneled EAP session.
Wed Jan 30 16:21:23 2008 : Debug:   Processing the authenticate section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authenticate for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: Request found, released from the list
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: EAP/mschapv2
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: processing type mschapv2
Wed Jan 30 16:21:23 2008 : Debug:   Not-EAP proxy set.  Not composing EAP
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authenticate]: module "eap" returns handled for request 6
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   PEAP: Tunneled authentication will be proxied to xxx
Wed Jan 30 16:21:23 2008 : Debug:   PEAP: Remembering to do EAP-MS-CHAP-V2 post-proxy.
Wed Jan 30 16:21:23 2008 : Debug:   Tunneled session will be proxied.  Not doing EAP.
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authenticate]: module "eap" returns handled for request 6
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   Processing the pre-proxy section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group pre-proxy for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[pre-proxy]: calling files (rlm_files) for request 6
Wed Jan 30 16:21:23 2008 : Debug:     preproxy_users: Matched entry DEFAULT at line 33
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[pre-proxy]: returned from files (rlm_files) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[pre-proxy]: module "files" returns ok for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[pre-proxy]: calling pre_proxy_log (rlm_detail) for request 6
Wed Jan 30 16:21:23 2008 : Debug: radius_xlat:  '/var/log/freeradius/radacct/192.168.2.28/pre-proxy-detail-20080130'
Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.2.28/pre-proxy-detail-20080130
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[pre-proxy]: returned from pre_proxy_log (rlm_detail) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[pre-proxy]: module "pre_proxy_log" returns ok for request 6
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group pre-proxy (returns ok) for request 6
Wed Jan 30 16:21:23 2008 : Debug:  proxy: creating 5002a8c0:1812
Wed Jan 30 16:21:23 2008 : Debug:  proxy: allocating 5002a8c0:1812 0
Sending Access-Request of id 0 to 192.168.2.80 port 1812
	User-Name = "aaa"
	NAS-IP-Address = 127.0.0.1
	MS-CHAP-Challenge = 0xd705730f12a9595b41ac811cc23eab54
	MS-CHAP2-Response = 0x0661543bffa8ddc094f4dd7d68d583583cef000000000000000037cc3ccd31b876ad62b6164cbbb47f0f87d04f4c2156a13d
	Proxy-State = 0x36
	Service-Type := BOSS4-HomeNet-VPN
Wed Jan 30 16:21:23 2008 : Debug: Waking up in 6 seconds...
rad_recv: Access-Accept packet from host 192.168.2.80:1812, id=0, length=262
Wed Jan 30 16:21:23 2008 : Debug:  proxy: de-allocating 5002a8c0:1812 0
	Reply-Message = "ACCESS: GRANTED"
	Reply-Message = "AGREEMENT-ID: 587986"
	Framed-IP-Address = 192.168.2.56
	Framed-IP-Netmask = 255.255.255.255
	Framed-Protocol = PPP
	MS-CHAP2-Success = 0x00533d46344538343746453843323736414341453537393637343835343143384642303742334633303739
	MS-MPPE-Encryption-Policy = 0x00000001
	MS-MPPE-Encryption-Types = 0x00000006
	MS-MPPE-Recv-Key = 0x6b79482763300b5dece7d6ac717d8a21
	MS-MPPE-Send-Key = 0xe23347a646ed9a7a19693881f99ebb37
	Service-Type = Framed-User
	Reply-Message = "STATUS: 0.00000000"
Wed Jan 30 16:21:23 2008 : Debug:   Processing the post-proxy section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group post-proxy for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[post-proxy]: calling post_proxy_log (rlm_detail) for request 6
Wed Jan 30 16:21:23 2008 : Debug: radius_xlat:  '/var/log/freeradius/radacct/192.168.2.28/post-proxy-detail-20080130'
Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.2.28/post-proxy-detail-20080130
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[post-proxy]: returned from post_proxy_log (rlm_detail) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[post-proxy]: module "post_proxy_log" returns ok for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[post-proxy]: calling eap (rlm_eap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   PEAP: Passing reply from proxy back into the tunnel.
Wed Jan 30 16:21:23 2008 : Debug:   PEAP: Passing reply back for EAP-MS-CHAP-V2 0x801453f8 2
Wed Jan 30 16:21:23 2008 : Debug:   Processing the post-proxy section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group post-proxy for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[post-proxy]: calling post_proxy_log (rlm_detail) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[post-proxy]: returned from post_proxy_log (rlm_detail) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[post-proxy]: module "post_proxy_log" returns noop for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[post-proxy]: calling eap (rlm_eap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_mschapv2: Passing reply from proxy back into the tunnel 0x801453f8 2.
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_mschapv2: Authentication succeeded.
Wed Jan 30 16:21:23 2008 : Debug: MSCHAP Success 
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[post-proxy]: returned from eap (rlm_eap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[post-proxy]: module "eap" returns ok for request 6
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group post-proxy (returns ok) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   POST-PROXY 2
Wed Jan 30 16:21:23 2008 : Debug:   Processing the post-auth section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group post-auth for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[post-auth]: calling reply_log (rlm_detail) for request 6
Wed Jan 30 16:21:23 2008 : Debug: radius_xlat:  '/var/log/freeradius/radacct/127.0.0.1/reply-detail-20080130'
Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d expands to /var/log/freeradius/radacct/127.0.0.1/reply-detail-20080130
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[post-auth]: returned from reply_log (rlm_detail) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[post-auth]: module "reply_log" returns ok for request 6
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group post-auth (returns ok) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   POST-AUTH 2
  PEAP: Final reply from tunneled session code 11
	Reply-Message = "ACCESS: GRANTED"
	Reply-Message = "AGREEMENT-ID: 587986"
	Framed-IP-Address = 192.168.2.56
	Framed-IP-Netmask = 255.255.255.255
	Framed-Protocol = PPP
	Service-Type = Framed-User
	Reply-Message = "STATUS: 0.00000000"
	EAP-Message = 0x010700331a0306002e533d46344538343746453843323736414341453537393637343835343143384642303742334633303739
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x2e6847c5eb9a59e5f7cdbc3d8f082a8f
Wed Jan 30 16:21:23 2008 : Debug:  PEAP: Got reply 11
  PEAP: Processing from tunneled session code 0x80144e58 11
	Reply-Message = "ACCESS: GRANTED"
	Reply-Message = "AGREEMENT-ID: 587986"
	Framed-IP-Address = 192.168.2.56
	Framed-IP-Netmask = 255.255.255.255
	Framed-Protocol = PPP
	Service-Type = Framed-User
	Reply-Message = "STATUS: 0.00000000"
	EAP-Message = 0x010700331a0306002e533d46344538343746453843323736414341453537393637343835343143384642303742334633303739
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x2e6847c5eb9a59e5f7cdbc3d8f082a8f
Wed Jan 30 16:21:23 2008 : Debug:   PEAP: Got tunneled Access-Challenge
  PEAP tunnel data out 0000: 1a 03 06 00 2e 53 3d 46 34 45 38 34 37 46 45 38 
  PEAP tunnel data out 0010: 43 32 37 36 41 43 41 45 35 37 39 36 37 34 38 35 
  PEAP tunnel data out 0020: 34 31 43 38 46 42 30 37 42 33 46 33 30 37 39 
Wed Jan 30 16:21:23 2008 : Debug:   PEAP: Reply was handled
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[post-proxy]: returned from eap (rlm_eap) for request 6
Wed Jan 30 16:21:23 2008 : Debug:   modcall[post-proxy]: module "eap" returns ok for request 6
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group post-proxy (returns ok) for request 6
Sending Access-Challenge of id 6 to 192.168.2.28 port 1032
	EAP-Message = 0x0107004a1900170301003f3cbae61fe7c97a3500bb9b7aa65a7ebf4dfde9f637ba2a0f53ed7e91716066ab1dac2c590f7476689bf80aacf390629dd56a9d5e9df17b60819fc23938d207
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x8f6fded6f73f89f6c871aa78026be3fe
Wed Jan 30 16:21:23 2008 : Debug: Finished request 6
Wed Jan 30 16:21:23 2008 : Debug: Going to the next request
Wed Jan 30 16:21:23 2008 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.2.28:1032, id=7, length=223
	Message-Authenticator = 0xdf76dfa6cb666f43cae3f55e797a4b95
	Service-Type = Framed-User
	User-Name = "aaa"
	Framed-MTU = 1488
	State = 0x8f6fded6f73f89f6c871aa78026be3fe
	Called-Station-Id = "00-15-E9-AE-B2-BF:WLAN"
	Calling-Station-Id = "00-17-9A-82-C7-7B"
	NAS-Identifier = "WLAN Access Point"
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 54Mbps 802.11g"
	EAP-Message = 0x0207001d19001703010012156f46fa75527ef68f17bb704f8dba1532f7
	NAS-IP-Address = 192.168.2.28
	NAS-Port = 1
	NAS-Port-Id = "STA port # 1"
Wed Jan 30 16:21:23 2008 : Debug:   Processing the authorize section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authorize for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "preprocess" returns ok for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling auth_log (rlm_detail) for request 7
Wed Jan 30 16:21:23 2008 : Debug: radius_xlat:  '/var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130'
Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from auth_log (rlm_detail) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "auth_log" returns ok for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling attr_filter (rlm_attr_filter) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from attr_filter (rlm_attr_filter) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "attr_filter" returns noop for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "chap" returns noop for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "mschap" returns noop for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 7
Wed Jan 30 16:21:23 2008 : Debug:     rlm_realm: No '@' in User-Name = "aaa", looking up realm NULL
Wed Jan 30 16:21:23 2008 : Debug:     rlm_realm: No such realm "NULL"
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "suffix" returns noop for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: EAP packet type response id 7 length 29
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "eap" returns updated for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling files (rlm_files) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from files (rlm_files) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "files" returns notfound for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling pap (rlm_pap) for request 7
Wed Jan 30 16:21:23 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user.  Authentication may fail because of this.
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from pap (rlm_pap) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "pap" returns noop for request 7
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authorize (returns updated) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   rad_check_password:  Found Auth-Type EAP
Wed Jan 30 16:21:23 2008 : Debug: auth: type "EAP"
Wed Jan 30 16:21:23 2008 : Debug:   Processing the authenticate section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authenticate for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: Request found, released from the list
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: EAP/peap
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: processing type peap
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: Authenticate
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: processing TLS
Wed Jan 30 16:21:23 2008 : Debug:   eaptls_verify returned 7 
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_tls: Done initial handshake
Wed Jan 30 16:21:23 2008 : Debug:   eaptls_process returned 7 
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: EAPTLS_OK
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: Session established.  Decoding tunneled attributes.
  PEAP tunnel data in 0000: 1a 03 
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: EAP type mschapv2
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap_peap: Tunneled data is valid.
  PEAP: Got tunneled EAP-Message
	EAP-Message = 0x020700061a03
Wed Jan 30 16:21:23 2008 : Debug:   PEAP: Setting User-Name to aaa
Wed Jan 30 16:21:23 2008 : Debug:   PEAP: Adding old state with 2e 68
  PEAP: Sending tunneled request
	EAP-Message = 0x020700061a03
	FreeRADIUS-Proxied-To = 127.0.0.1
	User-Name = "aaa"
	State = 0x2e6847c5eb9a59e5f7cdbc3d8f082a8f
Wed Jan 30 16:21:23 2008 : Debug:   Processing the authorize section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authorize for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "preprocess" returns ok for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling auth_log (rlm_detail) for request 7
Wed Jan 30 16:21:23 2008 : Debug: radius_xlat:  '/var/log/freeradius/radacct/127.0.0.1/auth-detail-20080130'
Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/127.0.0.1/auth-detail-20080130
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from auth_log (rlm_detail) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "auth_log" returns ok for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling attr_filter (rlm_attr_filter) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from attr_filter (rlm_attr_filter) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "attr_filter" returns noop for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling chap (rlm_chap) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from chap (rlm_chap) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "chap" returns noop for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling mschap (rlm_mschap) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from mschap (rlm_mschap) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "mschap" returns noop for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling suffix (rlm_realm) for request 7
Wed Jan 30 16:21:23 2008 : Debug:     rlm_realm: No '@' in User-Name = "aaa", looking up realm NULL
Wed Jan 30 16:21:23 2008 : Debug:     rlm_realm: No such realm "NULL"
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from suffix (rlm_realm) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "suffix" returns noop for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: EAP packet type response id 7 length 6
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "eap" returns updated for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling files (rlm_files) for request 7
Wed Jan 30 16:21:23 2008 : Debug:     users: Matched entry aaa at line 85
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from files (rlm_files) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "files" returns ok for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: calling pap (rlm_pap) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authorize]: returned from pap (rlm_pap) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authorize]: module "pap" returns noop for request 7
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authorize (returns updated) for request 7
  PEAP: Got tunneled reply RADIUS code 0
Wed Jan 30 16:21:23 2008 : Debug:   PEAP: Calling authenticate in order to initiate tunneled EAP session.
Wed Jan 30 16:21:23 2008 : Debug:   Processing the authenticate section of radiusd.conf
Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authenticate for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: Request not found in the list
Wed Jan 30 16:21:23 2008 : Error: rlm_eap: Either EAP-request timed out OR EAP-response to an unknown EAP-request
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: Failed in handler
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authenticate]: module "eap" returns invalid for request 7
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authenticate (returns invalid) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   PEAP: Can't handle the return code 4
Wed Jan 30 16:21:23 2008 : Debug:  rlm_eap: Handler failed in EAP/peap
Wed Jan 30 16:21:23 2008 : Debug:   rlm_eap: Failed in EAP select
Wed Jan 30 16:21:23 2008 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 7
Wed Jan 30 16:21:23 2008 : Debug:   modcall[authenticate]: module "eap" returns invalid for request 7
Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authenticate (returns invalid) for request 7
Wed Jan 30 16:21:23 2008 : Debug: auth: Failed to validate the user.
Wed Jan 30 16:21:23 2008 : Debug: Delaying request 7 for 1 seconds
Wed Jan 30 16:21:23 2008 : Debug: Finished request 7
Wed Jan 30 16:21:23 2008 : Debug: Going to the next request
Wed Jan 30 16:21:23 2008 : Debug: Waking up in 6 seconds...

EAP-PEAP-MS-CHAPv2: MS-CHAPv2 attributes discarded after proxying

Dmitry Sergienko

Dmitry Sergienko

Alan DeKok

Dmitry Sergienko

Alan DeKok

Dmitry Sergienko

Dmitry Sergienko

Alan DeKok

A.L.M.Buxey＠lboro.ac.uk

Dmitry Sergienko

Alan DeKok

Dmitry Sergienko

Alan DeKok

Dmitry Sergienko

Alan DeKok

Dmitry Sergienko

Dmitry Sergienko

Alan DeKok

tags

participants (3)