- Freeradius-Users - lists.freeradius.org

Re: 2 different authorization?
by Evgeney Bakhtin 18 Feb '08

18 Feb '08

Hello, I just need to configure FreeRadius to manage auth & acct for 2 different users too. I have create 2 instances of the sql module, in my sql.conf: sql instance1 { ... } sql instance2 { ... } But I don't understand how and where I can use this instances. In radiusd.conf I have: [authorize] { ... instance1 ... } [accounting] { ... instance1 ... } Where I need to indicate different sql instances for different users? Regards, Evgeney Bakhtin.

1 0

Wifi and Client-Side authentication
by Bill Farina 18 Feb '08

18 Feb '08

Here's the scenario, I have a Linksys WRT54GS running DD-WRT RC5 which is fully configured for Radius. I have a small FreeBSD server running FreeRadius-1.1.7_2. HTTPD (or Apache) has not been installed on the system and in it's current configuration would be difficult to do so. The BSD box is also running PAP which makes it very easy to configure accounts and it's a account creation method that I'm familiar and comfortable with. The two machines are currently communicating. What I'm trying to do is figure out a way that I can authenticate enduser machines using this setup. What I would like to see is upon the initial login attempt, a popup comes up and asks for username and password. From that point on, everything would be automatic on the user-side and individual client machines would store all of the login information. I'm not opposed to adding software to client machines to facilitate the login.

3 2

rlm_python & freeradiusd 2.0.2
by Alexander Demidoff 17 Feb '08

17 Feb '08

Hello all! I want to use python possibilities to authorize users with freeradius. So, I compiled freeradius with options: --with-experimental-modules \ --with-rlm_python created config files and my pythom module "radiusd_isp", put it python path freeradius -X out me: python { mod_instantiate = "radiusd_isp" func_instantiate = "instantiate" mod_authorize = "radiusd_isp" func_authorize = "authorize" mod_authenticate = "radiusd_isp" func_authenticate = "authenticate" mod_preacct = "radiusd_isp" func_preacct = "preacct" mod_accounting = "radiusd_isp" func_accounting = "accounting" mod_detach = "radiusd_isp" func_detach = "detach" } exceptions.ImportError: No module named radiusd_isp Failed to import python module "radiusd_isp" /etc/freeradius/python.conf[32]: Instantiation failed for module "python" /etc/freeradius/radiusd.conf[1824]: Failed to find module "python". /etc/freeradius/radiusd.conf[1793]: Errors parsing authorize section. help me anybody, please !?

3 5

one username and 2 NAS
by enrico fanti 16 Feb '08

16 Feb '08

Hi , I have freeradius configured with Mysql. I would like to have a user can ssh login to 2 server linux (i.e. 2 NAS , same username). Freeradius must make the control if NAS-IP Address is ok for this user in the radcheck table.. I use the "==" operator end my radcheck table is: mysql> SELECT id, UserName, Attribute, Value, op from radcheck WHERE Username = 'pippo' order by id; +----+----------+----------------+---------------+----+ | id | UserName | Attribute | Value | op | +----+----------+----------------+---------------+----+ | 39 | pippo | NAS-IP-Address | 10.0.0.52 | == | | 40 | pippo | NAS-IP-Address | 10.0.0.49 | == | | 41 | pippo | Expiration | 1203325200 | == | | 42 | pippo | Crypt-Password | v7fawImvQUoXM | == | +----+----------+----------------+---------------+----+ It doesn't work...... Some ideas ??? Thank you Enrico

3 2

Could not link driver rlm_sql_mysql.so
by johnson elangbam 15 Feb '08

15 Feb '08

hi, I couldn't be able to link the driver of mysql 5 with free radius 2.0.2due to this file "rlm_sql_mysql.so". I couldn't locate this file in my entire system. I've gone througe all the faq's, but it doesn't work. the error's still there. The errors look like this. rlm_sql (sql): Could not link driver rlm_sql_mysql: rlm_sql_mysql.so: cannot open shared object file: No such file or directory rlm_sql (sql): Make sure it (and all its dependent libraries!) are in the search path of your system's ld. /usr/local/etc/raddb/sql.conf[22]: Instantiation failed for module "sql" /usr/local/etc/raddb/sites-enabled/default[124]: Failed to find module "sql". /usr/local/etc/raddb/sites-enabled/default[34]: Errors parsing authorize section. With Regards Elangbam Johnson

4 3

Non capturing parenthesis in regexp causes seg fault.
by Arran Cudbard-Bell 15 Feb '08

15 Feb '08

Hi, Got this on my 32bit intel box running Ubuntu Linux 6.10 if("%{User-Name}" =~ /(?:.*)/){ } --- ++? if ("%{User-Name}" =~ /(?:.*)/) expand: %{User-Name} -> anonymous Program received signal SIGSEGV, Segmentation fault. [Switching to Thread -1213196608 (LWP 6433)] 0xb7bc9492 in regexec () from /lib/tls/i686/cmov/libc.so.6 (gdb) bt #0 0xb7bc9492 in regexec () from /lib/tls/i686/cmov/libc.so.6 #1 0x0806d6a9 in ?? () #2 0xbfb2e650 in ?? () #3 0xbfb2ee84 in ?? () #4 0x00000009 in ?? () #5 0xbfb2e608 in ?? () #6 0x00000000 in ?? () Normal expressions work fine. Thanks, Arran -- Arran Cudbard-Bell (A.Cudbard-Bell(a)sussex.ac.uk) Authentication, Authorisation and Accounting Officer Infrastructure Services | ENG1 E1-1-08 University Of Sussex, Brighton EXT:01273 873900 | INT: 3900

2 4

Acct-Authentic & changing usernames
by Phil Mayers 15 Feb '08

15 Feb '08

We're bringing a Cisco (formerly Airespace) lightweight wireless system online, and I'm seeing some odd things in the accounting. Specifically, the usernames can change in the accounting packets. This causes the default SQL queries (at least, the ones for Postgres under 1.1.7) to generate duplicate entries for the session, because the "where" clause includes the username. For example, I might see this: User-Name = "unknown" NAS-Port = 29 NAS-IP-Address = 172.16.x.x Framed-IP-Address = 192.168.x.x NAS-Identifier = "wlan-wism-1-1" Airespace-Wlan-Id = 2 Acct-Session-Id = "47b3193c/00:aa:bb:cc:dd:ee/5746" Acct-Authentic = Remote Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3602" Acct-Status-Type = Start Calling-Station-Id = "00:aa:bb:cc:dd:ee" Called-Station-Id = "00:1b:d5:08:01:00" ...then a few seconds later User-Name = "THEUSER" NAS-Port = 29 NAS-IP-Address = 172.16.x.x Framed-IP-Address = 192.168.x.x NAS-Identifier = "wlan-wism-1-1" Airespace-Wlan-Id = 2 Acct-Session-Id = "47b3193c/00:aa:bb:cc:dd:ee/5746" Acct-Authentic = RADIUS Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3602" Acct-Status-Type = Interim-Update Acct-Input-Octets = 105078 Acct-Output-Octets = 72551 Acct-Input-Packets = 754 Acct-Output-Packets = 300 Acct-Session-Time = 74 Acct-Delay-Time = 0 Calling-Station-Id = "00:aa:bb:cc:dd:ee" Called-Station-Id = "00:1b:d5:08:01:00" If the user is on e.g. a windows XP laptop and logs out, I might finally see: User-Name = "host/thelaptop.domain.com" NAS-Port = 29 NAS-IP-Address = 172.16.x.x Framed-IP-Address = 192.168.x.x NAS-Identifier = "wlan-wism-1-1" Airespace-Wlan-Id = 2 Acct-Session-Id = "47b3193c/00:aa:bb:cc:dd:ee/5746" Acct-Authentic = Remote Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "3602" Acct-Status-Type = Stop Acct-Input-Octets = 1852445 Acct-Output-Octets = 5401691 Acct-Input-Packets = 17608 Acct-Output-Packets = 8630 Acct-Terminate-Cause = User-Request Acct-Session-Time = 30517 Acct-Delay-Time = 0 Calling-Station-Id = "00:aa:bb:cc:dd:ee" Called-Station-Id = "00:1b:d5:08:01:00" It seems the NAS is having a changing view of the authentication username as various events take place, presumably at the EAPOL layer. However it seems to consistently set Acct-Authentic to RADIUS for "real" usernames, and "Remote" for unknown or non-authenticated usernames, so it sort of "knows" this is happening. Now the Cisco WLC (nee Airespace) is a weird bit of kit anyway; it sort of "holds onto" client sessions in case they come back shortly (not unusual for wireless) but I'm wondering if this behaviour is legal, sane or what? I can probably fix our SQL queries, but I thought people might be interested; for interest, what was the original rationale behind the where clause in the default SQL queries: where username='%{SQL-User-Name}' ??

3 3

Re: Re: can't get WPA/2 and EAP-TTLS to work
by David Mitton 15 Feb '08

15 Feb '08

1 0

Re: can't get WPA/2 and EAP-TTLS to work
by William Bulley 15 Feb '08

15 Feb '08

According to A.L.M.Buxey(a)lboro.ac.uk: > > from what i can see, rubbish. freeradius as an AAA does not > ask NAs about their VLANs - dynamic or otherwise! there a re > few things wonky or wrong. I didn't think Cisco's VLAN concept was accurate, but I couldn't expect them to know anything about FreeRADIUS... > first , what version of FR are you using exactly? i would STRONGLY > recommend 2.0.2 as 1.1.x (you appear to be 1.1.7 with patches...) > isnt as configurable. I have been following that thread on the list here, and am in the process up upgrading my FreeBSD ports _INCLUDING_ FreeRADIUS, but the 2.0.2 version is not in the FreeBSD ports tree yet (as of 2/14). > secondly > > > foo User-Password == "password" > > foo Cleartext-Password := "password" > > (as clearly in the docs) And just as clearly, I missed that one - yep, thanks. > > Thu Feb 14 08:41:05 2008 : Debug: rlm_eap_tls: add_reply failed to create attribute MS-MPPE-Recv-Key: Unknown attribute > > "MS-MPPE-Recv-Key" > > Thu Feb 14 08:41:05 2008 : Debug: rlm_eap_tls: add_reply failed to create attribute MS-MPPE-Send-Key: Unknown attribute > > "MS-MPPE-Send-Key" > > this aint good. you've got to have these in your TTLS or things arent > going to work. dictionary files all okay and present and loaded? > you arent filtering attributes from my quick scan of the config...unless > you've not copied that part. I commented out the Micro$loth dictionary since I wasn't using anything from Redmond in this setup. I will uncomment this and see what happens. Thanks for all your help. Regards, web... -- William Bulley Email: web(a)umich.edu

1 0

can't get WPA/2 and EAP-TTLS to work
by William Bulley 15 Feb '08

15 Feb '08

The wpa_supplicant keeps looping looking for missing keys accordint to Jouni. I suspected my Cisco access point was not configured properly, but Cisco claims that FreeRADIUS is asking the access point about dynamic VLANs which aren't even configured in FreeRADIUS (see configurations below). +-----------------------------------+ | ThinkPad T42 with D-Link DWL-G660 | | (ath0) on FreeBSD 6.2-STABLE | | running wpa_supplicant 0.4.8 | +-----------------------------------+ ^ 802.1X | WPA/2 EAP-TTLS v +---------------------------------------+ | Cisco 1131AG 802.11a/b/g AP IOS 12.4 | +---------------------------------------+ ^ EAP-TTLS | RADIUS v +-----------------------------------+ | FreeRADIUS 1.1.7_2 on FreeBSD 7.0 | +-----------------------------------+ It almost works in that authentication succeeds (see debug log file output), but the complete 802.1x connection does not succeed, hence the looping behaviour... =*=*=*=*=*=*=*=*=*= wpa_supplicant.conf =*=*=*=*=*=*=*=*=*=*=*=*= ctrl_interface=/var/run/wpa_supplicant ctrl_interface_group=0 network={ ssid="testing" bssid=00:xx:yy:yy:zz:zz proto=RSN key_mgmt=WPA-EAP eap=TTLS anonymous_identity="anonymous" identity="foo" password="password" phase2="auth=MD5" } =*=*=*=*=*=*=*=*=*= FreeRADIUS eap.conf =*=*=*=*=*=*=*=*=*=*=*= eap { default_eap_type = ttls timer_expire = 60 ignore_unknown_eap_types = no cisco_accounting_username_bug = yes md5 { } tls { private_key_password = whatever private_key_file = ${raddbdir}/certs/cert-srv.pem certificate_file = ${raddbdir}/certs/cert-srv.pem CA_file = ${raddbdir}/certs/demoCA/cacert.pem dh_file = ${raddbdir}/certs/dh random_file = ${raddbdir}/certs/random fragment_size = 1024 include_length = yes cipher_list = "DEFAULT" } ttls { default_eap_type = md5 copy_request_to_tunnel = yes use_tunneled_reply = yes } } =*=*=*=*=*=*=*=*=*= FreeRADIUS users =*=*=*=*=*=*=*=*=*=*=*= foo User-Password == "password" =*=*=*=*=*=*=*=*= simplified radiusd.conf =*=*=*=*=*=*=*=*=*=*= [snip] less important stuff omitted [/snip] $INCLUDE ${confdir}/clients.conf $INCLUDE ${confdir}/eap.conf instantiate { } authorize { preprocess auth_log eap files pap } authenticate { Auth-Type PAP { pap } eap } preacct { preprocess acct_unique } accounting { detail } post-auth { reply_log } =*=*=*=*=*=*=*=*= -Xxx debug output snippet =*=*=*=*=*=*=*=*=*= Thu Feb 14 08:41:05 2008 : Debug: Processing the authorize section of radiusd.conf Thu Feb 14 08:41:05 2008 : Debug: modcall: entering group authorize for request 6 Thu Feb 14 08:41:05 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 6 Thu Feb 14 08:41:05 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 6 Thu Feb 14 08:41:05 2008 : Debug: modcall[authorize]: module "preprocess" returns ok for request 6 Thu Feb 14 08:41:05 2008 : Debug: modsingle[authorize]: calling auth_log (rlm_detail) for request 6 Thu Feb 14 08:41:05 2008 : Debug: radius_xlat: '/var/log/radacct/www.xxx.yyy.zzz/auth-20080214' Thu Feb 14 08:41:05 2008 : Debug: rlm_detail: /var/log/radacct/%{Client-IP-Address}/auth-%Y%m%d expands to /var/log/rada cct/www.xxx.yyy.zzz/auth-20080214 Thu Feb 14 08:41:05 2008 : Debug: modsingle[authorize]: returned from auth_log (rlm_detail) for request 6 Thu Feb 14 08:41:05 2008 : Debug: modcall[authorize]: module "auth_log" returns ok for request 6 Thu Feb 14 08:41:05 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 6 Thu Feb 14 08:41:05 2008 : Debug: rlm_eap: EAP packet type response id 7 length 112 Thu Feb 14 08:41:05 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Thu Feb 14 08:41:05 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 6 Thu Feb 14 08:41:05 2008 : Debug: modcall[authorize]: module "eap" returns updated for request 6 Thu Feb 14 08:41:05 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 6 Thu Feb 14 08:41:05 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 6 Thu Feb 14 08:41:05 2008 : Debug: modcall[authorize]: module "files" returns notfound for request 6 Thu Feb 14 08:41:05 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 6 Thu Feb 14 08:41:05 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fai l because of this. Thu Feb 14 08:41:05 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 6 Thu Feb 14 08:41:05 2008 : Debug: modcall[authorize]: module "pap" returns noop for request 6 Thu Feb 14 08:41:05 2008 : Debug: modcall: leaving group authorize (returns updated) for request 6 Thu Feb 14 08:41:05 2008 : Debug: rad_check_password: Found Auth-Type EAP Thu Feb 14 08:41:05 2008 : Debug: auth: type "EAP" Thu Feb 14 08:41:05 2008 : Debug: Processing the authenticate section of radiusd.conf Thu Feb 14 08:41:05 2008 : Debug: modcall: entering group authenticate for request 6 Thu Feb 14 08:41:05 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 6 Thu Feb 14 08:41:05 2008 : Debug: rlm_eap: Request found, released from the list Thu Feb 14 08:41:05 2008 : Debug: rlm_eap: EAP/ttls Thu Feb 14 08:41:05 2008 : Debug: rlm_eap: processing type ttls Thu Feb 14 08:41:05 2008 : Debug: rlm_eap_ttls: Authenticate Thu Feb 14 08:41:05 2008 : Debug: rlm_eap_tls: processing TLS Thu Feb 14 08:41:05 2008 : Debug: eaptls_verify returned 7 Thu Feb 14 08:41:05 2008 : Debug: rlm_eap_tls: Done initial handshake Thu Feb 14 08:41:05 2008 : Debug: eaptls_process returned 7 Thu Feb 14 08:41:05 2008 : Debug: rlm_eap_ttls: Session established. Proceeding to decode tunneled attributes. Thu Feb 14 08:41:05 2008 : Debug: TTLS: Adding old state with 29 1f Thu Feb 14 08:41:05 2008 : Debug: Processing the authorize section of radiusd.conf Thu Feb 14 08:41:05 2008 : Debug: modcall: entering group authorize for request 6 Thu Feb 14 08:41:05 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 6 Thu Feb 14 08:41:05 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 6 Thu Feb 14 08:41:05 2008 : Debug: modcall[authorize]: module "preprocess" returns ok for request 6 Thu Feb 14 08:41:05 2008 : Debug: modsingle[authorize]: calling auth_log (rlm_detail) for request 6 Thu Feb 14 08:41:05 2008 : Debug: radius_xlat: '/var/log/radacct/127.0.0.1/auth-20080214' Thu Feb 14 08:41:05 2008 : Debug: rlm_detail: /var/log/radacct/%{Client-IP-Address}/auth-%Y%m%d expands to /var/log/rada cct/127.0.0.1/auth-20080214 Thu Feb 14 08:41:05 2008 : Debug: modsingle[authorize]: returned from auth_log (rlm_detail) for request 6 Thu Feb 14 08:41:05 2008 : Debug: modcall[authorize]: module "auth_log" returns ok for request 6 Thu Feb 14 08:41:05 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 6 Thu Feb 14 08:41:05 2008 : Debug: rlm_eap: EAP packet type response id 7 length 22 Thu Feb 14 08:41:05 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Thu Feb 14 08:41:05 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 6 Thu Feb 14 08:41:05 2008 : Debug: modcall[authorize]: module "eap" returns updated for request 6 Thu Feb 14 08:41:05 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 6 Thu Feb 14 08:41:05 2008 : Debug: users: Matched entry foo at line 217 Thu Feb 14 08:41:05 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 6 Thu Feb 14 08:41:05 2008 : Debug: modcall[authorize]: module "files" returns ok for request 6 Thu Feb 14 08:41:05 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 6 Thu Feb 14 08:41:05 2008 : Debug: rlm_pap: Found existing Auth-Type, not changing it. Thu Feb 14 08:41:05 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 6 Thu Feb 14 08:41:05 2008 : Debug: modcall[authorize]: module "pap" returns noop for request 6 Thu Feb 14 08:41:05 2008 : Debug: modcall: leaving group authorize (returns updated) for request 6 Thu Feb 14 08:41:05 2008 : Debug: rad_check_password: Found Auth-Type EAP Thu Feb 14 08:41:05 2008 : Debug: auth: type "EAP" Thu Feb 14 08:41:05 2008 : Debug: Processing the authenticate section of radiusd.conf Thu Feb 14 08:41:05 2008 : Debug: modcall: entering group authenticate for request 6 Thu Feb 14 08:41:05 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 6 Thu Feb 14 08:41:05 2008 : Debug: rlm_eap: Request found, released from the list Thu Feb 14 08:41:05 2008 : Debug: rlm_eap: EAP/md5 Thu Feb 14 08:41:05 2008 : Debug: rlm_eap: processing type md5 Thu Feb 14 08:41:05 2008 : Debug: rlm_eap: Freeing handler Thu Feb 14 08:41:05 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 6 Thu Feb 14 08:41:05 2008 : Debug: modcall[authenticate]: module "eap" returns ok for request 6 Thu Feb 14 08:41:05 2008 : Debug: modcall: leaving group authenticate (returns ok) for request 6 Thu Feb 14 08:41:05 2008 : Error: Trying to look up name of unknown client 127.0.0.1. Thu Feb 14 08:41:05 2008 : Auth: Login OK: [foo/<no User-Password attribute>] (from client UNKNOWN-CLIENT port 262 cli 0 0-13-46-C1-7A-01) Thu Feb 14 08:41:05 2008 : Debug: Processing the post-auth section of radiusd.conf Thu Feb 14 08:41:05 2008 : Debug: modcall: entering group post-auth for request 6 Thu Feb 14 08:41:05 2008 : Debug: modsingle[post-auth]: calling reply_log (rlm_detail) for request 6 Thu Feb 14 08:41:05 2008 : Debug: radius_xlat: '/var/log/radacct/127.0.0.1/reply-detail-20080214' Thu Feb 14 08:41:05 2008 : Debug: rlm_detail: /var/log/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d expands to /var/ log/radacct/127.0.0.1/reply-detail-20080214 Thu Feb 14 08:41:05 2008 : Debug: modsingle[post-auth]: returned from reply_log (rlm_detail) for request 6 Thu Feb 14 08:41:05 2008 : Debug: modcall[post-auth]: module "reply_log" returns ok for request 6 Thu Feb 14 08:41:05 2008 : Debug: modcall: leaving group post-auth (returns ok) for request 6 Thu Feb 14 08:41:05 2008 : Debug: TTLS: Got tunneled Access-Accept Thu Feb 14 08:41:05 2008 : Debug: rlm_eap_tls: add_reply failed to create attribute MS-MPPE-Recv-Key: Unknown attribute "MS-MPPE-Recv-Key" Thu Feb 14 08:41:05 2008 : Debug: rlm_eap_tls: add_reply failed to create attribute MS-MPPE-Send-Key: Unknown attribute "MS-MPPE-Send-Key" Thu Feb 14 08:41:05 2008 : Debug: rlm_eap: Freeing handler Thu Feb 14 08:41:05 2008 : Debug: TTLS: Freeing handler for user foo Thu Feb 14 08:41:05 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 6 Thu Feb 14 08:41:05 2008 : Debug: modcall[authenticate]: module "eap" returns ok for request 6 Thu Feb 14 08:41:05 2008 : Debug: modcall: leaving group authenticate (returns ok) for request 6 Thu Feb 14 08:41:05 2008 : Auth: Login OK: [anonymous/<no User-Password attribute>] (from client hotbox port 2 62 cli 00-xx-yy-yy-zz-zz) Thu Feb 14 08:41:05 2008 : Debug: Processing the post-auth section of radiusd.conf Thu Feb 14 08:41:05 2008 : Debug: modcall: entering group post-auth for request 6 Thu Feb 14 08:41:05 2008 : Debug: modsingle[post-auth]: calling reply_log (rlm_detail) for request 6 Thu Feb 14 08:41:05 2008 : Debug: radius_xlat: '/var/log/radacct/www.xxx.yyy.zzz/reply-detail-20080214' Thu Feb 14 08:41:05 2008 : Debug: rlm_detail: /var/log/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d expands to /var/ log/radacct/www.xxx.yyy.zzz/reply-detail-20080214 Thu Feb 14 08:41:05 2008 : Debug: modsingle[post-auth]: returned from reply_log (rlm_detail) for request 6 Thu Feb 14 08:41:05 2008 : Debug: modcall[post-auth]: module "reply_log" returns ok for request 6 Thu Feb 14 08:41:05 2008 : Debug: modcall: leaving group post-auth (returns ok) for request 6 Sending Access-Accept of id 42 to www.xxx.yyy.zzz port 1645 Message-Authenticator = 0x00000000000000000000000000000000 User-Name = "foo\000" EAP-Message = 0x03070004 <<<<===== this looks like success [EAP code == 3] Thu Feb 14 08:41:05 2008 : Debug: Finished request 6 Thu Feb 14 08:41:05 2008 : Debug: Going to the next request Thu Feb 14 08:41:05 2008 : Debug: Waking up in 6 seconds... =*=*=*=*=*=*=*=*= Cisco debug log snippet =*=*=*=*=*=*=*=*=*= Feb 14 13:40:56.976: dot11_auth_dot1x_run_rfsm: Executing Action(CLIENT_WAIT,CLIENT_REPLY) for 00xx.yyyy.zzzz Feb 14 13:40:56.976: dot11_auth_dot1x_send_response_to_server: Sending client 00xx.yyyy.zzzz data to server Feb 14 13:40:56.977: dot11_auth_dot1x_send_response_to_server: Started timer server_timeout 60 seconds Feb 14 13:40:56.990: dot11_auth_dot1x_parse_aaa_resp: Received server response: PASS Feb 14 13:40:56.990: dot11_auth_dot1x_parse_aaa_resp: found eap pak in server response Feb 14 13:40:56.990: dot11_auth_server_chk_ssid: Checking for SSID in server attributes Feb 14 13:40:56.990: dot11_auth_server_vlan_number: Checking for VLAN ID in server attributes Feb 14 13:40:56.990: dot11_auth_dot1x_run_rfsm: Executing Action(SERVER_WAIT,SERVER_PASS) for 00xx.yyyy.zzzz Feb 14 13:40:56.990: dot11_auth_dot1x_send_response_to_client: Forwarding server message to client 00xx.yyyy.zzzz Feb 14 13:40:56.990: EAPOL pak dump tx Feb 14 13:40:56.990: EAPOL Version: 0x1 type: 0x0 length: 0x0004 Feb 14 13:40:56.991: EAP code: 0x3 id: 0x7 length: 0x0004 <<<<<===== [EAP success code == 3] 01802DA0: 01000004 03070004 ........ Feb 14 13:40:56.991: dot11_auth_send_msg: sending data to requestor status 1 Feb 14 13:40:56.991: dot11_auth_send_msg: Sending EAPOL to requestor Feb 14 13:40:56.991: dot1x-registry:registry:dot1x_ether_macaddr called Feb 14 13:40:56.991: dot11_auth_dot1x_send_response_to_client: Started timer client_timeout 30 seconds Feb 14 13:40:56.991: dot11_auth_send_msg: sending data to requestor status 2 Feb 14 13:40:56.991: dot11_auth_send_msg: resp->nsk_len 0 resp->auth_key_len 0 Feb 14 13:40:56.992: dot11_auth_send_msg: client authenticated 00xx.yyyy.zzzz, node_type 64 for application 0x1 Feb 14 13:40:56.992: dot11_auth_delete_client_entry: 00xx.yyyy.zzzz is deleted for application 0x1 Feb 14 13:40:56.992: dot1x-registry:registry:dot1x_ether_macaddr called Feb 14 13:40:56.998: dot1x-ev:dot1x_mgr_pre_process_eapol_pak: Role determination not required on Dot11Radio0. Feb 14 13:40:56.998: dot1x-packet:dot1x_mgr_process_eapol_pak: queuing an EAPOL pkt on Authenticator Q Feb 14 13:40:57.092: dot1x-registry:registry:dot1x_ether_macaddr called Feb 14 13:40:57.093: dot1x-ev:dot1x_mgr_pre_process_eapol_pak: Role determination not required on Dot11Radio0. Feb 14 13:40:57.093: dot1x-packet:dot1x_mgr_process_eapol_pak: queuing an EAPOL pkt on Authenticator Q Feb 14 13:40:57.192: dot1x-registry:registry:dot1x_ether_macaddr called Feb 14 13:40:57.193: dot1x-ev:dot1x_mgr_pre_process_eapol_pak: Role determination not required on Dot11Radio0. Feb 14 13:40:57.193: dot1x-packet:dot1x_mgr_process_eapol_pak: queuing an EAPOL pkt on Authenticator Q Feb 14 08:40:57.292 -0500: %DOT11-7-AUTH_FAILED: Station 00xx.yyyy.zzzz Authentication failed ^^^^^^^^^^^ ^^^^^^^^^^^^^^^^^^^^^ Clearly the access point isn't helping here... =*=*=*=*=*=*=*=*=*=*=*=*= wpa_supplicant "-dd" output =*=*=*=*=*=*=*=*=*=*=*=*=*=*=*= Initializing interface 'ath0' conf '/etc/wpa_supplicant.conf' driver 'default' ctrl_interface 'N/A' Configuration file '/etc/wpa_supplicant.conf' -> '/etc/wpa_supplicant.conf' Reading configuration file '/etc/wpa_supplicant.conf' ctrl_interface='/var/run/wpa_supplicant' ctrl_interface_group=0 (from group name 'wheel') Line: 7 - start of a new network block ssid - hexdump_ascii(len=7): 74 65 73 74 69 6e 67 testing BSSID - hexdump(len=6): 00 xx xx xx xx xx proto: 0x2 key_mgmt: 0x1 eap methods - hexdump(len=2): 15 00 anonymous_identity - hexdump_ascii(len=9): 61 6e 6f 6e 79 6d 6f 75 73 anonymous identity - hexdump_ascii(len=3): 66 6f 6f foo password - hexdump_ascii(len=8): [REMOVED] phase2 - hexdump_ascii(len=11): 61 75 74 68 65 61 70 3d 4d 44 35 autheap=MD5 Priority group 0 id=0 ssid='testing' Initializing interface (2) 'ath0' 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 Own MAC address: 00:xx:xx:xx:xx:xx wpa_driver_bsd_set_wpa: enabled=1 wpa_driver_bsd_set_wpa_internal: wpa=3 privacy=1 wpa_driver_bsd_del_key: keyidx=0 wpa_driver_bsd_del_key: keyidx=1 wpa_driver_bsd_del_key: keyidx=2 wpa_driver_bsd_del_key: keyidx=3 wpa_driver_bsd_set_countermeasures: enabled=0 wpa_driver_bsd_set_drop_unencrypted: enabled=1 Setting scan request: 0 sec 100000 usec Added interface ath0 State: DISCONNECTED -> SCANNING Starting AP scan (broadcast SSID) Received 0 bytes of scan results (7 BSSes) Scan results: 7 Selecting BSS from priority group 0 0: 00:xx:xx:xx:xx:xx ssid='JoesROOM' wpa_ie_len=0 rsn_ie_len=22 caps=0x31 skip - SSID mismatch 1: 00:xx:xx:xx:xx:xx ssid='testing' wpa_ie_len=0 rsn_ie_len=22 caps=0x31 selected based on RSN IE Trying to associate with 00:xx:xx:xx:xx:xx (SSID='testing' freq=2442 MHz) Cancelling scan request WPA: clearing own WPA/RSN IE Automatic auth_alg selection: 0x1 wpa_driver_bsd_set_auth_alg alg 0x1 authmode 1 RSN: using IEEE 802.11i/D9.0 WPA: Selected cipher suites: group 16 pairwise 16 key_mgmt 1 WPA: clearing AP WPA IE WPA: set AP RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 01 28 00 WPA: using GTK CCMP WPA: using PTK CCMP WPA: using KEY_MGMT 802.1X WPA: Set own WPA IE default - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 01 00 00 No keys have been configured - skip key clearing wpa_driver_bsd_set_drop_unencrypted: enabled=1 State: SCANNING -> ASSOCIATING wpa_driver_bsd_associate: ssid 'testing' wpa ie len 22 pairwise 3 group 3 key mgmt 0 wpa_driver_bsd_associate: set PRIVACY 1 Setting authentication timeout: 10 sec 0 usec EAPOL: External notification - portControl=Auto RSN: Ignored PMKID candidate without preauth flag State: ASSOCIATING -> ASSOCIATED Associated to a new BSS: BSSID=00:xx:xx:xx:xx:xx No keys have been configured - skip key clearing Associated with 00:xx:xx:xx:xx:xx 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 RX EAPOL from 00:xx:xx:xx:xx:xx RX EAPOL - hexdump(len=48): 01 00 00 33 01 01 00 33 01 00 6e 65 74 77 6f 72 6b 69 64 3d 74 65 73 74 69 6e 67 2c 6e 61 73 69 64 3d 63 69 73 63 6f 2c 70 6f 72 74 69 64 3d 30 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 method=1 id=1 EAP: EAP entering state IDENTITY CTRL-EVENT-EAP-STARTED EAP authentication started EAP: EAP-Request Identity data - hexdump_ascii(len=39): 00 6e 65 74 77 6f 72 6b 69 64 3d 74 65 73 74 69 _networkid=testi 6e 67 2c 6e 61 73 69 64 3d 63 69 73 63 6f 2c 70 ng,nasid=cisco,p 6f 72 74 69 64 3d 30 ortid=0 EAP: using anonymous identity - hexdump_ascii(len=9): 61 6e 6f 6e 79 6d 6f 75 73 anonymous EAP: EAP entering state SEND_RESPONSE EAP: EAP entering state IDLE EAPOL: SUPP_BE entering state RESPONSE EAPOL: txSuppRsp TX EAPOL - hexdump(len=18): 01 00 00 18 02 01 00 18 01 61 6e 6f 6e 79 6d 6f 75 73 EAPOL: SUPP_BE entering state RECEIVE RX EAPOL from 00:xx:xx:xx:xx:xx RX EAPOL - hexdump(len=46): 01 00 00 06 01 02 00 06 15 20 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 EAPOL: Received EAP-Packet frame EAPOL: SUPP_BE entering state REQUEST EAPOL: getSuppRsp EAP: EAP entering state RECEIVED EAP: Received EAP-Request method=21 id=2 EAP: EAP entering state GET_METHOD EAP: initialize selected EAP method (21, TTLS) EAP-TTLS: Phase2 type: EAP EAP-TTLS: Phase2 EAP types - hexdump(len=1): 04 CTRL-EVENT-EAP-METHOD EAP method 21 (TTLS) selected EAP: EAP entering state METHOD SSL: Received packet(len=6) - Flags 0x20 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: 100 bytes pending from ssl_out SSL: 100 bytes left to be sent out (of total 100 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 TX EAPOL - hexdump(len=110): 01 00 00 6a 02 02 00 6a 15 00 16 03 01 00 5f 01 00 00 5b 03 01 47 a9 b1 f0 85 22 af ea 08 17 80 24 ee a6 61 19 34 ba 99 d9 94 9d 0e b6 d6 31 ff 6b 83 ac f9 a0 00 00 34 00 39 00 38 00 35 00 16 00 13 00 0a 00 33 00 32 00 2f 00 66 00 05 00 04 00 63 00 62 00 61 00 15 00 12 00 09 00 65 00 64 00 60 00 14 00 11 00 08 00 06 00 03 01 00 EAPOL: SUPP_BE entering state RECEIVE RX EAPOL from 00:xx:xx:xx:xx:xx RX EAPOL - hexdump(len=1038): [deleted] EAPOL: Received EAP-Packet frame EAPOL: SUPP_BE entering state REQUEST EAPOL: getSuppRsp EAP: EAP entering state RECEIVED EAP: Received EAP-Request method=21 id=3 EAP: EAP entering state METHOD SSL: Received packet(len=1034) - Flags 0xc0 SSL: TLS Message Length: 2126 SSL: Need 1102 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 TX EAPOL - hexdump(len=10): 01 00 00 06 02 03 00 06 15 00 EAPOL: SUPP_BE entering state RECEIVE RX EAPOL from 00:xx:xx:xx:xx:xx RX EAPOL - hexdump(len=1038): [deleted] EAPOL: Received EAP-Packet frame EAPOL: SUPP_BE entering state REQUEST EAPOL: getSuppRsp EAP: EAP entering state RECEIVED EAP: Received EAP-Request method=21 id=4 EAP: EAP entering state METHOD SSL: Received packet(len=1034) - Flags 0xc0 SSL: TLS Message Length: 2126 SSL: Need 78 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 TX EAPOL - hexdump(len=10): 01 00 00 06 02 04 00 06 15 00 EAPOL: SUPP_BE entering state RECEIVE RX EAPOL from 00:xx:xx:xx:xx:xx RX EAPOL - hexdump(len=92): 01 00 00 58 01 05 00 58 15 80 00 00 08 4e 9e 69 96 15 00 d2 3a 5a a5 8a 72 56 25 f3 2e fe 2c 1c ac b1 88 a7 de a7 1d 18 94 5e ac 5a 1e 15 cc c6 3d 2d 98 96 87 4b 1e a6 4e 93 50 33 c5 c0 c0 ac 67 8b bc d3 fc 8d 8f 63 04 21 90 77 06 ec 1e 94 85 b6 a2 16 03 01 00 04 0e 00 00 00 EAPOL: Received EAP-Packet frame EAPOL: SUPP_BE entering state REQUEST EAPOL: getSuppRsp EAP: EAP entering state RECEIVED EAP: Received EAP-Request method=21 id=5 EAP: EAP entering state METHOD SSL: Received packet(len=88) - Flags 0x80 SSL: TLS Message Length: 2126 SSL: (where=0x1001 ret=0x1) SSL: SSL_connect:SSLv3 read server hello A 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 TX EAPOL - hexdump(len=144): 01 00 00 8c 02 05 00 8c 15 00 16 03 01 00 46 10 00 00 42 00 40 82 45 b6 b2 83 6a 15 52 cb c1 d8 7c 57 05 4d da aa fd 65 d4 73 2c 86 fd d9 99 12 17 b2 a5 f1 de 68 80 81 6e df dd fc d2 3e 8e 2a fe 72 61 34 55 9d 92 85 3b 21 27 5e 72 e2 bc 2c 7c 21 61 e8 a1 14 03 01 00 01 01 16 03 01 00 30 be 1e 85 a3 09 4b 34 31 17 06 74 06 a8 18 0d 7d 91 08 75 66 9d 19 07 71 b0 2a 55 51 b3 fd 51 d9 41 08 54 c8 7d 7e b6 64 95 7d 28 89 97 18 02 7a EAPOL: SUPP_BE entering state RECEIVE RX EAPOL from 00:xx:xx:xx:xx:xx RX EAPOL - hexdump(len=73): 01 00 00 45 01 06 00 45 15 80 00 00 00 3b 14 03 01 00 01 01 16 03 01 00 30 4d 08 fa 7d 74 55 0c d1 da f0 32 ac f8 71 4e c6 1d a3 17 de de 23 fa 43 9d 09 aa 60 c9 e3 ff 59 c3 98 49 9c e5 54 0e 28 76 8e 25 a1 a7 96 7f 6e EAPOL: Received EAP-Packet frame EAPOL: SUPP_BE entering state REQUEST EAPOL: getSuppRsp EAP: EAP entering state RECEIVED EAP: Received EAP-Request method=21 id=6 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 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 EAP Request: type=1 EAP: using real identity - hexdump_ascii(len=3): 66 6f 6f foo EAP-TTLS: AVP encapsulate EAP Response - hexdump(len=8): 02 06 00 08 01 66 6f 6f EAP-TTLS: Encrypting Phase 2 data - hexdump(len=16): [REMOVED] 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 TX EAPOL - hexdump(len=100): 01 00 00 60 02 06 00 60 15 00 17 03 01 00 20 b5 05 8a a6 5e 78 16 9e e2 f6 fd 52 6e 86 d6 42 69 36 a7 3f 3b b1 80 12 13 6a 29 7f 91 8a b3 b0 17 03 01 00 30 b8 41 cc 87 65 b4 21 f6 ad b2 9e 1b d8 12 be f1 2f b0 60 ca ac 14 70 61 d6 93 4b 56 e0 de 32 40 4c b5 96 f4 92 08 ae 2b 34 42 63 6c d0 09 a8 f6 EAPOL: SUPP_BE entering state RECEIVE RX EAPOL from 00:xx:xx:xx:xx:xx RX EAPOL - hexdump(len=83): 01 00 00 4f 01 07 00 4f 15 80 00 00 00 45 17 03 01 00 40 ea 30 50 29 6d a3 63 42 7f 47 0c 98 01 af 14 f3 f4 44 cc 76 a1 20 7d 85 47 42 de f3 76 16 48 79 ab 95 2d d5 c0 c4 ff 5a 3f 42 1c 6c 04 92 f7 f2 13 b8 12 8b 9b e1 49 d7 c7 4b 9a e2 23 42 60 8b EAPOL: Received EAP-Packet frame EAPOL: SUPP_BE entering state REQUEST EAPOL: getSuppRsp EAP: EAP entering state RECEIVED EAP: Received EAP-Request method=21 id=7 EAP: EAP entering state METHOD SSL: Received packet(len=79) - Flags 0x80 SSL: TLS Message Length: 69 EAP-TTLS: received 69 bytes encrypted data for Phase 2 EAP-TTLS: Decrypted Phase 2 AVPs - hexdump(len=32): 00 00 00 4f 40 00 00 1e 01 07 00 16 04 10 f0 7d 0e 84 ea da c9 80 d7 2b bd f0 76 2f 03 80 00 00 EAP-TTLS: AVP: code=79 flags=0x40 length=30 EAP-TTLS: AVP data - hexdump(len=22): 01 07 00 16 04 10 f0 7d 0e 84 ea da c9 80 d7 2b bd f0 76 2f 03 80 EAP-TTLS: AVP - EAP Message EAP-TTLS: Phase 2 EAP - hexdump(len=22): 01 07 00 16 04 10 f0 7d 0e 84 ea da c9 80 d7 2b bd f0 76 2f 03 80 EAP-TTLS: received Phase 2: code=1 identifier=7 length=22 EAP-TTLS: Phase 2 EAP Request: type=4 EAP-TTLS: Selected Phase 2 EAP method 4 EAP-MD5: Challenge - hexdump(len=16): f0 7d 0e 84 ea da c9 80 d7 2b bd f0 76 2f 03 80 EAP-MD5: generating Challenge Response EAP-MD5: Response - hexdump(len=16): 7a ba fd 26 e7 f0 62 3d c8 87 1d 1c bf 89 28 7e EAP-TTLS: AVP encapsulate EAP Response - hexdump(len=22): 02 07 00 16 04 10 7a ba fd 26 e7 f0 62 3d c8 87 1d 1c bf 89 28 7e EAP-TTLS: Encrypting Phase 2 data - hexdump(len=32): [REMOVED] EAP-TTLS: Authentication completed successfully EAP: method process -> ignore=FALSE methodState=DONE decision=UNCOND_SUCC EAP: EAP entering state SEND_RESPONSE EAP: EAP entering state IDLE EAPOL: SUPP_BE entering state RESPONSE EAPOL: txSuppRsp TX EAPOL - hexdump(len=116): 01 00 00 70 02 07 00 70 15 00 17 03 01 00 20 47 89 49 56 e6 61 64 d4 ef 83 a2 87 80 6a 8c 6d c7 6e 75 75 59 17 1f f4 6b 29 73 25 6b ba dd 9f 17 03 01 00 40 de a7 87 c8 51 85 32 1b 58 6a 2b 40 24 2c 33 52 16 f5 82 40 00 d6 27 5a ca 41 4e 1c d1 99 20 cf 72 28 98 04 5c b6 18 7b f4 e8 86 6c d3 7b d1 ff d8 6a 0e fd d5 ab ad bd 75 08 f8 a8 a7 08 59 54 EAPOL: SUPP_BE entering state RECEIVE RX EAPOL from 00:xx:xx:xx:xx:xx RX EAPOL - hexdump(len=46): 01 00 00 04 03 07 00 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 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:xx:xx:xx:xx:xx RX EAPOL - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 17 07 47 46 61 66 67 b9 96 02 eb b4 94 ce ed cc c7 33 13 1d 59 bb d6 6e 3b 59 08 ef e9 9c f5 2a 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 16 dd 14 00 0f ac 04 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00 00 00 EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines IEEE 802.1X RX: version=2 type=3 length=117 EAPOL-Key type=2 WPA: RX EAPOL-Key - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 17 07 47 46 61 66 67 b9 96 02 eb b4 94 ce ed cc c7 33 13 1d 59 bb d6 6e 3b 59 08 ef e9 9c f5 2a 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 16 dd 14 00 0f ac 04 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00 00 00 State: ASSOCIATED -> 4WAY_HANDSHAKE WPA: RX message 1 of 4-Way Handshake from 00:xx:xx:xx:xx:xx (ver=2) RSN: msg 1/4 key data - hexdump(len=22): dd 14 00 0f ac 04 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00 00 00 RSN: PMKID from Authenticator - hexdump(len=16): 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00 00 00 RSN: no matching PMKID found WPA: PMK from EAPOL state machines - hexdump(len=32): [REMOVED] RSN: added PMKSA cache entry for 00:xx:xx:xx:xx:xx RSN: no PMKSA entry found - trigger full EAP authentication RX EAPOL from 00:xx:xx:xx:xx:xx RX EAPOL - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 02 17 07 47 46 61 66 67 b9 96 02 eb b4 94 ce ed cc c7 33 13 1d 59 bb d6 6e 3b 59 08 ef e9 9c f5 2b 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 16 dd 14 00 0f ac 04 43 41 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00 EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines IEEE 802.1X RX: version=2 type=3 length=117 EAPOL-Key type=2 WPA: RX EAPOL-Key - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 02 17 07 47 46 61 66 67 b9 96 02 eb b4 94 ce ed cc c7 33 13 1d 59 bb d6 6e 3b 59 08 ef e9 9c f5 2b 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 16 dd 14 00 0f ac 04 43 41 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00 State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE WPA: RX message 1 of 4-Way Handshake from 00:xx:xx:xx:xx:xx (ver=2) RSN: msg 1/4 key data - hexdump(len=22): dd 14 00 0f ac 04 43 41 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00 RSN: PMKID from Authenticator - hexdump(len=16): 43 41 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00 RSN: no matching PMKID found WPA: PMK from EAPOL state machines - hexdump(len=32): [REMOVED] WPA: reusing previous PMKSA entry RSN: no PMKSA entry found - trigger full EAP authentication RX EAPOL from 00:xx:xx:xx:xx:xx RX EAPOL - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 03 17 07 47 46 61 66 67 b9 96 02 eb b4 94 ce ed cc c7 33 13 1d 59 bb d6 6e 3b 59 08 ef e9 9c f5 2c 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 16 dd 14 00 0f ac 04 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00 00 00 EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines IEEE 802.1X RX: version=2 type=3 length=117 EAPOL-Key type=2 WPA: RX EAPOL-Key - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 03 17 07 47 46 61 66 67 b9 96 02 eb b4 94 ce ed cc c7 33 13 1d 59 bb d6 6e 3b 59 08 ef e9 9c f5 2c 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 16 dd 14 00 0f ac 04 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00 00 00 State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE WPA: RX message 1 of 4-Way Handshake from 00:xx:xx:xx:xx:xx (ver=2) RSN: msg 1/4 key data - hexdump(len=22): dd 14 00 0f ac 04 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00 00 00 RSN: PMKID from Authenticator - hexdump(len=16): 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00 00 00 RSN: no matching PMKID found WPA: PMK from EAPOL state machines - hexdump(len=32): [REMOVED] WPA: reusing previous PMKSA entry RSN: no PMKSA entry found - trigger full EAP authentication Setting scan request: 0 sec 100000 usec Added BSSID 00:xx:xx:xx:xx:xx into blacklist State: 4WAY_HANDSHAKE -> DISCONNECTED 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 CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys wpa_driver_bsd_del_key: keyidx=0 wpa_driver_bsd_del_key: keyidx=1 wpa_driver_bsd_del_key: keyidx=2 wpa_driver_bsd_del_key: keyidx=3 wpa_driver_bsd_del_key: addr=00:00:00:00:00:00 keyidx=0 State: DISCONNECTED -> SCANNING =*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*= When I contacted Cisco support, they said the two following lines which are from the above Cisco debug logs: Feb 14 13:40:56.990: dot11_auth_server_chk_ssid: Checking for SSID in server attributes Feb 14 13:40:56.990: dot11_auth_server_vlan_number: Checking for VLAN ID in server attributes indicated to them that FreeRADIUS was sending dynamic VLAN attributes to the access point. I do not have any VLAN or other tunnelling attributes set on the FreeRADIUS side. Jouni suggested that these lines from the wpa_supplicant "-dd" debug log above: RSN: PMKID from Authenticator - hexdump(len=16): 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00 00 00 RSN: no matching PMKID found WPA: PMK from EAPOL state machines - hexdump(len=32): [REMOVED] RSN: added PMKSA cache entry for 00:xx:xx:xx:xx:xx RSN: no PMKSA entry found - trigger full EAP authentication indicated that the access point is not sending the correct keys. I cannot understand whether my problems lie in the FreeRADIUS area (my misconfiguration of which) or in the Cisco access point (my misconfiguration of which). I would be happy to include all or parts of my Cisco running configuration if necessary, but this email message is already too long. Regards, web... -- William Bulley Email: web(a)umich.edu

2 1