dhcp ttls 3com 7760

9 Nov 2007

      Hello,

I want to use EAP-TTLS with PAP. Authentication seems good but attribute
Tunnel-Private-Group-Id:0 = "88" doesn't works and dhcp send me NAS's
VLAN default and not VLAN 88.
Thanks

DEBUG FREERADIUS  FreeRADIUS Version 1.1.3, on Debian

Fri Nov  9 10:13:47 2007 : Info: Starting - reading configuration
files ...
Fri Nov  9 10:13:47 2007 : Debug: reread_config:  reading radiusd.conf
Fri Nov  9 10:13:47 2007 : Debug: Config:   including
file: /etc/freeradius/proxy.conf
Fri Nov  9 10:13:47 2007 : Debug: Config:   including
file: /etc/freeradius/clients.conf
Fri Nov  9 10:13:47 2007 : Debug: Config:   including
file: /etc/freeradius/snmp.conf
Fri Nov  9 10:13:47 2007 : Debug: Config:   including
file: /etc/freeradius/eap.conf
Fri Nov  9 10:13:47 2007 : Debug: Config:   including
file: /etc/freeradius/sql.conf
Fri Nov  9 10:13:47 2007 : Debug:  main: prefix = "/usr"
Fri Nov  9 10:13:47 2007 : Debug:  main: localstatedir = "/var"
Fri Nov  9 10:13:47 2007 : Debug:  main: logdir = "/var/log/freeradius"
Fri Nov  9 10:13:47 2007 : Debug:  main: libdir = "/usr/lib/freeradius"
Fri Nov  9 10:13:47 2007 : Debug:  main: radacctdir =
"/var/log/freeradius/radacct"
Fri Nov  9 10:13:47 2007 : Debug:  main: hostname_lookups = no
Fri Nov  9 10:13:47 2007 : Debug:  main: max_request_time = 30
Fri Nov  9 10:13:47 2007 : Debug:  main: cleanup_delay = 5
Fri Nov  9 10:13:47 2007 : Debug:  main: max_requests = 1024
Fri Nov  9 10:13:47 2007 : Debug:  main: delete_blocked_requests = 0
Fri Nov  9 10:13:47 2007 : Debug:  main: port = 0
Fri Nov  9 10:13:47 2007 : Debug:  main: allow_core_dumps = no
Fri Nov  9 10:13:47 2007 : Debug:  main: log_stripped_names = no
Fri Nov  9 10:13:47 2007 : Debug:  main: log_file =
"/var/log/freeradius/radius.log"
Fri Nov  9 10:13:47 2007 : Debug:  main: log_auth = no
Fri Nov  9 10:13:47 2007 : Debug:  main: log_auth_badpass = no
Fri Nov  9 10:13:47 2007 : Debug:  main: log_auth_goodpass = no
Fri Nov  9 10:13:47 2007 : Debug:  main: pidfile =
"/var/run/freeradius/freeradius.pid"
Fri Nov  9 10:13:47 2007 : Debug:  main: user = "freerad"
Fri Nov  9 10:13:47 2007 : Debug:  main: group = "freerad"
Fri Nov  9 10:13:47 2007 : Debug:  main: usercollide = no
Fri Nov  9 10:13:47 2007 : Debug:  main: lower_user = "no"
Fri Nov  9 10:13:47 2007 : Debug:  main: lower_pass = "no"
Fri Nov  9 10:13:47 2007 : Debug:  main: nospace_user = "no"
Fri Nov  9 10:13:47 2007 : Debug:  main: nospace_pass = "no"
Fri Nov  9 10:13:47 2007 : Debug:  main: checkrad = "/usr/sbin/checkrad"
Fri Nov  9 10:13:47 2007 : Debug:  main: proxy_requests = yes
Fri Nov  9 10:13:47 2007 : Debug:  proxy: retry_delay = 5
Fri Nov  9 10:13:47 2007 : Debug:  proxy: retry_count = 3
Fri Nov  9 10:13:47 2007 : Debug:  proxy: synchronous = no
Fri Nov  9 10:13:47 2007 : Debug:  proxy: default_fallback = yes
Fri Nov  9 10:13:47 2007 : Debug:  proxy: dead_time = 120
Fri Nov  9 10:13:47 2007 : Debug:  proxy: post_proxy_authorize = no
Fri Nov  9 10:13:47 2007 : Debug:  proxy: wake_all_if_all_dead = no
Fri Nov  9 10:13:47 2007 : Debug:  security: max_attributes = 200
Fri Nov  9 10:13:47 2007 : Debug:  security: reject_delay = 1
Fri Nov  9 10:13:47 2007 : Debug:  security: status_server = no
Fri Nov  9 10:13:47 2007 : Debug:  main: debug_level = 0
Fri Nov  9 10:13:47 2007 : Debug: read_config_files:  reading dictionary
Fri Nov  9 10:13:47 2007 : Debug: read_config_files:  reading naslist
Fri Nov  9 10:13:47 2007 : Info: Using deprecated naslist file.  Support
for this will go away soon.
Fri Nov  9 10:13:47 2007 : Debug: read_config_files:  reading clients
Fri Nov  9 10:13:47 2007 : Debug: read_config_files:  reading realms
Fri Nov  9 10:13:47 2007 : Debug: radiusd:  entering modules setup
Fri Nov  9 10:13:47 2007 : Debug: Module: Library search path
is /usr/lib/freeradius
Fri Nov  9 10:13:47 2007 : Debug: Module: Loaded exec 
Fri Nov  9 10:13:47 2007 : Debug:  exec: wait = yes
Fri Nov  9 10:13:47 2007 : Debug:  exec: program = "(null)"
Fri Nov  9 10:13:47 2007 : Debug:  exec: input_pairs = "request"
Fri Nov  9 10:13:47 2007 : Debug:  exec: output_pairs = "(null)"
Fri Nov  9 10:13:47 2007 : Debug:  exec: packet_type = "(null)"
Fri Nov  9 10:13:47 2007 : Info: rlm_exec: Wait=yes but no output
defined. Did you mean output=none?
Fri Nov  9 10:13:47 2007 : Debug: Module: Instantiated exec (exec) 
Fri Nov  9 10:13:47 2007 : Debug: Module: Loaded expr 
Fri Nov  9 10:13:47 2007 : Debug: Module: Instantiated expr (expr) 
Fri Nov  9 10:13:47 2007 : Debug: Module: Loaded PAP 
Fri Nov  9 10:13:47 2007 : Debug:  pap: encryption_scheme = "clear"
Fri Nov  9 10:13:47 2007 : Debug: Module: Instantiated pap (pap) 
Fri Nov  9 10:13:47 2007 : Debug: Module: Loaded eap 
Fri Nov  9 10:13:47 2007 : Debug:  eap: default_eap_type = "ttls"
Fri Nov  9 10:13:47 2007 : Debug:  eap: timer_expire = 60
Fri Nov  9 10:13:47 2007 : Debug:  eap: ignore_unknown_eap_types = no
Fri Nov  9 10:13:47 2007 : Debug:  eap: cisco_accounting_username_bug =
no
Fri Nov  9 10:13:47 2007 : Debug:  gtc: challenge = "Password: "
Fri Nov  9 10:13:47 2007 : Debug:  gtc: auth_type = "PAP"
Fri Nov  9 10:13:47 2007 : Debug: rlm_eap: Loaded and initialized type
gtc
Fri Nov  9 10:13:47 2007 : Debug:  tls: rsa_key_exchange = no
Fri Nov  9 10:13:47 2007 : Debug:  tls: dh_key_exchange = yes
Fri Nov  9 10:13:47 2007 : Debug:  tls: rsa_key_length = 512
Fri Nov  9 10:13:47 2007 : Debug:  tls: dh_key_length = 512
Fri Nov  9 10:13:47 2007 : Debug:  tls: verify_depth = 0
Fri Nov  9 10:13:47 2007 : Debug:  tls: CA_path = "(null)"
Fri Nov  9 10:13:47 2007 : Debug:  tls: pem_file_type = yes
Fri Nov  9 10:13:47 2007 : Debug:  tls: private_key_file =
"/etc/freeradius/certs/root@iut-nimes.fr-cert.pem"
Fri Nov  9 10:13:47 2007 : Debug:  tls: certificate_file =
"/etc/freeradius/certs/root@iut-nimes.fr-cert.pem"
Fri Nov  9 10:13:47 2007 : Debug:  tls: CA_file =
"/etc/freeradius/certs/racine_radius_ca-cacert.pem"
Fri Nov  9 10:13:47 2007 : Debug:  tls: private_key_password =
"radcert123"
Fri Nov  9 10:13:47 2007 : Debug:  tls: dh_file =
"/etc/freeradius/certs/dh"
Fri Nov  9 10:13:47 2007 : Debug:  tls: random_file =
"/etc/freeradius/certs/random"
Fri Nov  9 10:13:47 2007 : Debug:  tls: fragment_size = 1024
Fri Nov  9 10:13:47 2007 : Debug:  tls: include_length = yes
Fri Nov  9 10:13:47 2007 : Debug:  tls: check_crl = no
Fri Nov  9 10:13:47 2007 : Debug:  tls: check_cert_cn = "(null)"
Fri Nov  9 10:13:47 2007 : Debug:  tls: cipher_list = "(null)"
Fri Nov  9 10:13:47 2007 : Debug:  tls: check_cert_issuer = "(null)"
Fri Nov  9 10:13:47 2007 : Info: rlm_eap_tls: Loading the certificate
file as a chain
Fri Nov  9 10:13:48 2007 : Debug: rlm_eap: Loaded and initialized type
tls
Fri Nov  9 10:13:48 2007 : Debug:  ttls: default_eap_type = "gtc"
Fri Nov  9 10:13:48 2007 : Debug:  ttls: copy_request_to_tunnel = yes
Fri Nov  9 10:13:48 2007 : Debug:  ttls: use_tunneled_reply = yes
Fri Nov  9 10:13:48 2007 : Debug: rlm_eap: Loaded and initialized type
ttls
Fri Nov  9 10:13:48 2007 : Debug: Module: Instantiated eap (eap) 
Fri Nov  9 10:13:48 2007 : Debug: Module: Loaded files 
Fri Nov  9 10:13:48 2007 : Debug:  files: usersfile =
"/etc/freeradius/users"
Fri Nov  9 10:13:48 2007 : Debug:  files: acctusersfile =
"/etc/freeradius/acct_users"
Fri Nov  9 10:13:48 2007 : Debug:  files: preproxy_usersfile =
"/etc/freeradius/preproxy_users"
Fri Nov  9 10:13:48 2007 : Debug:  files: compat = "no"
Fri Nov  9 10:13:48 2007 : Debug: Module: Instantiated files (files) 
Fri Nov  9 10:13:48 2007 : Debug: Module: Loaded preprocess 
Fri Nov  9 10:13:48 2007 : Debug:  preprocess: huntgroups =
"/etc/freeradius/huntgroups"
Fri Nov  9 10:13:48 2007 : Debug:  preprocess: hints =
"/etc/freeradius/hints"
Fri Nov  9 10:13:48 2007 : Debug:  preprocess: with_ascend_hack = no
Fri Nov  9 10:13:48 2007 : Debug:  preprocess: ascend_channels_per_line
= 23
Fri Nov  9 10:13:48 2007 : Debug:  preprocess: with_ntdomain_hack = no
Fri Nov  9 10:13:48 2007 : Debug:  preprocess:
with_specialix_jetstream_hack = no
Fri Nov  9 10:13:48 2007 : Debug:  preprocess: with_cisco_vsa_hack = no
Fri Nov  9 10:13:48 2007 : Debug:  preprocess: with_alvarion_vsa_hack =
no
Fri Nov  9 10:13:48 2007 : Debug: Module: Instantiated preprocess
(preprocess) 
Fri Nov  9 10:13:48 2007 : Debug: Module: Loaded Acct-Unique-Session-Id 
Fri Nov  9 10:13:48 2007 : Debug:  acct_unique: key = "User-Name,
Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
Fri Nov  9 10:13:48 2007 : Debug: Module: Instantiated acct_unique
(acct_unique) 
Fri Nov  9 10:13:48 2007 : Debug: Module: Loaded realm 
Fri Nov  9 10:13:48 2007 : Debug:  realm: format = "suffix"
Fri Nov  9 10:13:48 2007 : Debug:  realm: delimiter = "@"
Fri Nov  9 10:13:48 2007 : Debug:  realm: ignore_default = no
Fri Nov  9 10:13:48 2007 : Debug:  realm: ignore_null = no
Fri Nov  9 10:13:48 2007 : Debug: Module: Instantiated realm (suffix) 
Fri Nov  9 10:13:48 2007 : Debug: Module: Loaded detail 
Fri Nov  9 10:13:48 2007 : Debug:  detail: detailfile =
"/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
Fri Nov  9 10:13:48 2007 : Debug:  detail: detailperm = 384
Fri Nov  9 10:13:48 2007 : Debug:  detail: dirperm = 493
Fri Nov  9 10:13:48 2007 : Debug:  detail: locking = no
Fri Nov  9 10:13:48 2007 : Debug: Module: Instantiated detail (detail) 
Fri Nov  9 10:13:48 2007 : Debug: Module: Loaded System 
Fri Nov  9 10:13:48 2007 : Debug:  unix: cache = no
Fri Nov  9 10:13:48 2007 : Debug:  unix: passwd = "(null)"
Fri Nov  9 10:13:48 2007 : Debug:  unix: shadow = "/etc/shadow"
Fri Nov  9 10:13:48 2007 : Debug:  unix: group = "(null)"
Fri Nov  9 10:13:48 2007 : Debug:  unix: radwtmp =
"/var/log/freeradius/radwtmp"
Fri Nov  9 10:13:48 2007 : Debug:  unix: usegroup = no
Fri Nov  9 10:13:48 2007 : Debug:  unix: cache_reload = 600
Fri Nov  9 10:13:48 2007 : Debug: Module: Instantiated unix (unix) 
Fri Nov  9 10:13:48 2007 : Debug: Module: Loaded radutmp 
Fri Nov  9 10:13:48 2007 : Debug:  radutmp: filename =
"/var/log/freeradius/radutmp"
Fri Nov  9 10:13:48 2007 : Debug:  radutmp: username = "%{User-Name}"
Fri Nov  9 10:13:48 2007 : Debug:  radutmp: case_sensitive = yes
Fri Nov  9 10:13:48 2007 : Debug:  radutmp: check_with_nas = yes
Fri Nov  9 10:13:48 2007 : Debug:  radutmp: perm = 384
Fri Nov  9 10:13:48 2007 : Debug:  radutmp: callerid = yes
Fri Nov  9 10:13:48 2007 : Debug: Module: Instantiated radutmp
(radutmp) 
Fri Nov  9 10:13:48 2007 : Debug: Listening on authentication *:1812
Fri Nov  9 10:13:48 2007 : Debug: Listening on accounting *:1813
Fri Nov  9 10:13:48 2007 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 192.168.2.136:1067, id=27,
length=179
        Message-Authenticator = 0xc777320292ba053ae8629646e7d286d4
        Service-Type = Framed-User
        User-Name = "test88"
        Framed-MTU = 1488
        Called-Station-Id = "00-18-6E-9A-49-40:eap"
        Calling-Station-Id = "00-16-6F-42-28-0F"
        NAS-Identifier = "3comeap"
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 54Mbps 802.11g"
        EAP-Message = 0x021b000b01746573743838
        NAS-IP-Address = 192.168.2.136
        NAS-Port = 1
        NAS-Port-Id = "STA port # 1"
Fri Nov  9 10:13:58 2007 : Debug:   Processing the authorize section of
radiusd.conf
Fri Nov  9 10:13:58 2007 : Debug: modcall: entering group authorize for
request 0
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: calling eap
(rlm_eap) for request 0
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: EAP packet type response id
27 length 11
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: No EAP Start, assuming it's
an on-going EAP conversation
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: returned from
eap (rlm_eap) for request 0
Fri Nov  9 10:13:58 2007 : Debug:   modcall[authorize]: module "eap"
returns updated for request 0
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: calling files
(rlm_files) for request 0
Fri Nov  9 10:13:58 2007 : Debug:     users: Matched entry test88 at
line 89
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: returned from
files (rlm_files) for request 0
Fri Nov  9 10:13:58 2007 : Debug:   modcall[authorize]: module "files"
returns ok for request 0
Fri Nov  9 10:13:58 2007 : Debug: modcall: leaving group authorize
(returns updated) for request 0
Fri Nov  9 10:13:58 2007 : Debug:   rad_check_password:  Found Auth-Type
EAP
Fri Nov  9 10:13:58 2007 : Debug: auth: type "EAP"
Fri Nov  9 10:13:58 2007 : Debug:   Processing the authenticate section
of radiusd.conf
Fri Nov  9 10:13:58 2007 : Debug: modcall: entering group authenticate
for request 0
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authenticate]: calling eap
(rlm_eap) for request 0
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: EAP Identity
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: processing type tls
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: Initiate
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: Start returned 1
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authenticate]: returned
from eap (rlm_eap) for request 0
Fri Nov  9 10:13:58 2007 : Debug:   modcall[authenticate]: module "eap"
returns handled for request 0
Fri Nov  9 10:13:58 2007 : Debug: modcall: leaving group authenticate
(returns handled) for request 0
Sending Access-Challenge of id 27 to 192.168.2.136 port 1067
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "88"
        EAP-Message = 0x011c00061520
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xd2177350f1aeca055b21e4b7478c3c29
Fri Nov  9 10:13:58 2007 : Debug: Finished request 0
Fri Nov  9 10:13:58 2007 : Debug: Going to the next request
Fri Nov  9 10:13:58 2007 : Debug: --- Walking the entire request list
---
Fri Nov  9 10:13:58 2007 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.2.136:1067, id=28,
length=279
        Message-Authenticator = 0x6a90c00463c671bc9cf9fff2e3b69fd7
        Service-Type = Framed-User
        User-Name = "test88"
        Framed-MTU = 1488
        State = 0xd2177350f1aeca055b21e4b7478c3c29
        Called-Station-Id = "00-18-6E-9A-49-40:eap"
        Calling-Station-Id = "00-16-6F-42-28-0F"
        NAS-Identifier = "3comeap"
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 54Mbps 802.11g"
        EAP-Message =
0x021c005d150016030100520100004e0301473425793d9577ad5304cc664c14ffb9bbcf523d0f0ed0936a3610bf1848800000002600390038003500160013000a00330032002f0005000400150012000900140011000800060003020100
        NAS-IP-Address = 192.168.2.136
        NAS-Port = 1
        NAS-Port-Id = "STA port # 1"
Fri Nov  9 10:13:58 2007 : Debug:   Processing the authorize section of
radiusd.conf
Fri Nov  9 10:13:58 2007 : Debug: modcall: entering group authorize for
request 1
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: calling eap
(rlm_eap) for request 1
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: EAP packet type response id
28 length 93
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: No EAP Start, assuming it's
an on-going EAP conversation
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: returned from
eap (rlm_eap) for request 1
Fri Nov  9 10:13:58 2007 : Debug:   modcall[authorize]: module "eap"
returns updated for request 1
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: calling files
(rlm_files) for request 1
Fri Nov  9 10:13:58 2007 : Debug:     users: Matched entry test88 at
line 89
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: returned from
files (rlm_files) for request 1
Fri Nov  9 10:13:58 2007 : Debug:   modcall[authorize]: module "files"
returns ok for request 1
Fri Nov  9 10:13:58 2007 : Debug: modcall: leaving group authorize
(returns updated) for request 1
Fri Nov  9 10:13:58 2007 : Debug:   rad_check_password:  Found Auth-Type
EAP
Fri Nov  9 10:13:58 2007 : Debug: auth: type "EAP"
Fri Nov  9 10:13:58 2007 : Debug:   Processing the authenticate section
of radiusd.conf
Fri Nov  9 10:13:58 2007 : Debug: modcall: entering group authenticate
for request 1
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authenticate]: calling eap
(rlm_eap) for request 1
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: Request found, released
from the list
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: EAP/ttls
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: processing type ttls
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_ttls: Authenticate
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: processing TLS
Fri Nov  9 10:13:58 2007 : Debug:   eaptls_verify returned 7 
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: Done initial handshake
Fri Nov  9 10:13:58 2007 : Debug:     (other): before/accept
initialization 
Fri Nov  9 10:13:58 2007 : Debug:     TLS_accept: before/accept
initialization 
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: <<< TLS 1.0 Handshake
[length 0052], ClientHello  
Fri Nov  9 10:13:58 2007 : Debug:     TLS_accept: SSLv3 read client
hello A 
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: >>> TLS 1.0 Handshake
[length 004a], ServerHello  
Fri Nov  9 10:13:58 2007 : Debug:     TLS_accept: SSLv3 write server
hello A 
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: >>> TLS 1.0 Handshake
[length 0e3f], Certificate  
Fri Nov  9 10:13:58 2007 : Debug:     TLS_accept: SSLv3 write
certificate A 
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: >>> TLS 1.0 Handshake
[length 028d], ServerKeyExchange  
Fri Nov  9 10:13:58 2007 : Debug:     TLS_accept: SSLv3 write key
exchange A 
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: >>> TLS 1.0 Handshake
[length 0004], ServerHelloDone  
Fri Nov  9 10:13:58 2007 : Debug:     TLS_accept: SSLv3 write server
done A 
Fri Nov  9 10:13:58 2007 : Debug:     TLS_accept: SSLv3 flush data 
Fri Nov  9 10:13:58 2007 : Error:     TLS_accept:error in SSLv3 read
client certificate A 
Fri Nov  9 10:13:58 2007 : Error: rlm_eap: SSL error
error:00000000:lib(0):func(0):reason(0)
Fri Nov  9 10:13:58 2007 : Debug: In SSL Handshake Phase 
Fri Nov  9 10:13:58 2007 : Debug: In SSL Accept mode  
Fri Nov  9 10:13:58 2007 : Debug:   eaptls_process returned 13 
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authenticate]: returned
from eap (rlm_eap) for request 1
Fri Nov  9 10:13:58 2007 : Debug:   modcall[authenticate]: module "eap"
returns handled for request 1
Fri Nov  9 10:13:58 2007 : Debug: modcall: leaving group authenticate
(returns handled) for request 1
Sending Access-Challenge of id 28 to 192.168.2.136 port 1067
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "88"
        EAP-Message =
0x011d040a15c00000112e160301004a020000460301473424d614cdc5f63f7c490da1816099aea7d098d3e49d74e5b2220e5bd92b0820d9c32bcd1babc24318e7bcf9940af5ee2a349c684fc84e4ffaf4c6a565f95af00039011603010e3f0b000e3b000e380007213082071d30820505a003020102020101300d06092a864886f70d010105050030818b310b3009060355040613024652310f300d060355040813064672616e6365310e300c060355040713054e696d6573310c300a060355040a13034955543110300e060355040b14074955545f5241443119301706035504031410726163696e655f7261646975735f63613120301e06092a864886
        EAP-Message =
0xf70d0109011611726f6f74406975742d6e696d65732e6672301e170d3037313031373134313634375a170d3137313031333134313634375a30818e310b3009060355040613024652310f300d060355040813064672616e6365310e300c060355040713054e696d6573310c300a060355040a13034955543110300e060355040b14074955545f524144311c301a060355040313137261646975732e6975742d6e696d65732e66723120301e06092a864886f70d0109011611726f6f74406975742d6e696d65732e667230820222300d06092a864886f70d01010105000382020f003082020a0282020100b41f603426567257b79af7a1c55383b9f95630
        EAP-Message =
0xa56da69afde35132613928b2769e8a5aed6971a578e507a00f486bbc665725c549845c8d122cc5d555d7631e884b40aeee88b300066297f4419097c0e47d911a6af99beadeb5522b82927c960628ebdf76d8e11005ec71d155130f3846890118e9d6b3959f5251da0e4dd6ef485691e3ac7367a3c7216600cea8c25562497f07ac5b2c4b88f6e28a3199a84c0caeaa2978116e9107ea413138dba61344d3fb3217565ca782366ab67d28de7ab7044cb96e1b4fdaad497ef12348cb4f173e93faf163378e4d9dbb3d28555734ee1049570e1a0026cf838b1775adfa4c8fd31579e5a5d78adfe22c78d02c8a281b593e879b2732ea256b154d5493236414
        EAP-Message =
0xb9262c4c15e515fb040841e1fdb427a4d76a090242844af7b02d3059acda44bfb3235e479dc6b71ba61ce3da7338ce0b87bf501c4c49d49d3bf982d6f0ca490c7c0d84372bdc586d45315c2154fce654364e3eebc3dafd126b3257d77f96fd78f429b892293d09478866d41debd275f3a7b4411d49d6eb025ccff1d5f16cd74d42d8c6a7d33fcba89c389da11d415a5d9cd9bb0618cad78136c1350542ca6a7510682da4ff26788faad867e03535f05d12f4e1c14a0218cec63efa7ab20aead38731d3c7b87080fe3a4da8b74977e92ceb747c7887a4a1dfe30ec5abb7ad8d451866ddf9d1a965759ac903a40c74ee2f0203010001a382018530820181
        EAP-Message = 0x30090603551d1304023000301106096086480186f842
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x1c3235431a74fd4d4ba2ba6a54cf2408
Fri Nov  9 10:13:58 2007 : Debug: Finished request 1
Fri Nov  9 10:13:58 2007 : Debug: Going to the next request
Fri Nov  9 10:13:58 2007 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.2.136:1067, id=29,
length=192
        Message-Authenticator = 0xb32eb6623b0a8600f202c2ab5ec84bef
        Service-Type = Framed-User
        User-Name = "test88"
        Framed-MTU = 1488
        State = 0x1c3235431a74fd4d4ba2ba6a54cf2408
        Called-Station-Id = "00-18-6E-9A-49-40:eap"
        Calling-Station-Id = "00-16-6F-42-28-0F"
        NAS-Identifier = "3comeap"
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 54Mbps 802.11g"
        EAP-Message = 0x021d00061500
        NAS-IP-Address = 192.168.2.136
        NAS-Port = 1
        NAS-Port-Id = "STA port # 1"
Fri Nov  9 10:13:58 2007 : Debug:   Processing the authorize section of
radiusd.conf
Fri Nov  9 10:13:58 2007 : Debug: modcall: entering group authorize for
request 2
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: calling eap
(rlm_eap) for request 2
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: EAP packet type response id
29 length 6
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: No EAP Start, assuming it's
an on-going EAP conversation
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: returned from
eap (rlm_eap) for request 2
Fri Nov  9 10:13:58 2007 : Debug:   modcall[authorize]: module "eap"
returns updated for request 2
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: calling files
(rlm_files) for request 2
Fri Nov  9 10:13:58 2007 : Debug:     users: Matched entry test88 at
line 89
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: returned from
files (rlm_files) for request 2
Fri Nov  9 10:13:58 2007 : Debug:   modcall[authorize]: module "files"
returns ok for request 2
Fri Nov  9 10:13:58 2007 : Debug: modcall: leaving group authorize
(returns updated) for request 2
Fri Nov  9 10:13:58 2007 : Debug:   rad_check_password:  Found Auth-Type
EAP
Fri Nov  9 10:13:58 2007 : Debug: auth: type "EAP"
Fri Nov  9 10:13:58 2007 : Debug:   Processing the authenticate section
of radiusd.conf
Fri Nov  9 10:13:58 2007 : Debug: modcall: entering group authenticate
for request 2
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authenticate]: calling eap
(rlm_eap) for request 2
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: Request found, released
from the list
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: EAP/ttls
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: processing type ttls
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_ttls: Authenticate
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: processing TLS
Fri Nov  9 10:13:58 2007 : Debug: rlm_eap_tls: Received EAP-TLS ACK
message
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: ack handshake fragment
handler
Fri Nov  9 10:13:58 2007 : Debug:   eaptls_verify returned 1 
Fri Nov  9 10:13:58 2007 : Debug:   eaptls_process returned 13 
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authenticate]: returned
from eap (rlm_eap) for request 2
Fri Nov  9 10:13:58 2007 : Debug:   modcall[authenticate]: module "eap"
returns handled for request 2
Fri Nov  9 10:13:58 2007 : Debug: modcall: leaving group authenticate
(returns handled) for request 2
Sending Access-Challenge of id 29 to 192.168.2.136 port 1067
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "88"
        EAP-Message =
0x011e040a15c00000112e0101040403020640302b06096086480186f842010d041e161c54696e7943412047656e657261746564204365727469666963617465301d0603551d0e041604145e71168aa9388f5e560d055c69529a293bbfd4763081c00603551d230481b83081b5801450573acf65cdfb3d75565075c6bb595dcccc9fd1a18191a4818e30818b310b3009060355040613024652310f300d060355040813064672616e6365310e300c060355040713054e696d6573310c300a060355040a13034955543110300e060355040b14074955545f5241443119301706035504031410726163696e655f7261646975735f63613120301e06092a8648
        EAP-Message =
0x86f70d0109011611726f6f74406975742d6e696d65732e6672820900fdc00ec8e0a7815a301c0603551d12041530138111726f6f74406975742d6e696d65732e6672301c0603551d11041530138111726f6f74406975742d6e696d65732e667230160603551d250101ff040c300a06082b06010505070301300d06092a864886f70d01010505000382020100bfa653fd04981a61c719ea82621eb27a00668af0d8e3381acde6fef7e9b651621fce42f7fe72070bbe377390aeee3b66f4ee19615a5c42c4f152958647ee2a161d4cc6715d876f950b059877b0942c2d50c01d48aa5ec02545daa766db4edbb7ae942754b21486bb1205c9387d7a91a20d
        EAP-Message =
0x4c52d33934eb750bf306517ffcb24d3d1826b1eb9dca65610b4a90957a96e92cf9cbf4a5267c4c3b3f3438e82c169a81e73cae0bfb2d278ae08db316e26ff819affc4a256ec20cb4247b4a7330908959da4e54a3c87792e721cbfa07df8d98f7b609b51952c5fcc3efa4eb35bc985ca830ccf719ad9b40b47d10e9fc56095af4b0c64c1f219e00a05c725ab82ffa06f22c17923068fbc0801b1c50d3c1854b4eb06ef2afcef4d759913f5eddf33e37100c324dcb29bd53440a74fd689fe44c0e046bb667a634b59636df22a747b9de1016287f1bcbf55077be4b167539bda8da3d3f118387f56fc05442d67076b13a17d4eebdc1c93ea69169f5237c01
        EAP-Message =
0xedb917dbd28e4ea951779e18260b4872afa105c8ccc445ca864c0aa24edf754544e2e79b2681010ea7a5e72d5d0ba0e9e9655f6ae8a75718c91d8773ed4d40c7697a34730b2fa5d41043a70642e4f9317fe57cae2643e2734cc39150b1e798c258e86e5da2bb4b71c01e457f855ab790ca889f2ced7e8af871a3ef5c3362cbaf5706336399040f2289a2a3bce30a33709a060007113082070d308204f5a003020102020900fdc00ec8e0a7815a300d06092a864886f70d010105050030818b310b3009060355040613024652310f300d060355040813064672616e6365310e300c060355040713054e696d6573310c300a060355040a13034955543110
        EAP-Message = 0x300e060355040b14074955545f524144311930170603
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x9d5cfb6c9403a5db8329a3d3add3043d
Fri Nov  9 10:13:58 2007 : Debug: Finished request 2
Fri Nov  9 10:13:58 2007 : Debug: Going to the next request
Fri Nov  9 10:13:58 2007 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.2.136:1067, id=30,
length=192
        Message-Authenticator = 0x4c64f3772ffc237388e512a07398dea9
        Service-Type = Framed-User
        User-Name = "test88"
        Framed-MTU = 1488
        State = 0x9d5cfb6c9403a5db8329a3d3add3043d
        Called-Station-Id = "00-18-6E-9A-49-40:eap"
        Calling-Station-Id = "00-16-6F-42-28-0F"
        NAS-Identifier = "3comeap"
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 54Mbps 802.11g"
        EAP-Message = 0x021e00061500
        NAS-IP-Address = 192.168.2.136
        NAS-Port = 1
        NAS-Port-Id = "STA port # 1"
Fri Nov  9 10:13:58 2007 : Debug:   Processing the authorize section of
radiusd.conf
Fri Nov  9 10:13:58 2007 : Debug: modcall: entering group authorize for
request 3
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: calling eap
(rlm_eap) for request 3
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: EAP packet type response id
30 length 6
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: No EAP Start, assuming it's
an on-going EAP conversation
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: returned from
eap (rlm_eap) for request 3
Fri Nov  9 10:13:58 2007 : Debug:   modcall[authorize]: module "eap"
returns updated for request 3
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: calling files
(rlm_files) for request 3
Fri Nov  9 10:13:58 2007 : Debug:     users: Matched entry test88 at
line 89
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: returned from
files (rlm_files) for request 3
Fri Nov  9 10:13:58 2007 : Debug:   modcall[authorize]: module "files"
returns ok for request 3
Fri Nov  9 10:13:58 2007 : Debug: modcall: leaving group authorize
(returns updated) for request 3
Fri Nov  9 10:13:58 2007 : Debug:   rad_check_password:  Found Auth-Type
EAP
Fri Nov  9 10:13:58 2007 : Debug: auth: type "EAP"
Fri Nov  9 10:13:58 2007 : Debug:   Processing the authenticate section
of radiusd.conf
Fri Nov  9 10:13:58 2007 : Debug: modcall: entering group authenticate
for request 3
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authenticate]: calling eap
(rlm_eap) for request 3
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: Request found, released
from the list
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: EAP/ttls
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: processing type ttls
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_ttls: Authenticate
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: processing TLS
Fri Nov  9 10:13:58 2007 : Debug: rlm_eap_tls: Received EAP-TLS ACK
message
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: ack handshake fragment
handler
Fri Nov  9 10:13:58 2007 : Debug:   eaptls_verify returned 1 
Fri Nov  9 10:13:58 2007 : Debug:   eaptls_process returned 13 
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authenticate]: returned
from eap (rlm_eap) for request 3
Fri Nov  9 10:13:58 2007 : Debug:   modcall[authenticate]: module "eap"
returns handled for request 3
Fri Nov  9 10:13:58 2007 : Debug: modcall: leaving group authenticate
(returns handled) for request 3
Sending Access-Challenge of id 30 to 192.168.2.136 port 1067
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "88"
        EAP-Message =
0x011f040a15c00000112e5504031410726163696e655f7261646975735f63613120301e06092a864886f70d0109011611726f6f74406975742d6e696d65732e6672301e170d3037313031373133343330355a170d3137313031343133343330355a30818b310b3009060355040613024652310f300d060355040813064672616e6365310e300c060355040713054e696d6573310c300a060355040a13034955543110300e060355040b14074955545f5241443119301706035504031410726163696e655f7261646975735f63613120301e06092a864886f70d0109011611726f6f74406975742d6e696d65732e667230820222300d06092a864886f70d
        EAP-Message =
0x01010105000382020f003082020a0282020100c1768ae6fd481eaf9bec06a8a8f027a77ed587b81c0628e699dc331867010721e749fff40751b027a0fa389306b15a8ad06cc1659341ed04b24e7427d07804011fa33b6595cbed5d21b541bea2f07c6a1e76a29e00dab943efe93177391553d3fdaaf8d9644b86cc0ed17c60abb4333d785f696e327642b27a6dd7bd3b7979ee57bffeb8bd6f4d47410b28b6c98f9acc880bbdc56f165896b79bd5beb3c089ad811f85ad1b63a46164d535c4dd03392a85be6c7d65f4eda7932ecd5b916fbb639464213d5482803dc5f34943cdf0246d5991c470d2eae7c5dffe05c8e19b5e4e23a723cb0c6f0959af1c
        EAP-Message =
0x6e2aa2d356f786d78acec2498f7518dc1a15bdb202312e6bf3a39daaf70971359aa392e73452299cf20b1576a017efb62122dffb2ab347ee682aa3615b9b8f1601e46b33ab2889d40087ac0d9fc92c54283d9d48b405bdf2be5e6e338e2acc175b0ac63a4345a6f346ad0dff5eee00b548936aca7cead608b65539d8fde6cf3a11c739432741243bbafba4bd3fd4e83cef7a1468d87d94775a7eacda2856783676121238b317c9aaf25949d5897a8fc262e18c5f7dce8858396243920f521f65b485b9cd5e4b936bd014d34ee1cfc96c0a2a67a0e7dc2c8d2fdadc187c2f4728ff47ff123324c881374f7f54526476d6e91e646ef0f7df9f1b66efa63e
        EAP-Message =
0xa5cc0c37243d2acae9a3ed89fc68432257b83d080da587c5030203010001a38201703082016c301d0603551d0e0416041450573acf65cdfb3d75565075c6bb595dcccc9fd13081c00603551d230481b83081b5801450573acf65cdfb3d75565075c6bb595dcccc9fd1a18191a4818e30818b310b3009060355040613024652310f300d060355040813064672616e6365310e300c060355040713054e696d6573310c300a060355040a13034955543110300e060355040b14074955545f5241443119301706035504031410726163696e655f7261646975735f63613120301e06092a864886f70d0109011611726f6f74406975742d6e696d65732e6672
        EAP-Message = 0x820900fdc00ec8e0a7815a300f0603551d130101ff04
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x46882bc4783ecf928f9e9249f78b3bdd
Fri Nov  9 10:13:58 2007 : Debug: Finished request 3
Fri Nov  9 10:13:58 2007 : Debug: Going to the next request
Fri Nov  9 10:13:58 2007 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.2.136:1067, id=31,
length=192
        Message-Authenticator = 0x77224a6af99075e4218c335270197e98
        Service-Type = Framed-User
        User-Name = "test88"
        Framed-MTU = 1488
        State = 0x46882bc4783ecf928f9e9249f78b3bdd
        Called-Station-Id = "00-18-6E-9A-49-40:eap"
        Calling-Station-Id = "00-16-6F-42-28-0F"
        NAS-Identifier = "3comeap"
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 54Mbps 802.11g"
        EAP-Message = 0x021f00061500
        NAS-IP-Address = 192.168.2.136
        NAS-Port = 1
        NAS-Port-Id = "STA port # 1"
Fri Nov  9 10:13:58 2007 : Debug:   Processing the authorize section of
radiusd.conf
Fri Nov  9 10:13:58 2007 : Debug: modcall: entering group authorize for
request 4
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: calling eap
(rlm_eap) for request 4
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: EAP packet type response id
31 length 6
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: No EAP Start, assuming it's
an on-going EAP conversation
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: returned from
eap (rlm_eap) for request 4
Fri Nov  9 10:13:58 2007 : Debug:   modcall[authorize]: module "eap"
returns updated for request 4
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: calling files
(rlm_files) for request 4
Fri Nov  9 10:13:58 2007 : Debug:     users: Matched entry test88 at
line 89
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: returned from
files (rlm_files) for request 4
Fri Nov  9 10:13:58 2007 : Debug:   modcall[authorize]: module "files"
returns ok for request 4
Fri Nov  9 10:13:58 2007 : Debug: modcall: leaving group authorize
(returns updated) for request 4
Fri Nov  9 10:13:58 2007 : Debug:   rad_check_password:  Found Auth-Type
EAP
Fri Nov  9 10:13:58 2007 : Debug: auth: type "EAP"
Fri Nov  9 10:13:58 2007 : Debug:   Processing the authenticate section
of radiusd.conf
Fri Nov  9 10:13:58 2007 : Debug: modcall: entering group authenticate
for request 4
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authenticate]: calling eap
(rlm_eap) for request 4
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: Request found, released
from the list
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: EAP/ttls
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: processing type ttls
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_ttls: Authenticate
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: processing TLS
Fri Nov  9 10:13:58 2007 : Debug: rlm_eap_tls: Received EAP-TLS ACK
message
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: ack handshake fragment
handler
Fri Nov  9 10:13:58 2007 : Debug:   eaptls_verify returned 1 
Fri Nov  9 10:13:58 2007 : Debug:   eaptls_process returned 13 
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authenticate]: returned
from eap (rlm_eap) for request 4
Fri Nov  9 10:13:58 2007 : Debug:   modcall[authenticate]: module "eap"
returns handled for request 4
Fri Nov  9 10:13:58 2007 : Debug: modcall: leaving group authenticate
(returns handled) for request 4
Sending Access-Challenge of id 31 to 192.168.2.136 port 1067
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "88"
        EAP-Message =
0x0120040a15c00000112e0530030101ff301106096086480186f842010104040302010630090603551d1204023000302b06096086480186f842010d041e161c54696e7943412047656e657261746564204365727469666963617465301c0603551d11041530138111726f6f74406975742d6e696d65732e6672300e0603551d0f0101ff040403020106300d06092a864886f70d01010505000382020100a5ddc9c739f4bf4ab6816f961849875fbf26eafd3d78cfd8ff8a06a00cbf2d4b92b3be41e052c071f640c310cbbafc42a5272175cd1d57b9f29d7755c579caf68f18458043f16b3ee3205e158d6dbfe0f0c9a9b91e373aec65da6a7685a80167
        EAP-Message =
0xd82adf320568ed7f13f1c1a34077aaa26d2deb008ba7bdf5d7957f1e65edcad2999477968c4f4e2b19958b3b75a22ef87d21f22b82e0d552569d30ef005df0cf2ce51b1b5b9c0eb48154e0f018aefdca1ea1bacdf057cea2a665e0368619c6b9d2bbc594725154b5ad74edc538bf2e56c7166f589d405eca502618556d709662248e2a0aba8432f9d8c8608f9f29b8115a3c9ac9ae08e9411d27be1240e555dfdd2955e02094a2103aa2d4fa39fde98c81a2d384a7ee3bb9dbf5de186f1a9908ba17d8e73b1ea4fece4fd79bc45d426f18b7be65bbc0df7f6df3ab62f1f92ee720d97fcc4bba9faade8232939e1c9057723a6247a8b7e6f03aaf63a616
        EAP-Message =
0x17aab7b3c9d2f6a351f981f93941d027558b6a29df8685285dcc0ba6ca17e28d6bb404c30812210c7d6be30558d6b71117c71b1e5d5a80cc8b9b133255a0f92636f404bbba2f65301796e8360955dbe6958d763b7ff33faa1495e5b9ebef8ed10ca39c904f435bbfca79a772237cead4bac8881646996100477d03091fc5f4cce5db151dc02cdb8fb0d4a0d50c344bfe57871889f13cdab4b25981fc0c251ae672207e160301028d0c0002890040e54527309c69a6f9b14f9a455b74e4427a66dc3886a1ef826a7b7fbb07bd8b71470270e0758bb20446c948c11f0c49339127ff5e06397ee77242c0b6087a51ef000105004038a4729f66fc680faff0
        EAP-Message =
0xa67f4976b6c570ac9b4bf26d7329ad0146e1ff5c3504d49dda799a542cafac56169a986fde46e7a3ffc6a13bfcb488a224667cd6cd3602000b41100ff0622cc9c151c424d440d2d278f0458460f20449003f96f4a08e867139ddad96486227961650ef185141ee5e8476e961f363864c9f236efef0bb48d0002a26a1a99b3be10dce08d964fb66f65b3c65e0ccfe11329d08fd0ce9b3ad61f9deb161ac5ca91fad58bd1c42d34b62f67d20708d41e2b4c823c0e4a2172694401051b83a6d2a17b2a214f12430863673e9c58919531bc0d3317fef5445702c6fd5ab7065342bc01b6a0c25969a8b3ac7f43d4934ef90733ec6bc1718043e0d1c244e74e0
        EAP-Message = 0xa5e083696ef825244f59dd34a4b79eb36d2fde633883
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x59529d4d47264ff7047cff71020f5ad5
Fri Nov  9 10:13:58 2007 : Debug: Finished request 4
Fri Nov  9 10:13:58 2007 : Debug: Going to the next request
Fri Nov  9 10:13:58 2007 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.2.136:1067, id=32,
length=192
        Message-Authenticator = 0x81487325bd7145bec596503c0cdfa330
        Service-Type = Framed-User
        User-Name = "test88"
        Framed-MTU = 1488
        State = 0x59529d4d47264ff7047cff71020f5ad5
        Called-Station-Id = "00-18-6E-9A-49-40:eap"
        Calling-Station-Id = "00-16-6F-42-28-0F"
        NAS-Identifier = "3comeap"
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 54Mbps 802.11g"
        EAP-Message = 0x022000061500
        NAS-IP-Address = 192.168.2.136
        NAS-Port = 1
        NAS-Port-Id = "STA port # 1"
Fri Nov  9 10:13:58 2007 : Debug:   Processing the authorize section of
radiusd.conf
Fri Nov  9 10:13:58 2007 : Debug: modcall: entering group authorize for
request 5
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: calling eap
(rlm_eap) for request 5
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: EAP packet type response id
32 length 6
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: No EAP Start, assuming it's
an on-going EAP conversation
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: returned from
eap (rlm_eap) for request 5
Fri Nov  9 10:13:58 2007 : Debug:   modcall[authorize]: module "eap"
returns updated for request 5
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: calling files
(rlm_files) for request 5
Fri Nov  9 10:13:58 2007 : Debug:     users: Matched entry test88 at
line 89
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: returned from
files (rlm_files) for request 5
Fri Nov  9 10:13:58 2007 : Debug:   modcall[authorize]: module "files"
returns ok for request 5
Fri Nov  9 10:13:58 2007 : Debug: modcall: leaving group authorize
(returns updated) for request 5
Fri Nov  9 10:13:58 2007 : Debug:   rad_check_password:  Found Auth-Type
EAP
Fri Nov  9 10:13:58 2007 : Debug: auth: type "EAP"
Fri Nov  9 10:13:58 2007 : Debug:   Processing the authenticate section
of radiusd.conf
Fri Nov  9 10:13:58 2007 : Debug: modcall: entering group authenticate
for request 5
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authenticate]: calling eap
(rlm_eap) for request 5
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: Request found, released
from the list
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: EAP/ttls
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: processing type ttls
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_ttls: Authenticate
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: processing TLS
Fri Nov  9 10:13:58 2007 : Debug: rlm_eap_tls: Received EAP-TLS ACK
message
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: ack handshake fragment
handler
Fri Nov  9 10:13:58 2007 : Debug:   eaptls_verify returned 1 
Fri Nov  9 10:13:58 2007 : Debug:   eaptls_process returned 13 
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authenticate]: returned
from eap (rlm_eap) for request 5
Fri Nov  9 10:13:58 2007 : Debug:   modcall[authenticate]: module "eap"
returns handled for request 5
Fri Nov  9 10:13:58 2007 : Debug: modcall: leaving group authenticate
(returns handled) for request 5
Sending Access-Challenge of id 32 to 192.168.2.136 port 1067
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "88"
        EAP-Message =
0x0121013815800000112efa61a7eb64c36763345961c050a4deca07a623145ff7ed7191dd11faf05680c040a1b984deff6a9aff5e32fddaf367b168addfaa9bc900f58d125a4b6f7db814c635af55c017cee93ea04bf1f937c40b353a802fb2ea1cf955b5f2058429b8d9f1d09249bb51ea827213c2e63a23eb7ddfbbb15e16bc2a53e55b48e05d6d0af80edbbeb0ac2d1095738d621c7c2447f1b6714fdaf4d47b550f8ed6da0a532a3f3b23bc7ff06cccd25b7841ef0000f00ac6b96407589ca87bff317c6575050a745e7c4189c5f651581659b2f430b1c962fa168f31300616833c348c9096a19c3f11855a2202b08d86166fbacb025ffabfc54e77
        EAP-Message =
0x7a4bf8a5d15b1e5e6e45a60dd18b8b01ed6f8dc2c85b732b80b0c44bc91e9115288dba0456baac6ec5cd3bdd3069530a7fb216030100040e000000
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x2a1973f2f0e864b9d2daf9614a03dcfb
Fri Nov  9 10:13:58 2007 : Debug: Finished request 5
Fri Nov  9 10:13:58 2007 : Debug: Going to the next request
Fri Nov  9 10:13:58 2007 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.2.136:1067, id=33,
length=326
        Message-Authenticator = 0xb1bf1dd835788bdba02ca5c972c927d2
        Service-Type = Framed-User
        User-Name = "test88"
        Framed-MTU = 1488
        State = 0x2a1973f2f0e864b9d2daf9614a03dcfb
        Called-Station-Id = "00-18-6E-9A-49-40:eap"
        Calling-Station-Id = "00-16-6F-42-28-0F"
        NAS-Identifier = "3comeap"
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 54Mbps 802.11g"
        EAP-Message =
0x0221008c15001603010046100000420040a6844192dda9f96857f865018016aa092fb6bba52a05e2dea4121d9db1dfbb8174e5066d099c8017dd7b4541fa95baa9af034191f0e257c2557fbb32967da20514030100010116030100300a0e675a9c9f9bf4d193f71bed9f980f4f9ab0b2643ae52f7456f524200142d83e4e45e39421908c536e9d4464ed3208
        NAS-IP-Address = 192.168.2.136
        NAS-Port = 1
        NAS-Port-Id = "STA port # 1"
Fri Nov  9 10:13:58 2007 : Debug:   Processing the authorize section of
radiusd.conf
Fri Nov  9 10:13:58 2007 : Debug: modcall: entering group authorize for
request 6
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: calling eap
(rlm_eap) for request 6
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: EAP packet type response id
33 length 140
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: No EAP Start, assuming it's
an on-going EAP conversation
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: returned from
eap (rlm_eap) for request 6
Fri Nov  9 10:13:58 2007 : Debug:   modcall[authorize]: module "eap"
returns updated for request 6
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: calling files
(rlm_files) for request 6
Fri Nov  9 10:13:58 2007 : Debug:     users: Matched entry test88 at
line 89
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authorize]: returned from
files (rlm_files) for request 6
Fri Nov  9 10:13:58 2007 : Debug:   modcall[authorize]: module "files"
returns ok for request 6
Fri Nov  9 10:13:58 2007 : Debug: modcall: leaving group authorize
(returns updated) for request 6
Fri Nov  9 10:13:58 2007 : Debug:   rad_check_password:  Found Auth-Type
EAP
Fri Nov  9 10:13:58 2007 : Debug: auth: type "EAP"
Fri Nov  9 10:13:58 2007 : Debug:   Processing the authenticate section
of radiusd.conf
Fri Nov  9 10:13:58 2007 : Debug: modcall: entering group authenticate
for request 6
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authenticate]: calling eap
(rlm_eap) for request 6
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: Request found, released
from the list
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: EAP/ttls
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap: processing type ttls
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_ttls: Authenticate
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: processing TLS
Fri Nov  9 10:13:58 2007 : Debug:   eaptls_verify returned 7 
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: Done initial handshake
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: <<< TLS 1.0 Handshake
[length 0046], ClientKeyExchange  
Fri Nov  9 10:13:58 2007 : Debug:     TLS_accept: SSLv3 read client key
exchange A 
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: <<< TLS 1.0
ChangeCipherSpec [length 0001]  
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: <<< TLS 1.0 Handshake
[length 0010], Finished  
Fri Nov  9 10:13:58 2007 : Debug:     TLS_accept: SSLv3 read finished A 
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: >>> TLS 1.0
ChangeCipherSpec [length 0001]  
Fri Nov  9 10:13:58 2007 : Debug:     TLS_accept: SSLv3 write change
cipher spec A 
Fri Nov  9 10:13:58 2007 : Debug:   rlm_eap_tls: >>> TLS 1.0 Handshake
[length 0010], Finished  
Fri Nov  9 10:13:58 2007 : Debug:     TLS_accept: SSLv3 write finished
A 
Fri Nov  9 10:13:58 2007 : Debug:     TLS_accept: SSLv3 flush data 
Fri Nov  9 10:13:58 2007 : Debug:     (other): SSL negotiation finished
successfully 
Fri Nov  9 10:13:58 2007 : Error: rlm_eap: SSL error
error:00000000:lib(0):func(0):reason(0)
Fri Nov  9 10:13:58 2007 : Debug: SSL Connection Established 
Fri Nov  9 10:13:58 2007 : Debug:   eaptls_process returned 13 
Fri Nov  9 10:13:58 2007 : Debug:   modsingle[authenticate]: returned
from eap (rlm_eap) for request 6
Fri Nov  9 10:13:58 2007 : Debug:   modcall[authenticate]: module "eap"
returns handled for request 6
Fri Nov  9 10:13:58 2007 : Debug: modcall: leaving group authenticate
(returns handled) for request 6
Sending Access-Challenge of id 33 to 192.168.2.136 port 1067
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "88"
        EAP-Message =
0x0122004515800000003b1403010001011603010030748c180ed5aeb0c6cb5904d6ed1ecd99918e7483a9a9e7e813cc0b1cd40a5b8dbe30bca40912e85da1685ef09787b890
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xbd0bc2de964e06859f41e9de677beb32
Fri Nov  9 10:13:58 2007 : Debug: Finished request 6
Fri Nov  9 10:13:58 2007 : Debug: Going to the next request
Fri Nov  9 10:13:58 2007 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.2.136:1067, id=34,
length=298
        Message-Authenticator = 0xd1c723457a5b6ee40d31f56a8ef63066
        Service-Type = Framed-User
        User-Name = "test88"
        Framed-MTU = 1488
        State = 0xbd0bc2de964e06859f41e9de677beb32
        Called-Station-Id = "00-18-6E-9A-49-40:eap"
        Calling-Station-Id = "00-16-6F-42-28-0F"
        NAS-Identifier = "3comeap"
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 54Mbps 802.11g"
        EAP-Message =
0x022200701500170301002027428965475f2914dc59e2399ee15f4bd0c64242e54854ed7d30487b26f916541703010040247e769840abb023d2e402caf508eb2e79d7435cc9baad9249d3dd6cfb9e6f6f6a8291dcde57fabbdf84e72483a2ab1c7e8d3c84945d7c86243443c600330609
        NAS-IP-Address = 192.168.2.136
        NAS-Port = 1
        NAS-Port-Id = "STA port # 1"
Fri Nov  9 10:13:59 2007 : Debug:   Processing the authorize section of
radiusd.conf
Fri Nov  9 10:13:59 2007 : Debug: modcall: entering group authorize for
request 7
Fri Nov  9 10:13:59 2007 : Debug:   modsingle[authorize]: calling eap
(rlm_eap) for request 7
Fri Nov  9 10:13:59 2007 : Debug:   rlm_eap: EAP packet type response id
34 length 112
Fri Nov  9 10:13:59 2007 : Debug:   rlm_eap: No EAP Start, assuming it's
an on-going EAP conversation
Fri Nov  9 10:13:59 2007 : Debug:   modsingle[authorize]: returned from
eap (rlm_eap) for request 7
Fri Nov  9 10:13:59 2007 : Debug:   modcall[authorize]: module "eap"
returns updated for request 7
Fri Nov  9 10:13:59 2007 : Debug:   modsingle[authorize]: calling files
(rlm_files) for request 7
Fri Nov  9 10:13:59 2007 : Debug:     users: Matched entry test88 at
line 89
Fri Nov  9 10:13:59 2007 : Debug:   modsingle[authorize]: returned from
files (rlm_files) for request 7
Fri Nov  9 10:13:59 2007 : Debug:   modcall[authorize]: module "files"
returns ok for request 7
Fri Nov  9 10:13:59 2007 : Debug: modcall: leaving group authorize
(returns updated) for request 7
Fri Nov  9 10:13:59 2007 : Debug:   rad_check_password:  Found Auth-Type
EAP
Fri Nov  9 10:13:59 2007 : Debug: auth: type "EAP"
Fri Nov  9 10:13:59 2007 : Debug:   Processing the authenticate section
of radiusd.conf
Fri Nov  9 10:13:59 2007 : Debug: modcall: entering group authenticate
for request 7
Fri Nov  9 10:13:59 2007 : Debug:   modsingle[authenticate]: calling eap
(rlm_eap) for request 7
Fri Nov  9 10:13:59 2007 : Debug:   rlm_eap: Request found, released
from the list
Fri Nov  9 10:13:59 2007 : Debug:   rlm_eap: EAP/ttls
Fri Nov  9 10:13:59 2007 : Debug:   rlm_eap: processing type ttls
Fri Nov  9 10:13:59 2007 : Debug:   rlm_eap_ttls: Authenticate
Fri Nov  9 10:13:59 2007 : Debug:   rlm_eap_tls: processing TLS
Fri Nov  9 10:13:59 2007 : Debug:   eaptls_verify returned 7 
Fri Nov  9 10:13:59 2007 : Debug:   rlm_eap_tls: Done initial handshake
Fri Nov  9 10:13:59 2007 : Debug:   eaptls_process returned 7 
Fri Nov  9 10:13:59 2007 : Debug:   rlm_eap_ttls: Session established.
Proceeding to decode tunneled attributes.
  TTLS tunnel data in 0000: 00 00 00 01 40 00 00 0e 74 65 73 74 38 38 00
00 
  TTLS tunnel data in 0010: 00 00 00 02 40 00 00 18 70 61 73 73 74 65 73
74 
  TTLS tunnel data in 0020: 38 38 00 00 00 00 00 00 
  TTLS: Got tunneled request
        User-Name = "test88"
        User-Password = "passtest88"
        FreeRADIUS-Proxied-To = 127.0.0.1
  TTLS: Sending tunneled request
        User-Name = "test88"
        User-Password = "passtest88"
        FreeRADIUS-Proxied-To = 127.0.0.1
        Service-Type = Framed-User
        Framed-MTU = 1488
        Called-Station-Id = "00-18-6E-9A-49-40:eap"
        Calling-Station-Id = "00-16-6F-42-28-0F"
        NAS-Identifier = "3comeap"
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 54Mbps 802.11g"
        NAS-IP-Address = 192.168.2.136
        NAS-Port = 1
        NAS-Port-Id = "STA port # 1"
Fri Nov  9 10:13:59 2007 : Debug:   Processing the authorize section of
radiusd.conf
Fri Nov  9 10:13:59 2007 : Debug: modcall: entering group authorize for
request 7
Fri Nov  9 10:13:59 2007 : Debug:   modsingle[authorize]: calling eap
(rlm_eap) for request 7
Fri Nov  9 10:13:59 2007 : Debug:   rlm_eap: No EAP-Message, not doing
EAP
Fri Nov  9 10:13:59 2007 : Debug:   modsingle[authorize]: returned from
eap (rlm_eap) for request 7
Fri Nov  9 10:13:59 2007 : Debug:   modcall[authorize]: module "eap"
returns noop for request 7
Fri Nov  9 10:13:59 2007 : Debug:   modsingle[authorize]: calling files
(rlm_files) for request 7
Fri Nov  9 10:13:59 2007 : Debug:     users: Matched entry test88 at
line 89
Fri Nov  9 10:13:59 2007 : Debug:   modsingle[authorize]: returned from
files (rlm_files) for request 7
Fri Nov  9 10:13:59 2007 : Debug:   modcall[authorize]: module "files"
returns ok for request 7
Fri Nov  9 10:13:59 2007 : Debug: modcall: leaving group authorize
(returns ok) for request 7
Fri Nov  9 10:13:59 2007 : Debug: auth: type Local
Fri Nov  9 10:13:59 2007 : Debug: auth: user supplied User-Password
matches local User-Password
  TTLS: Got tunneled reply RADIUS code 2
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "88"
Fri Nov  9 10:13:59 2007 : Debug:   TTLS: Got tunneled Access-Accept
Fri Nov  9 10:13:59 2007 : Debug:   rlm_eap: Freeing handler
Fri Nov  9 10:13:59 2007 : Debug:   modsingle[authenticate]: returned
from eap (rlm_eap) for request 7
Fri Nov  9 10:13:59 2007 : Debug:   modcall[authenticate]: module "eap"
returns ok for request 7
Fri Nov  9 10:13:59 2007 : Debug: modcall: leaving group authenticate
(returns ok) for request 7
Sending Access-Accept of id 34 to 192.168.2.136 port 1067
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "88"
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "88"
        MS-MPPE-Recv-Key =
0x9532a94e83def6d946f8fad11fdd6ffba23fa797a90c77c6369f326b9580839e
        MS-MPPE-Send-Key =
0xa1d35c5041047126400a7226508b58e7fc889813ec39139b4ff3d58eec13f86d
        EAP-Message = 0x03220004
        Message-Authenticator = 0x00000000000000000000000000000000
        User-Name = "test88"
Fri Nov  9 10:13:59 2007 : Debug: Finished request 7
Fri Nov  9 10:13:59 2007 : Debug: Going to the next request
Fri Nov  9 10:13:59 2007 : Debug: --- Walking the entire request list
---
Fri Nov  9 10:13:59 2007 : Debug: Waking up in 5 seconds...
Fri Nov  9 10:14:04 2007 : Debug: --- Walking the entire request list
---
Fri Nov  9 10:14:04 2007 : Debug: Cleaning up request 0 ID 27 with
timestamp 473424d6
Fri Nov  9 10:14:04 2007 : Debug: Cleaning up request 1 ID 28 with
timestamp 473424d6
Fri Nov  9 10:14:04 2007 : Debug: Cleaning up request 2 ID 29 with
timestamp 473424d6
Fri Nov  9 10:14:04 2007 : Debug: Cleaning up request 3 ID 30 with
timestamp 473424d6
Fri Nov  9 10:14:04 2007 : Debug: Cleaning up request 4 ID 31 with
timestamp 473424d6
Fri Nov  9 10:14:04 2007 : Debug: Cleaning up request 5 ID 32 with
timestamp 473424d6
Fri Nov  9 10:14:04 2007 : Debug: Cleaning up request 6 ID 33 with
timestamp 473424d6
Fri Nov  9 10:14:04 2007 : Debug: Waking up in 1 seconds...
Fri Nov  9 10:14:05 2007 : Debug: --- Walking the entire request list
---
Fri Nov  9 10:14:05 2007 : Debug: Cleaning up request 7 ID 34 with
timestamp 473424d7
Fri Nov  9 10:14:05 2007 : Debug: Nothing to do.  Sleeping until we see
a request.

DEBUG WPA SUPLLICANT  wpa_supplicant -d -i "eth2" -D "wext"
-c /etc/wpa_supplicant/wpa_supplicant.conf > debug.txt

Initializing interface 'eth2' conf
'/etc/wpa_supplicant/wpa_supplicant.conf' driver 'wext' ctrl_interface
'N/A' bridge 'N/A'
Configuration file '/etc/wpa_supplicant/wpa_supplicant.conf' ->
'/etc/wpa_supplicant/wpa_supplicant.conf'
Reading configuration file '/etc/wpa_supplicant/wpa_supplicant.conf'
ctrl_interface='/var/run/wpa_supplicant'
Priority group 0
   id=0 ssid='sjp'
   id=1 ssid='eap'
Initializing interface (2) 'eth2'
EAPOL: SUPP_PAE entering state DISCONNECTED
EAPOL: KEY_RX entering state NO_KEY_RECEIVE
EAPOL: SUPP_BE entering state INITIALIZE
EAP: EAP entering state DISABLED
EAPOL: External notification - portEnabled=0
EAPOL: External notification - portValid=0
SIOCGIWRANGE: WE(compiled)=20 WE(source)=18 enc_capa=0xf
  capabilities: key_mgmt 0xf enc 0xf
WEXT: Operstate: linkmode=1, operstate=5
Own MAC address: 00:16:6f:42:28:0f
wpa_driver_wext_set_wpa
wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_countermeasures
wpa_driver_wext_set_drop_unencrypted
Setting scan request: 0 sec 100000 usec
Added interface eth2
RTM_NEWLINK: operstate=0 ifi_flags=0x1002 ()
Wireless event: cmd=0x8b06 len=8
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'eth2' added
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'eth2' added
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
Wireless event: cmd=0x8b19 len=8
Received 840 bytes of scan results (3 BSSes)
Scan results: 3
Selecting BSS from priority group 0
0: 00:18:6e:9a:49:40 ssid='eap' wpa_ie_len=24 rsn_ie_len=22 caps=0x11
   skip - SSID mismatch
   selected based on WPA IE
Trying to associate with 00:18:6e:9a:49:40 (SSID='eap' freq=0 MHz)
Cancelling scan request
WPA: clearing own WPA/RSN IE
Automatic auth_alg selection: 0x1
WPA: using IEEE 802.11i/D3.0
WPA: Selected cipher suites: group 8 pairwise 8 key_mgmt 1 proto 1
WPA: set AP WPA IE - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2
02 01 00 00 50 f2 02 01 00 00 50 f2 01
WPA: set AP RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 02 01 00 00
0f ac 02 01 00 00 0f ac 01 01 00
WPA: using GTK TKIP
WPA: using PTK TKIP
WPA: using KEY_MGMT 802.1X
WPA: Set own WPA IE default - hexdump(len=24): dd 16 00 50 f2 01 01 00
00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 01
No keys have been configured - skip key clearing
wpa_driver_wext_set_drop_unencrypted
State: DISCONNECTED -> ASSOCIATING
wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
WEXT: Operstate: linkmode=-1, operstate=5
wpa_driver_wext_associate
Setting authentication timeout: 10 sec 0 usec
EAPOL: External notification - portControl=Auto
RSN: added PMKSA cache candidate 00:18:6e:9a:49:40 prio 1000
RSN: processing PMKSA candidate list
RSN: not in suitable state for new pre-authentication
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
Wireless event: cmd=0x8b06 len=8
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
Wireless event: cmd=0x8b1a len=12
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
Wireless event: cmd=0x8b15 len=20
Wireless event: new AP: 00:18:6e:9a:49:40
State: ASSOCIATING -> ASSOCIATED
wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
WEXT: Operstate: linkmode=-1, operstate=5
Associated to a new BSS: BSSID=00:18:6e:9a:49:40
No keys have been configured - skip key clearing
Associated with 00:18:6e:9a:49:40
WPA: Association event - clear replay counter
EAPOL: External notification - portEnabled=0
EAPOL: External notification - portValid=0
EAPOL: External notification - portEnabled=1
EAPOL: SUPP_PAE entering state CONNECTING
EAPOL: SUPP_BE entering state IDLE
EAP: EAP entering state INITIALIZE
EAP: EAP entering state IDLE
Setting authentication timeout: 10 sec 0 usec
Cancelling scan request
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'eth2' added
EAPOL: startWhen --> 0
EAPOL: SUPP_PAE entering state CONNECTING
EAPOL: txStart
RX EAPOL from 00:18:6e:9a:49:40
Setting authentication timeout: 70 sec 0 usec
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_PAE entering state RESTART
EAP: EAP entering state INITIALIZE
EAP: EAP entering state IDLE
EAPOL: SUPP_PAE entering state AUTHENTICATING
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request id=27 method=1 vendor=0 vendorMethod=0
EAP: EAP entering state IDENTITY
CTRL-EVENT-EAP-STARTED EAP authentication started
EAP: EAP-Request Identity data - hexdump_ascii(len=0):
EAP: using anonymous identity - hexdump_ascii(len=6):
     74 65 73 74 38 38                                 test88          
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:18:6e:9a:49:40
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request id=28 method=21 vendor=0 vendorMethod=0
EAP: EAP entering state GET_METHOD
EAP: Initialize selected EAP method: vendor 0 method 21 (TTLS)
EAP-TTLS: Phase2 type: PAP
CTRL-EVENT-EAP-METHOD EAP vendor 0 method 21 (TTLS) selected
EAP: EAP entering state METHOD
SSL: Received packet(len=6) - Flags 0x20
EAP-TTLS: Start (server ver=0, own ver=0)
EAP-TTLS: Using TTLS version 0
TLS: Trusted root certificate(s) loaded
EAP-TTLS: Start
SSL: (where=0x10 ret=0x1)
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:before/connect initialization
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 write client hello A
SSL: (where=0x1002 ret=0xffffffff)
SSL: SSL_connect:error in SSLv3 read server hello A
SSL: SSL_connect - want more data
SSL: 87 bytes pending from ssl_out
SSL: 87 bytes left to be sent out (of total 87 bytes)
EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:18:6e:9a:49:40
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request id=29 method=21 vendor=0 vendorMethod=0
EAP: EAP entering state METHOD
SSL: Received packet(len=1034) - Flags 0xc0
SSL: TLS Message Length: 4398
SSL: Need 3374 bytes more input data
SSL: Building ACK
EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:18:6e:9a:49:40
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request id=30 method=21 vendor=0 vendorMethod=0
EAP: EAP entering state METHOD
SSL: Received packet(len=1034) - Flags 0xc0
SSL: TLS Message Length: 4398
SSL: Need 2350 bytes more input data
SSL: Building ACK
EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:18:6e:9a:49:40
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request id=31 method=21 vendor=0 vendorMethod=0
EAP: EAP entering state METHOD
SSL: Received packet(len=1034) - Flags 0xc0
SSL: TLS Message Length: 4398
SSL: Need 1326 bytes more input data
SSL: Building ACK
EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:18:6e:9a:49:40
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request id=32 method=21 vendor=0 vendorMethod=0
EAP: EAP entering state METHOD
SSL: Received packet(len=1034) - Flags 0xc0
SSL: TLS Message Length: 4398
SSL: Need 302 bytes more input data
SSL: Building ACK
EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:18:6e:9a:49:40
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request id=33 method=21 vendor=0 vendorMethod=0
EAP: EAP entering state METHOD
SSL: Received packet(len=312) - Flags 0x80
SSL: TLS Message Length: 4398
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 read server hello A
TLS: tls_verify_cb - preverify_ok=1 err=0 (ok) depth=1
buf='/C=FR/ST=France/L=Nimes/O=IUT/OU=IUT_RAD/CN=racine_radius_ca/emailAddress=root@iut-nimes.fr'
TLS: tls_verify_cb - preverify_ok=1 err=0 (ok) depth=0
buf='/C=FR/ST=France/L=Nimes/O=IUT/OU=IUT_RAD/CN=radius.iut-nimes.fr/emailAddress=root@iut-nimes.fr'
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 read server certificate A
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 read server key exchange A
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 read server done A
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 write client key exchange A
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 write change cipher spec A
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 write finished A
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 flush data
SSL: (where=0x1002 ret=0xffffffff)
SSL: SSL_connect:error in SSLv3 read finished A
SSL: SSL_connect - want more data
SSL: 134 bytes pending from ssl_out
SSL: 134 bytes left to be sent out (of total 134 bytes)
EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:18:6e:9a:49:40
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request id=34 method=21 vendor=0 vendorMethod=0
EAP: EAP entering state METHOD
SSL: Received packet(len=69) - Flags 0x80
SSL: TLS Message Length: 59
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 read finished A
SSL: (where=0x20 ret=0x1)
SSL: (where=0x1002 ret=0x1)
SSL: 0 bytes pending from ssl_out
OpenSSL: tls_connection_handshake - Failed to read possible Application
Data error:00000000:lib(0):func(0):reason(0)
SSL: No data to be sent out
EAP-TTLS: TLS done, proceed to Phase 2
EAP-TTLS: Derived key - hexdump(len=64): [REMOVED]
EAP-TTLS: received 0 bytes encrypted data for Phase 2
EAP-TTLS: empty data in beginning of Phase 2 - use fake EAP-Request
Identity
EAP-TTLS: Phase 2 PAP Request
EAP-TTLS: Encrypting Phase 2 data - hexdump(len=40): [REMOVED]
EAP-TTLS: Authentication completed successfully
EAP: method process -> ignore=FALSE methodState=DONE decision=COND_SUCC
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:18:6e:9a:49:40
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Success
EAP: EAP entering state SUCCESS
CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully
EAPOL: SUPP_BE entering state RECEIVE
EAPOL: SUPP_BE entering state SUCCESS
EAPOL: SUPP_BE entering state IDLE
RX EAPOL from 00:18:6e:9a:49:40
EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
IEEE 802.1X RX: version=1 type=3 length=95
  EAPOL-Key type=254
  key_info 0x89 (ver=1 keyidx=0 rsvd=0 Pairwise Ack)
  key_length=32 key_data_length=0
  replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 0e
  key_nonce - hexdump(len=32): ba 6d 7a 29 4b fb ae e3 0c 72 31 b1 7c 86
8f bc d8 ec fb cc 17 7e fd 63 c6 d4 30 db 95 82 bc e3
  key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00
  key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00
State: ASSOCIATED -> 4WAY_HANDSHAKE
WPA: RX message 1 of 4-Way Handshake from 00:18:6e:9a:49:40 (ver=1)
WPA: PMK from EAPOL state machines - hexdump(len=32): [REMOVED]
WPA: Renewed SNonce - hexdump(len=32): b4 b6 69 9a 88 23 e3 6a e5 b9 aa
6a 1a 96 bd 52 a3 11 39 5b ff 8a f6 74 9e 1a 96 ab 62 f2 3b f7
WPA: PMK - hexdump(len=32): [REMOVED]
WPA: PTK - hexdump(len=64): [REMOVED]
WPA: WPA IE for msg 2/4 - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50
f2 02 01 00 00 50 f2 02 01 00 00 50 f2 01
WPA: Sending EAPOL-Key 2/4
RX EAPOL from 00:18:6e:9a:49:40
EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
IEEE 802.1X RX: version=1 type=3 length=119
  EAPOL-Key type=254
  key_info 0x1c9 (ver=1 keyidx=0 rsvd=0 Pairwise Install Ack MIC)
  key_length=32 key_data_length=24
  replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 0f
  key_nonce - hexdump(len=32): ba 6d 7a 29 4b fb ae e3 0c 72 31 b1 7c 86
8f bc d8 ec fb cc 17 7e fd 63 c6 d4 30 db 95 82 bc e3
  key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00
  key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_mic - hexdump(len=16): bf e3 38 d7 41 93 34 33 55 f7 ce 50 14 2e
b1 fd
State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
WPA: RX message 3 of 4-Way Handshake from 00:18:6e:9a:49:40 (ver=1)
WPA: IE KeyData - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02
01 00 00 50 f2 02 01 00 00 50 f2 01
WPA: Sending EAPOL-Key 4/4
WPA: Installing PTK to the driver.
WPA: RSC - hexdump(len=6): 00 00 00 00 00 00
wpa_driver_wext_set_key: alg=2 key_idx=0 set_tx=1 seq_len=6 key_len=32
State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
RX EAPOL from 00:18:6e:9a:49:40
EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
IEEE 802.1X RX: version=1 type=3 length=127
  EAPOL-Key type=254
  key_info 0x3b1 (ver=1 keyidx=3 rsvd=0 Group Ack MIC Secure)
  key_length=32 key_data_length=32
  replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 10
  key_nonce - hexdump(len=32): f7 a5 9a e3 ed 43 f9 e7 85 c8 66 d7 e3 fe
58 38 5d ca 2d 88 38 7d 89 22 67 b4 8a 06 6c fe cd b8
  key_iv - hexdump(len=16): 3c f1 ff 2b 28 05 c6 a5 f0 6f 67 d8 e7 a7 fa
92
  key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_mic - hexdump(len=16): 82 79 18 3f fe 79 21 09 81 1e 1b 89 89 8d
9f d5
WPA: RX message 1 of Group Key or STAKey Handshake from
00:18:6e:9a:49:40 (ver=1)
State: GROUP_HANDSHAKE -> GROUP_HANDSHAKE
WPA: Group Key - hexdump(len=32): [REMOVED]
WPA: Installing GTK to the driver (keyidx=3 tx=0).
WPA: RSC - hexdump(len=6): 00 00 00 00 00 00
wpa_driver_wext_set_key: alg=2 key_idx=3 set_tx=0 seq_len=6 key_len=32
WPA: Sending EAPOL-Key 2/2
WPA: Key negotiation completed with 00:18:6e:9a:49:40 [PTK=TKIP
GTK=TKIP]
Cancelling authentication timeout
State: GROUP_HANDSHAKE -> COMPLETED
CTRL-EVENT-CONNECTED - Connection to 00:18:6e:9a:49:40 completed (auth)
[id=1 id_str=]
wpa_driver_wext_set_operstate: operstate 0->1 (UP)
WEXT: Operstate: linkmode=-1, operstate=6
EAPOL: External notification - portValid=1
EAPOL: SUPP_PAE entering state AUTHENTICATED
RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'eth2' added
RSN: processing PMKSA candidate list
RSN: not in suitable state for new pre-authentication
EAPOL: startWhen --> 0
CTRL-EVENT-TERMINATING - signal 2 received
Removing interface eth2
State: COMPLETED -> DISCONNECTED
wpa_driver_wext_set_operstate: operstate 1->0 (DORMANT)
WEXT: Operstate: linkmode=-1, operstate=5
wpa_driver_wext_deauthenticate
wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
EAPOL: External notification - portEnabled=0
EAPOL: SUPP_PAE entering state DISCONNECTED
EAPOL: SUPP_BE entering state INITIALIZE
EAP: EAP entering state DISABLED
EAPOL: External notification - portValid=0
wpa_driver_wext_set_wpa
wpa_driver_wext_set_drop_unencrypted
wpa_driver_wext_set_countermeasures
No keys have been configured - skip key clearing
WEXT: Operstate: linkmode=0, operstate=6
EAP: deinitialize previously used EAP method (21, TTLS) at EAP deinit
ENGINE: engine deinit
Cancelling scan request

dhcp ttls 3com 7760

Jouvenel Jean-Pierre