Does the device support dynamic VLAN assigment via radius? The fact that you are sending VLAN attributes to the AP doesn't mean that it will understand them. Ivan Kalik Kalik Informatika ISP Dana 9/11/2007, "Jouvenel Jean-Pierre" <jouvenel@iut-nimes.fr> piše:
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
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html