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