- Freeradius-Users - lists.freeradius.org

Logging
by Süleyman Düzdaban 18 Dec '15

18 Dec '15

Hi, /(Excu//se my English after that time./) FR version: 3.0.10 I have two linelog instances for access ("linelog") and accounting ("log_accounting"). I put the "linelog" in innert-tunnel's post-auth section instead of default for Access-Accept and Access-Reject with inner identity and it seems like that:/ //Thu Dec 17 15:26:58 2015 Access accepted: ///1234567890/@realm-is-here NAS-IP-Address: 10.109.50.207 Called-Station-Id: A0-48-1C-56-C6-A1 Packet-Src-IP-Address: 80.251.40.29 Calling-Station-Id: C0-BD-D1-89-0B-90// //Thu Dec 17 15:27:30 2015 Access accepted: //1234567890//@realm-is-here//NAS-IP-Address: 10.109.50.185 Called-Station-Id: A0-48-1C-56-C6-9D Packet-Src-IP-Address: 80.251.40.29 Calling-Station-Id: C0-BD-D1-89-0B-90// //Thu Dec 17 15:27:44 2015 Access accepted: //1234567890//@realm-is-here//NAS-IP-Address: 10.109.50.202 Called-Station-Id: A0-48-1C-56-C6-A0 Packet-Src-IP-Address: 80.251.40.29 Calling-Station-Id: C0-BD-D1-89-0B-90// //Thu Dec 17 15:30:42 2015 Access accepted: //1234567890//@realm-is-here//NAS-IP-Address: 10.109.50.201 Called-Station-Id: 14-58-D0-66-E6-55 Packet-Src-IP-Address: 80.251.40.29 Calling-Station-Id: C0-BD-D1-89-0B-90// //Thu Dec 17 15:31:38 2015 Access accepted: //1234567890//@realm-is-here//NAS-IP-Address: 10.109.50.206 Called-Station-Id: 14-58-D0-66-B6-51 Packet-Src-IP-Address: 80.251.40.29 Calling-Station-Id: C0-BD-D1-89-0B-90// //Thu Dec 17 15:32:43 2015 Access accepted: //1234567890//@realm-is-here//NAS-IP-Address: 10.109.50.222 Called-Station-Id: 14-58-D0-66-B6-9C Packet-Src-IP-Address: 80.251.40.29 Calling-Station-Id: C0-BD-D1-89-0B-90// //Thu Dec 17 15:32:50 2015 Access accepted: //1234567890//@realm-is-here//NAS-IP-Address: 10.109.50.192 Called-Station-Id: 14-58-D0-66-C6-7A Packet-Src-IP-Address: 80.251.40.29 Calling-Station-Id: C0-BD-D1-89-0B-90// //Thu Dec 17 15:32:51 2015 Access accepted: 1234567890//@realm-is-here//NAS-IP-Address: 10.109.50.205 Called-Station-Id: 14-58-D0-66-C6-56 Packet-Src-IP-Address: 80.251.40.29 Calling-Station-Id: C0-BD-D1-89-0B-90/ As shown above, i can get the inner user identities but also i get multiple "Accept" lines for the same user after first login (15:26:58) although there is no attempt by the user for login. I see the same thing in the accounting log file too: / //Thu Dec 17 15:26:58 2015 Connect: 1234567890@realm-is-here sessId: 93e63906-0000077e called: A0-48-1C-56-C6-A1 calling: C0-BD-D1-89-0B-90 port: 1385 ip: Thu Dec 17 15:27:14 2015 Connect: 1234567890@realm-is-here sessId: e85fb0d5-00000289 called: 14-58-D0-66-B6-51 calling: C0-BD-D1-89-0B-90 port: 533 ip: Thu Dec 17 15:27:16 2015 Connect: 1234567890@realm-is-here sessId: 758f27c1-000001e1 called: 14-58-D0-66-E6-55 calling: C0-BD-D1-89-0B-90 port: 397 ip: Thu Dec 17 15:27:19 2015 Disconnect: 1234567890@realm-is-here sessId: 758f27c1-000001e1 called: 14-58-D0-66-E6-55 calling: C0-BD-D1-89-0B-90 port: 397 ip: sessTime: 3 seconds input: 569B output: 967B Thu Dec 17 15:27:30 2015 Connect: 1234567890@realm-is-here sessId: 32b8e9e6-0000048e called: A0-48-1C-56-C6-9D calling: C0-BD-D1-89-0B-90 port: 841 ip: Thu Dec 17 15:27:42 2015 Disconnect: 1234567890@realm-is-here sessId: 15f28421-00000256 called: 14-58-D0-66-B6-E1 calling: C0-BD-D1-89-0B-90 port: 474 ip: 92.61.7.155 sessTime: seconds input: 6096B output: 7868B Thu Dec 17 15:27:44 2015 Connect: 1234567890@realm-is-here sessId: 6ee0534b-00001696 called: A0-48-1C-56-C6-A0 calling: C0-BD-D1-89-0B-90 port: 4162 ip: Thu Dec 17 15:27:52 2015 Disconnect: 1234567890@realm-is-here sessId: ba48b418-00000360 called: 14-58-D0-66-C6-61 calling: C0-BD-D1-89-0B-90 port: 634 ip: 92.61.7.155 sessTime: seconds input: 54571B output: 96205B Thu Dec 17 15:28:11 2015 Disconnect: 1234567890@realm-is-here sessId: e85fb0d5-00000289 called: 14-58-D0-66-B6-51 calling: C0-BD-D1-89-0B-90 port: 533 ip: 92.61.7.155 sessTime: seconds input: 569B output: 1183B Thu Dec 17 15:28:17 2015 Connect: 1234567890@realm-is-here sessId: 192aa670-00000e35 called: A0-48-1C-56-C6-A6 calling: C0-BD-D1-89-0B-90 port: 2558 ip: Thu Dec 17 15:28:22 2015 Disconnect: 1234567890@realm-is-here sessId: 93e63906-0000077e called: A0-48-1C-56-C6-A1 calling: C0-BD-D1-89-0B-90 port: 1385 ip: 92.61.7.155 sessTime: seconds input: 4371B output: 3351B Thu Dec 17 15:29:13 2015 Disconnect: 1234567890@realm-is-here sessId: 32b8e9e6-0000048e called: A0-48-1C-56-C6-9D calling: C0-BD-D1-89-0B-90 port: 841 ip: 92.61.7.155 sessTime: seconds input: 94910B output: 28777B Thu Dec 17 15:29:14 2015 Disconnect: 1234567890@realm-is-here sessId: 6ee0534b-00001696 called: A0-48-1C-56-C6-A0 calling: C0-BD-D1-89-0B-90 port: 4162 ip: 92.61.7.155 sessTime: seconds input: 26866B output: 9369B Thu Dec 17 15:30:42 2015 Connect: 1234567890@realm-is-here sessId: 90649829-000001e3 called: 14-58-D0-66-E6-55 calling: C0-BD-D1-89-0B-90 port: 399 ip: Thu Dec 17 15:30:43 2015 Disconnect: 1234567890@realm-is-here sessId: 192aa670-00000e35 called: A0-48-1C-56-C6-A6 calling: C0-BD-D1-89-0B-90 port: 2558 ip: 92.61.7.155 sessTime: seconds input: 7238B output: 7872B Thu Dec 17 15:31:38 2015 Connect: 1234567890@realm-is-here sessId: 88a18c10-0000028b called: 14-58-D0-66-B6-51 calling: C0-BD-D1-89-0B-90 port: 535 ip: Thu Dec 17 15:31:56 2015 Connect: 1234567890@realm-is-here sessId: 7d5f1897-0000077f called: A0-48-1C-56-C6-A1 calling: C0-BD-D1-89-0B-90 port: 1386 ip: Thu Dec 17 15:32:06 2015 Connect: 1234567890@realm-is-here sessId: 68d0d39a-00000366 called: 14-58-D0-66-C6-61 calling: C0-BD-D1-89-0B-90 port: 639 ip: Thu Dec 17 15:32:36 2015 Disconnect: 1234567890@realm-is-here sessId: 90649829-000001e3 called: 14-58-D0-66-E6-55 calling: C0-BD-D1-89-0B-90 port: 399 ip: 92.61.7.155 sessTime: seconds input: 55755B output: 34278B Thu Dec 17 15:32:43 2015 Connect: 1234567890@realm-is-here sessId: 2e5136a5-0000018c called: 14-58-D0-66-B6-9C calling: C0-BD-D1-89-0B-90 port: 293 ip: Thu Dec 17 15:32:45 2015 Connect: 1234567890@realm-is-here sessId: 80a8748c-000001be called: 14-58-D0-66-56-1E calling: C0-BD-D1-89-0B-90 port: 351 ip: Thu Dec 17 15:32:48 2015 Disconnect: 1234567890@realm-is-here sessId: 80a8748c-000001be called: 14-58-D0-66-56-1E calling: C0-BD-D1-89-0B-90 port: 351 ip: 92.61.7.155 sessTime: 3 seconds input: 4892B output: 2684B Thu Dec 17 15:32:50 2015 Connect: 1234567890@realm-is-here sessId: e767e76d-00000143 called: 14-58-D0-66-C6-7A calling: C0-BD-D1-89-0B-90 port: 262 ip: Thu Dec 17 15:32:51 2015 Connect: 1234567890@realm-is-here sessId: d9b51d3b-00000230 called: 14-58-D0-66-C6-56 calling: C0-BD-D1-89-0B-90 port: 442 ip: Thu Dec 17 15:32:51 2015 Disconnect: 1234567890@realm-is-here sessId: 88a18c10-0000028b called: 14-58-D0-66-B6-51 calling: C0-BD-D1-89-0B-90 port: 535 ip: 92.61.7.155 sessTime: seconds input: 5743B output: 3632B / Why do i get that much lines even when there is no login-logout attempt by the user? There is another issue with accounting. I can get the inner user name sometimes (As shown above both files look like okay) but sometimes I can't. That's the log (Some part of it actually that about the case for the user *1639**5**905204*/@realm-is-here/): (And again there is no attempt to login or logout by the user at all.) Access Accept/Reject: Thu Dec 17 17:26:20 2015 Access accepted: 16395905204@realm-is-here NAS-IP-Address: 10.50.43.204 Called-Station-Id: 00-03-52-0B-2B-93 Packet-Src-IP-Address: 80.251.40.40 Calling-Station-Id: 8C-00-6D-07-3B-9A Accounting: Thu Dec 17 17:24:50 2015 Disconnect: 16395905204@realm-is-here sessId: 9e57770c-0000010d called: 00-03-52-0B-2B-93 calling: 8C-00-6D-07-3B-9A port: 238 ip: 185.22.249.217 sessTime: 481 seconds input: 29613B output: 22215B Thu Dec 17 17:26:20 2015 Connect: 16395905204@realm-is-here sessId: 1f605712-0000010e called: 00-03-52-0B-2B-93 calling: 8C-00-6D-07-3B-9A port: 239 ip: Debug: (13337) Received Accounting-Request Id 62 from 80.251.40.40:54942 to 80.251.40.8:1813 length 364 (13337) Acct-Multi-Session-Id = "00-03-52-A6-A3-70-8C-00-6D-07-3B-9A-56-72-D1-E3-00-0E-DF-CA" (13337) Acct-Session-Id = "9e57770c-0000010d" (13337) NAS-Port = 238 (13337) NAS-Port-Type = Wireless-802.11 (13337) NAS-Identifier = "AU-MSC-5500-1" (13337) NAS-IP-Address = 10.50.43.204 (13337) Framed-MTU = 1496 (13337) Framed-IP-Address = 185.22.249.217 (13337) User-Name = "16395905204@realm-is-here" (13337) Calling-Station-Id = "8C-00-6D-07-3B-9A" (13337) Called-Station-Id = "00-03-52-0B-2B-93" (13337) Acct-Status-Type = Stop (13337) Acct-Session-Time = 481 (13337) Acct-Input-Packets = 102 (13337) Acct-Output-Packets = 217 (13337) Acct-Input-Octets = 29613 (13337) Acct-Output-Octets = 22215 (13337) Acct-Delay-Time = 0 (13337) Colubris-AVPair = "ssid=AU WiFi Net" (13337) Colubris-AVPair = "incoming-vlan-id=51" (13337) Colubris-AVPair = "group=TND-Yerleske" (13337) Colubris-AVPair = "phytype=IEEE802dot11g" (13337) Attr-26.8744.250 = 0x00000001 (13337) Attr-26.8744.249 = 0x50fb2808 (13337) # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default (13337) preacct { (13337) [preprocess] = ok (13337) policy acct_unique { (13337) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) { (13337) EXPAND %{string:Class} (13337) --> (13337) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (13337) else { (13337) update request { (13337) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (13337) --> c6f70635bf1e4b14ea52406bac73b3ee (13337) &Acct-Unique-Session-Id := c6f70635bf1e4b14ea52406bac73b3ee (13337) } # update request = noop (13337) } # else = noop (13337) } # policy acct_unique = noop (13337) suffix: Checking for suffix after "@" (13337) suffix: Looking up realm "ankara.edu.tr" for User-Name = "16395905204@realm-is-here" (13337) suffix: Found realm "ankara.edu.tr" (13337) suffix: Adding Stripped-User-Name = "16395905204" (13337) suffix: Adding Realm = "ankara.edu.tr" (13337) suffix: Accounting realm is LOCAL (13337) [suffix] = ok (13337) [files] = noop (13337) } # preacct = ok (13337) # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default (13337) accounting { (13337) detail: EXPAND /usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y/%m/%d/detail-%H00 (13337) detail: --> /usr/local/var/log/radius/radacct/80.251.40.40/2015/12/17/detail-1700 (13337) detail: /usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y/%m/%d/detail-%H00 expands to /usr/local/var/log/radius/radacct/80.251.40.40/2015/12/17/detail-1700 (13337) detail: EXPAND %t (13337) detail: --> Thu Dec 17 17:24:50 2015 (13337) [detail] = ok (13337) log_accounting: EXPAND Accounting-Request.%{%{Acct-Status-Type}:-unknown} (13337) log_accounting: --> Accounting-Request.Stop (13337) log_accounting: EXPAND /usr/local/var/log/radius/linelog-accounting (13337) log_accounting: --> /usr/local/var/log/radius/linelog-accounting (13337) log_accounting: EXPAND %t Disconnect: %{User-Name} sessId: %{Acct-Session-Id} called: %{Called-Station-Id} calling: %{Calling-Station-Id} port: %{NAS-Port} ip: %{Framed-IP-Address} sessTime: %{Acct-Session-Time} seconds input: %{Acct-Input-Octets}B output: %{Acct-Output-Octets}B (13337) log_accounting: --> Thu Dec 17 17:24:50 2015 Disconnect: 16395905204@realm-is-here sessId: 9e57770c-0000010d called: 00-03-52-0B-2B-93 calling: 8C-00-6D-07-3B-9A port: 238 ip: 185.22.249.217 sessTime: 481 seconds input: 29613B output: 22215B (13337) [log_accounting] = ok (13337) [exec] = noop (13337) attr_filter.accounting_response: EXPAND %{User-Name} (13337) attr_filter.accounting_response: --> 16395905204@realm-is-here (13337) attr_filter.accounting_response: Matched entry DEFAULT at line 12 (13337) [attr_filter.accounting_response] = updated (13337) } # accounting = updated (13337) Sent Accounting-Response Id 62 from 80.251.40.8:1813 to 80.251.40.40:54942 length 0 (13337) Finished request (13337) Cleaning up request packet ID 62 with timestamp +369 Waking up in 0.5 seconds. Above lines look like okay but then (at 17:26:20): (16180) Received Access-Request Id 135 from 80.251.40.40:54942 to 80.251.40.8:1812 length 368 (16180) Acct-Multi-Session-Id = "00-03-52-A6-A3-70-8C-00-6D-07-3B-9A-56-72-D4-1E-00-0D-4B-44" (16180) Acct-Session-Id = "1f605712-0000010e" (16180) NAS-Port = 239 (16180) NAS-Port-Type = Wireless-802.11 (16180) NAS-Identifier = "AU-MSC-5500-1" (16180) NAS-IP-Address = 10.50.43.204 (16180) Framed-MTU = 1496 (16180) User-Name = "anonymous@realm-is-here" (16180) Calling-Station-Id = "8C-00-6D-07-3B-9A" (16180) Called-Station-Id = "00-03-52-0B-2B-93" (16180) Service-Type = Framed-User (16180) EAP-Message = 0x02f8001c01616e6f6e796d6f757340616e6b6172612e6564752e7472 (16180) Colubris-AVPair = "ssid=AU WiFi Net" (16180) Colubris-AVPair = "incoming-vlan-id=51" (16180) Colubris-AVPair = "group=TND-Yerleske" (16180) Colubris-AVPair = "phytype=IEEE802dot11g" (16180) Attr-26.8744.250 = 0x00000001 (16180) Attr-26.8744.249 = 0x50fb2808 (16180) Message-Authenticator = 0x66886b75dae87c711e75232ce6e36114 (16180) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (16180) authorize { (16180) policy filter_username { (16180) if (!&User-Name) { (16180) if (!&User-Name) -> FALSE (16180) if (&User-Name =~ / /) { (16180) if (&User-Name =~ / /) -> FALSE (16180) if (&User-Name =~ /@.*@/ ) { (16180) if (&User-Name =~ /@.*@/ ) -> FALSE (16180) if (&User-Name =~ /\.\./ ) { (16180) if (&User-Name =~ /\.\./ ) -> FALSE (16180) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (16180) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (16180) if (&User-Name =~ /\.$/) { (16180) if (&User-Name =~ /\.$/) -> FALSE (16180) if (&User-Name =~ /(a)\./) { (16180) if (&User-Name =~ /(a)\./) -> FALSE (16180) } # policy filter_username = notfound (16180) [preprocess] = ok (16180) if ("%{User-Name}" == "eduroamtest(a)ulakbim.gov.tr") { (16180) if ("%{User-Name}" == "eduroamtest(a)ulakbim.gov.tr") -> FALSE (16180) elsif ("%{User-Name}" =~ /^(.+)@realm-is-here$/ && NAS-Identifier =~ /^AU-MSC-5500-(.+)$/) { (16180) EXPAND %{User-Name} (16180) --> anonymous@realm-is-here (16180) elsif ("%{User-Name}" =~ /^(.+)@realm-is-here$/ && NAS-Identifier =~ /^AU-MSC-5500-(.+)$/) -> TRUE (16180) elsif ("%{User-Name}" =~ /^(.+)@realm-is-here$/ && NAS-Identifier =~ /^AU-MSC-5500-(.+)$/) { (16180) if (Colubris-AVPair == "ssid=eduroam") { (16180) if (Colubris-AVPair == "ssid=eduroam") -> FALSE (16180) else { (16180) [noop] = noop (16180) } # else = noop (16180) } # elsif ("%{User-Name}" =~ /^(.+)@realm-is-here$/ && NAS-Identifier =~ /^AU-MSC-5500-(.+)$/) = noop (16180) ... skipping elsif for request 16180: Preceding "if" was taken (16180) ... skipping elsif for request 16180: Preceding "if" was taken (16180) ... skipping elsif for request 16180: Preceding "if" was taken (16180) auth_log: EXPAND /usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y/%m/%d/auth-detail-%H00 (16180) auth_log: --> /usr/local/var/log/radius/radacct/80.251.40.40/2015/12/17/auth-detail-1700 (16180) auth_log: /usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y/%m/%d/auth-detail-%H00 expands to /usr/local/var/log/radius/radacct/80.251.40.40/2015/12/17/auth-detail-1700 (16180) auth_log: EXPAND %t (16180) auth_log: --> Thu Dec 17 17:26:20 2015 (16180) [auth_log] = ok (16180) [chap] = noop (16180) [mschap] = noop (16180) [digest] = noop (16180) eap: Peer sent EAP Response (code 2) ID 248 length 28 (16180) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize (16180) [eap] = ok (16180) } # authorize = ok (16180) Found Auth-Type = EAP (16180) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (16180) authenticate { (16180) eap: Peer sent packet with method EAP Identity (1) (16180) eap: Calling submodule eap_ttls to process data (16180) eap_ttls: Initiating new EAP-TLS session (16180) eap_ttls: [eaptls start] = request (16180) eap: Sending EAP Request (code 1) ID 249 length 6 (16180) eap: EAP session adding &reply:State = 0xb7828561b77b903c (16180) [eap] = handled (16180) } # authenticate = handled (16180) Using Post-Auth-Type Challenge (16180) Post-Auth-Type sub-section not found. Ignoring. (16180) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (16180) Sent Access-Challenge Id 135 from 80.251.40.8:1812 to 80.251.40.40:54942 length 0 (16180) EAP-Message = 0x01f900061520 (16180) Message-Authenticator = 0x00000000000000000000000000000000 (16180) State = 0xb7828561b77b903c4f6473e0f27d0e52 (16180) Finished request Waking up in 0.2 seconds. Thanks.

2 1

RE: Index is not an integer (segfault)
by Franks Andy (IT Technical Architecture Manager) 17 Dec '15

17 Dec '15

Thanks guys, I may need some pointers on what to change at a later date then. At the moment, it's all working, nicely logging off mac addresses from the switch via disconnect under certain conditions, and I think we've finally got around the stupid mitel phones needing manually uplifted address limits and failing if you swap computers on the end. FR is awesome, bit of a learning curve, but nothing's worth doing unless it's slightly difficult. Andy -----Original Message----- From: Freeradius-Users [mailto:freeradius-users-bounces+andy.franks=sath.nhs.uk@lists.freeradius.org] On Behalf Of Alan DeKok Sent: 17 December 2015 14:55 To: FreeRadius users mailing list Subject: Re: Index is not an integer (segfault) On Dec 17, 2015, at 9:53 AM, Arran Cudbard-Bell <a.cudbardb(a)freeradius.org> wrote: > Could also just print non string types to a string and write that to the buffer in the xlat xlat, which is a little nicer than just erroring out. Sure. The first fix is to *not* crash. Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

1 0

RE: Index is not an integer (segfault)
by Franks Andy (IT Technical Architecture Manager) 17 Dec '15

17 Dec '15

Marvellous - thanks. Also, just a bit of feedback from the previous segfault relating to zero row return from a sql map entry, it now doesn't segfault, but says : ERROR: Failed retrieving field names: server error Instead. Should this be an error? I could do a reject=1 handling thing, but I'm not sure that nothing coming back from a sql query should cause a rejection by default (or should it?!) Thanks very much again Andy -----Original Message----- From: Freeradius-Users [mailto:freeradius-users-bounces+andy.franks=sath.nhs.uk@lists.freeradius.org] On Behalf Of Alan DeKok Sent: 17 December 2015 14:14 To: FreeRadius users mailing list Subject: Re: Index is not an integer (segfault) On Dec 17, 2015, at 4:50 AM, Franks Andy (IT Technical Architecture Manager) <Andy.Franks(a)sath.nhs.uk> wrote: > It works fine plugging the variable into a string, xlat seems to cast fine, even if we do an if ("%{xlat:control:Tmp-String-1[%{control:Tmp-Integer-0}]}" > 1 ), so the workaround is obvious, just thought I'd best let you know about the seg anyway. The fix is simple. I'll push a fix later today. Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

2 1

RE: Index is not an integer
by Franks Andy (IT Technical Architecture Manager) 15 Dec '15

15 Dec '15

Wow, that's made my day, works perfectly! I didn't realise you could use Tmp-* as a request "type" variable - does it belong in request or control, I've always assumed the latter but it makes things more concise due to the assumed request type. Anyway, really appreciate the time you took to try stuff out there Alan, thanks again. Andy -----Original Message----- From: Freeradius-Users [mailto:freeradius-users-bounces+andy.franks=sath.nhs.uk@lists.freeradius.org] On Behalf Of Alan DeKok Sent: 15 December 2015 16:00 To: FreeRadius users mailing list Subject: Re: Index is not an integer On Dec 15, 2015, at 9:20 AM, Franks Andy (IT Technical Architecture Manager) <Andy.Franks(a)sath.nhs.uk> wrote: > Had an earlier attempt was to break it down, guess I might have come at it from the wrong angle, i.e. trying "%{xlat:%{control:Tmp-Integer-0}}". I imagined that piece to be expanded first into and integer, in the way bracketed things work inside -> out. > > "%{Control:Tmp-Integer-0}" is fine, gives the correct number, no great surprise there. > > I can't test "%{control:Tmp-String-3[%{control:Tmp-Integer-0}]}" as the server won't start up since it doesn't see control:Tmp-Integer-0 as an actual integer. Yes. I did this: update request { Tmp-Integer-0 := 1 Tmp-String-0 += "a" Tmp-String-0 += "b" Tmp-String-0 += "c" } update reply { Filter-Id := "%{xlat:Tmp-String-0[%{Tmp-Integer-0}]}" } and it worked. The Filter-Id had 'b' as a value. Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

2 1

RE: Index is not an integer
by Franks Andy (IT Technical Architecture Manager) 15 Dec '15

15 Dec '15

Hi Alan, Had an earlier attempt was to break it down, guess I might have come at it from the wrong angle, i.e. trying "%{xlat:%{control:Tmp-Integer-0}}". I imagined that piece to be expanded first into and integer, in the way bracketed things work inside -> out. "%{Control:Tmp-Integer-0}" is fine, gives the correct number, no great surprise there. I can't test "%{control:Tmp-String-3[%{control:Tmp-Integer-0}]}" as the server won't start up since it doesn't see control:Tmp-Integer-0 as an actual integer. Arran's suggestion does allow the server to start, but gives an empty output in debugging mode: Variables going in : (1) control:Tmp-string-1 += 4685a44565edf4d8aae476f8ed3b0ab9 (1) control:Tmp-string-2 += 000E0000009C (1) control:Tmp-string-3 += 20b399f37010 (1) control:Tmp-string-4 += radacct_lan0 (1) control:Tmp-string-1 += 4ae6bd20c2955bdbc7a61703bd811c5b (1) control:Tmp-string-2 += 000E0000004B (1) control:Tmp-string-3 += 20b399f37010 (1) control:Tmp-string-4 += radacct_lant .. but not coming out: (1) update control { (1) Tmp-Integer-0 := 0 (1) } # update control (noop) (1) foreach &control:Tmp-String-1 { (1) foreach &control:Tmp-String-1 (1) # Foreach-Variable-0 = "4685a44565edf4d8aae476f8ed3b0ab9" (1) update control { (1) CoA-Failure-Reason !* ANY (1) EXPAND Foreach-Variable-0 (1) --> 4685a44565edf4d8aae476f8ed3b0ab9 (1) EXPAND %{Foreach-Variable-0} (1) --> 4685a44565edf4d8aae476f8ed3b0ab9 (1) CoA-Acct-Unique-Session-Id := "4685a44565edf4d8aae476f8ed3b0ab9" (1) EXPAND %{xlat:%%{control:Tmp-String-2[%{control:Tmp-Integer-0}]%}} (1) --> (1) CoA-Acct-Session-Id := "" (1) EXPAND %{xlat:%%{control:Tmp-String-3[%{control:Tmp-Integer-0}]%}} (1) --> (1) CoA-User-Name := "" .. based on a bit of trial code: update control { Tmp-Integer-0 !* ANY Tmp-String-0 !* ANY Tmp-String-1 !* ANY Tmp-String-2 !* ANY Tmp-String-0 := "call get_active_sessions_for_switchport ('%{NAS-IP-Address}', '%{NAS-Port}', ${policy.MaxClientAge})" } # map - get back one or more devices. map sql_SP_rsh-radius-lant &control:Tmp-String-0 { control:Tmp-string-1 += acctuniqueid control:Tmp-string-2 += acctsessionid control:Tmp-string-3 += username control:Tmp-string-4 += accounttable } if (&control:Tmp-String-1) { update control { Tmp-Integer-0 := 0 } foreach &control:Tmp-String-1 { # send the disconnect update control { CoA-Failure-Reason !* ANY CoA-Acct-Unique-Session-Id := "%{Foreach-Variable-0}" CoA-Acct-Session-Id := "%{xlat:%%{control:Tmp-String-2[%{control:Tmp-Integer-0}]%}}" CoA-User-Name := "%{xlat:%%{control:Tmp-String-3[%{control:Tmp-Integer-0}]%}}" } } } As you can see I'm trying to disconnect some switch sessions via CoA in an effort to get around a really annoying issue with phones we have of hanging onto mac addresses for ages after they've been removed. If I can't do it, no worries, it seems to me the most efficient way, but as with all things I.T. there are other ways of doing it, presumably some that still make the sql map stuff useful. Thank you! I'm sure all this will be useful for other people searching! Andy -----Original Message----- From: Freeradius-Users [mailto:freeradius-users-bounces+andy.franks=sath.nhs.uk@lists.freeradius.org] On Behalf Of Alan DeKok Sent: 15 December 2015 14:03 To: FreeRadius users mailing list Subject: Re: Index is not an integer On Dec 15, 2015, at 8:54 AM, Franks Andy (IT Technical Architecture Manager) <Andy.Franks(a)sath.nhs.uk> wrote: > > Hi Alan, > First of all thanks for the reply, that helps me understand "xlat's place". > > My real struggle was with what Arran provided yesterday, can't get it to work: As with most things, break it down in pieces. > "%{xlat:%%{control:Tmp-String-3[%{control:Tmp-Integer-0}]%}}" Hmm... I'm not sure that works. The problem is that this is complicated and not simple... > It use is to refer to the index of Tmp-String-3 via the dynamic integer Tmp-Integer-0. Trouble is, it comes back with an empty string. It comes back with a lot more than that. PLEASE run the server in debugging mode to see what the inputs and outputs are for each stage of expansion. Honestly, this should be the *first step*. And you should post it here, too. Ignoring the debug output means you will *never* get the problem solved. > Is it because of what you mentioned ; that > > control:Tmp-String-3[%{3}] != control:Tmp-String-3[3] No. %{xlat:3} is the same as %{3}. %{xlat:foo-3} is the same as %{foo-3}, not %{foo-%{3}}. There's no magical expansion in the middle of a string. > Do I need to do some regex matching and plug the integer value into the corresponding group by building, for example, a delimited string? Would that work? No. I'd break it down into pieces. The question is, what does each piece produce? Build it up in sequence. %{control:Tmp-Integer-0} is... %{control:Tmp-String-3[%{control:Tmp-Integer-0}] is ... My guess is that won't work, because the normal case is to *not* do xlat expansions on the array offsets. You might need to build up multiple layers of xlat expansions. > The apparent downside to that would be to only match a preset number of groups my expression contained, and, if possible, I'd like to match any number of previous "things", within reason. I'm guessing I'm on the edge of what should maybe done in perl / python / whatever, it just seems the tricky bit has been done with the import of mapped sql stuff, can't get over how useful that is, and now I just want to iterate over things in turn, literally the last thing to be done. Yup. Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

2 1

RE: Index is not an integer
by Franks Andy (IT Technical Architecture Manager) 15 Dec '15

15 Dec '15

Hi Alan, First of all thanks for the reply, that helps me understand "xlat's place". My real struggle was with what Arran provided yesterday, can't get it to work: "%{xlat:%%{control:Tmp-String-3[%{control:Tmp-Integer-0}]%}}" It use is to refer to the index of Tmp-String-3 via the dynamic integer Tmp-Integer-0. Trouble is, it comes back with an empty string. Is it because of what you mentioned ; that control:Tmp-String-3[%{3}] != control:Tmp-String-3[3] Do I need to do some regex matching and plug the integer value into the corresponding group by building, for example, a delimited string? Would that work? The apparent downside to that would be to only match a preset number of groups my expression contained, and, if possible, I'd like to match any number of previous "things", within reason. I'm guessing I'm on the edge of what should maybe done in perl / python / whatever, it just seems the tricky bit has been done with the import of mapped sql stuff, can't get over how useful that is, and now I just want to iterate over things in turn, literally the last thing to be done. Thanks again, appreciate the input a lot! Andy -----Original Message----- From: Freeradius-Users [mailto:freeradius-users-bounces+andy.franks=sath.nhs.uk@lists.freeradius.org] On Behalf Of Alan DeKok Sent: 15 December 2015 13:25 To: FreeRadius users mailing list Subject: Re: Index is not an integer On Dec 15, 2015, at 8:17 AM, Franks Andy (IT Technical Architecture Manager) <Andy.Franks(a)sath.nhs.uk> wrote: > Has anyone had any direct experience with using "%{xlat:..}". I can't seem to find much about using it directly, obviously xlats are used in ldap/sql/files etc a lot, any time you want to do anything directly outside a module, and they are super-useful but I haven't seen this used before to allow resolution of various levels of variable. The "%{foo}" thing is a normal expansion. The difficulty is that sometimes you want to build custom expansions at run-time, and the server doesn't allow for that. e.g. if you build the expansion like this: update request { Tmp-String-0 := "sql:SELECT ..." } Then doing this: Foo = "%{Tmp-String-0}" will get you the *string value* of Tmp-String-0. It won't run the expansion you've put into that string. The solution is %{xlat:...}. It does *another* round of expansion on the input string. So if "%{Tmp-String-0}" gets you the string for the SQL expansion, then "%{xlat:%{Tmp-String-0}}" will run the SQL expansion, and call SQL. > I can't get it to do much, tried a simple: > > Update control { > Tmp-Integer-0 := 3 > Tmp-String-1 := "%{control:Tmp-Integer-0}" > Tmp-String-1 := "%{xlat:%{control:Tmp-Integer-0}}" > } Well, yes. Integers aren't strings. The xlat expansion of "3" is equivalent to "%{3}". Which is empty if you haven't done any regular expression matching. > .. the first works as it should, but this xlat one is a mystery. Sorry for being a bit thick, possibly got it completely wrong. > I could do a switch .. case dependent on a tracked variable, but it's not very nice and would result it lots of identical code blocks to maintain. > > Sorry to be a pain, I did search around first even had a look at the source code, but it hurts my head. No worries. Sometimes it hurts *my* head, and I've been doing this for almost 20 years. Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

2 1

RE: Index is not an integer
by Franks Andy (IT Technical Architecture Manager) 15 Dec '15

15 Dec '15

So .. nearly.. there now with this sql thingy. Has anyone had any direct experience with using "%{xlat:..}". I can't seem to find much about using it directly, obviously xlats are used in ldap/sql/files etc a lot, any time you want to do anything directly outside a module, and they are super-useful but I haven't seen this used before to allow resolution of various levels of variable. I can't get it to do much, tried a simple: Update control { Tmp-Integer-0 := 3 Tmp-String-1 := "%{control:Tmp-Integer-0}" Tmp-String-1 := "%{xlat:%{control:Tmp-Integer-0}}" } EXPAND %{control:Tmp-Integer-0} (3) --> 3 (3) Tmp-String-1 := "3" (3) EXPAND %{xlat:%{control:Tmp-Integer-0}} (3) --> (3) Tmp-String-1 := "" .. the first works as it should, but this xlat one is a mystery. Sorry for being a bit thick, possibly got it completely wrong. I could do a switch .. case dependent on a tracked variable, but it's not very nice and would result it lots of identical code blocks to maintain. Sorry to be a pain, I did search around first even had a look at the source code, but it hurts my head. Andy -----Original Message----- From: Freeradius-Users [mailto:freeradius-users-bounces+andy.franks=sath.nhs.uk@lists.freeradius.org] On Behalf Of Franks Andy (IT Technical Architecture Manager) Sent: 14 December 2015 18:00 To: FreeRadius users mailing list Subject: RE: Index is not an integer Hmm, can I just double check : Variables going in : (1) control:Tmp-string-1 += 4685a44565edf4d8aae476f8ed3b0ab9 (1) control:Tmp-string-2 += 000E0000009C (1) control:Tmp-string-3 += 20b399f37010 (1) control:Tmp-string-4 += radacct_lan0 (1) control:Tmp-string-1 += 4ae6bd20c2955bdbc7a61703bd811c5b (1) control:Tmp-string-2 += 000E0000004B (1) control:Tmp-string-3 += 20b399f37010 (1) control:Tmp-string-4 += radacct_lant (1) control:Tmp-string-1 += bac91c23dbdab2d01c15ae88fcf7f2ae (1) control:Tmp-string-2 += 000E000000B0 (1) control:Tmp-string-3 += 20b399f37010 (1) control:Tmp-string-4 += radacct_lan0 (1) control:Tmp-string-1 += ccbc421c66a4b053a7ad970d1ccf40f2 (1) control:Tmp-string-2 += 000E000000AF (1) control:Tmp-string-3 += 20b399f37010 (1) control:Tmp-string-4 += radacct_lan0 .. but not coming out: (1) update control { (1) Tmp-Integer-0 := 0 (1) } # update control (noop) (1) foreach &control:Tmp-String-1 { (1) foreach &control:Tmp-String-1 (1) # Foreach-Variable-0 = "4685a44565edf4d8aae476f8ed3b0ab9" (1) update control { (1) CoA-Failure-Reason !* ANY (1) EXPAND Foreach-Variable-0 (1) --> 4685a44565edf4d8aae476f8ed3b0ab9 (1) EXPAND %{Foreach-Variable-0} (1) --> 4685a44565edf4d8aae476f8ed3b0ab9 (1) CoA-Acct-Unique-Session-Id := "4685a44565edf4d8aae476f8ed3b0ab9" (1) EXPAND %{xlat:%%{control:Tmp-String-2[%{control:Tmp-Integer-0}]%}} (1) --> (1) CoA-Acct-Session-Id := "" (1) EXPAND %{xlat:%%{control:Tmp-String-3[%{control:Tmp-Integer-0}]%}} (1) --> (1) CoA-User-Name := "" I presumed the use of quotes around the expansion? "%{xlat:%%{control:Tmp-String-3[%{control:Tmp-Integer-0}]%}}" Thanks Andy -----Original Message----- From: Freeradius-Users [mailto:freeradius-users-bounces+andy.franks=sath.nhs.uk@lists.freeradius.org] On Behalf Of Franks Andy (IT Technical Architecture Manager) Sent: 14 December 2015 17:49 To: FreeRadius users mailing list Subject: RE: Index is not an integer Thanks Arran, Discovered the multiple disconnect thing by trial and error, using radclient seems to work, albeit not preferable calling something "external", but there we are, I can judge by return string whether to close off accounting sessions that never got updated and so on, not too bad.. Wish there was some interface to directly query the switch for account sessions, mac addresses etc on there by port rather than use accounting, but afaics snmp isn't going to help, I don't know what else to do with that one. Thanks for the help anyway, much appreciated. Andy -----Original Message----- From: Freeradius-Users [mailto:freeradius-users-bounces+andy.franks=sath.nhs.uk@lists.freeradius.org] On Behalf Of Arran Cudbard-Bell Sent: 14 December 2015 17:32 To: FreeRadius users mailing list Subject: Re: Index is not an integer > On 14 Dec 2015, at 12:30, Arran Cudbard-Bell <a.cudbardb(a)freeradius.org> wrote: > > >> On 14 Dec 2015, at 12:24, Franks Andy (IT Technical Architecture Manager) <Andy.Franks(a)sath.nhs.uk> wrote: >> >> Hi all, >> Is there a way of doing this or its equivalent? I'm tracking the index of a variable via expr and then trying to get the output of other variables respectively - I need to do this via a changing index that's housed in a variable, but (and I may be doing this wrong) FR won't start with the following: > > Array index is not an integer, it's an attribute reference, which is not supported. > > You'd need to use > %{xlat:%%{control:Tmp-String-3[%{control:Tmp-Integer-0}]%}} > > It's probably not hard to implement array indexes as templates, but I don't have time to look at it right now. You also can't send multiple disconnects unless you call out to radclient and do it that way. -Arran Arran Cudbard-Bell <a.cudbardb(a)freeradius.org> FreeRADIUS development team FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2 - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

2 1

Radius proxy
by srithar jeevadurai 15 Dec '15

15 Dec '15

Dear Friends, I have a basic question on proxy impl of freeradius. I am new to radius proxy impl. so I have few basic queries. -------------- ---------------------------------- | Radius | | Radius Home 1 to n | | Proxy | <===> | | -------------- ---------------------------------- Radius proxy is one instance of radiusd binary and each home server (1-n) is one instance of radiusd binary. so totally n+1 radius binary will be running on same host if we go with proxy approach. Proxy server while doing load balancing, does it follow below rule? If a session's first request i.e. auth has been forwarded to a home server 1 then all subsequent request of same session will be forwarded to same home instance of home server or it will be forwarded using round robin style. If it is round robin and we are using a customized module to trace sessions then it would not work since session created with home server 1 and sub sequence request for the session may go to another home server. Please correct if my understanding is not right. Regards, Srithar Durairaj Alternate Mail I.D: srijeevadurai1(a)yahoo.co.in Mobile: +919886251852

2 3

Warnings about OpenSSL 1.0.1f and 1.0.1g
by Alan DeKok 15 Dec '15

15 Dec '15

Anyone using these versions of OpenSSL should either upgrade them, or set "disable_tlsv1_2" in the EAP TLS module configuration. To make a long story short, these versions of OpenSSL calculate the WiFi encryption keys incorrectly for TLS 1.2. I've pushed a fix to v3.0 which disables TLS 1.2 when the server is built against those versions of OpenSSL. The solution is to upgrade to a version of OpenSSL which works, upgrade FreeRADIUS, or to use "disable_tlsv1_2" on existing systems. Alan DeKok.

4 4

eap-tls mschapv2 FREERADIUS 2.1.12 LDAP
by Iban Lopez 15 Dec '15

15 Dec '15

Please! I need help! I don't understando why doesn't work... I want connect FREERADIUS+WPA2 ENTERPRISE+LDAP Ready to process requests. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=147 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x02000016017573756172696f31406f726731322e6573 Message-Authenticator = 0xdea69f107d3eb3fa8984ef20369ff923 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 0 length 22 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [ldap] performing user authorization for usuario1 [ldap] expand: %{Stripped-User-Name} -> usuario1 [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=usuario1) [ldap] expand: dc=org12,dc=es -> dc=org12,dc=es [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] attempting LDAP reconnection [ldap] (re)connect to 192.168.12.5:389, authentication 0 [ldap] bind as cn=admin,dc=org12,dc=es/admin to 192.168.12.5:389 [ldap] waiting for bind result ... [ldap] Bind was successful [ldap] performing search in dc=org12,dc=es, with filter (uid=usuario1) [ldap] No default NMAS login sequence [ldap] looking for check items in directory... [ldap] userPassword -> Password-With-Header == "{MD5}EitzhgCg9098MxwO9ZvDTA==" [ldap] userPassword -> Password-With-Header == "usuario11" [ldap] looking for reply items in directory... [ldap] user usuario1 authorized to use remote access [ldap] ldap_release_conn: Release Id: 0 ++[ldap] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] Failed to decode Password-With-Header = "usuario11" [pap] Normalizing MD5-Password from base64 encoding [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] EAP Identity [eap] processing type tls [tls] Initiate [tls] Start returned 1 ++[eap] returns handled Sending Access-Challenge of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x010100061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xb57eb6afb57faf487df7eda8ab9aed4e Finished request 0. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=343 Cleaning up request 0 ID 0 with timestamp +30 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 State = 0xb57eb6afb57faf487df7eda8ab9aed4e NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020100c81980000000be16030100b9010000b50301566f4b1c8b95e3029a111e69fe94c1dfd9f4492132092b855b454e08fc37e570000048c014c00a00390038c00fc0050035c012c00800160013c00dc003000ac013c00900330032c00ec004002fc011c007c00cc002000500040015001200090014001100080006000300ff01000044000b000403000102000a00340032000100020003000400050006000700080009000a000b000c000d000e000f001000110012001300140015001600170018001900230000 Message-Authenticator = 0x9cecda9b7eba5b5e92030bcb9a129ed9 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 1 length 200 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS TLS Length 190 [peap] Length Included [peap] eaptls_verify returned 11 [peap] (other): before/accept initialization [peap] TLS_accept: before/accept initialization [peap] <<< TLS 1.0 Handshake [length 00b9], ClientHello [peap] TLS_accept: SSLv3 read client hello A [peap] >>> TLS 1.0 Handshake [length 0039], ServerHello [peap] TLS_accept: SSLv3 write server hello A [peap] >>> TLS 1.0 Handshake [length 02c6], Certificate [peap] TLS_accept: SSLv3 write certificate A [peap] >>> TLS 1.0 Handshake [length 014b], ServerKeyExchange [peap] TLS_accept: SSLv3 write key exchange A [peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone [peap] TLS_accept: SSLv3 write server done A [peap] TLS_accept: SSLv3 flush data [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A In SSL Handshake Phase In SSL Accept mode [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x0102040019c00000046216030100390200003503013b05e43751f6ed209948d0a70be8d3187a7aa248a71cdb7e3f581c40920e12b500c01400000dff01000100000b00040300010216030102c60b0002c20002bf0002bc308202b8308201a0a0030201020209008e4322a719659612300d06092a864886f70d01010b0500301431123010060355040313094f312d536572766572301e170d3135313231343232303933385a170d3235313231313232303933385a301431123010060355040313094f312d53657276657230820122300d06092a864886f70d01010105000382010f003082010a0282010100aa4952ef410918d271d25e62c24a970e5a48 EAP-Message = 0x3c0d3522dd3fe3ed96edfadb3c2bdc7d7426941ccf7b6274c2516f3bfcb87db4d032d4883d8fbbb2acbbab3dd961c6fb45a100de0da286208d3f358766c1996991c32ef19cae13854c394994f1bd07072f11c21217f57859079ae71b8c1f657996cd02c886866e192b9e37ffffc78a21f946e9d9481b13dac3ee6f47e1057aa7c0c32e802b8f42abb98253c6782de98fce3dc0e5f3736ff177e1d41da6bf14ea990e69d0c58482d2b37a2e0c17afb2042223429b2d44c3e0f6b685ae06e8f2657fa4b0f1915f901c16996d951fcd01e4cde25eafa638e233822cfc4da71a9e0ab41de67cbfc421029b45df58dfb70203010001a30d300b30090603551d EAP-Message = 0x1304023000300d06092a864886f70d01010b050003820101005d5c50cacdf0bb5a076175b04f86d79aa1a19fc1ac4afeae40c90ce3b3f9a0d31b7c1488f9fd2eeb81d824833768aa71a2a1fa1f1d88881b53ed5fc774a028fe5f617a960ed8c301a1e41403949f93197408e77b0a7ddeb6cdcc8ca79e90afa95dd08e92c6cdd48a6b0916a35f6ebcc56cbe8ceda830da6d949ebecf0fa043ecafca348621466c0f59b2edc7603eb0bd710b50eea5f4d90bd33ca0fd49da2255804bbf81a3d31a0934957e7271d2a7b3a903f0c45585832079900db22ef7f99f135cf1119051dc9c4fd40ff16d5bc6ce65dbe14d0fa2aa0ba2c3777e7f24324aa28744cc EAP-Message = 0x174c25e9d2e1b28dd5a3e3b0e423617e2b1aa0127cb1510e491c7d61160301014b0c000147030017410434b5656233950421a6263bc2989ea8f67c50f61d9a0aa890edfc7913263d656cf17c39632e087d67342bd72eda8f2427817160bd752b873c343d8f6ba0af02a501005068ad61fbf5b665809cba4a5a08cbbb3719d57717168f170052a958fb3e6d580695621c6cd057326b71f71a37ba5d9be4e1abb40865523864966b383bff5007fcc3c4d36ed7279cb2bb5c33838f53d86b1145e678c3502a3dbbb76707e6ce41b3cb23c3e1d210539327b877ef9ca98d4bf67b8398b40d31e53ebe9e89445a8b012bbaa66edd765a585c10ff6451fbb0a5 EAP-Message = 0x15179268395ae167b343d4cc Message-Authenticator = 0x00000000000000000000000000000000 State = 0xb57eb6afb47caf487df7eda8ab9aed4e Finished request 1. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=149 Cleaning up request 1 ID 0 with timestamp +30 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 State = 0xb57eb6afb47caf487df7eda8ab9aed4e NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020200061900 Message-Authenticator = 0x59caa5e345582e838b1ffcd681e1f5b5 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 2 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake fragment handler [peap] eaptls_verify returned 1 [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x0103007219004cd8cb658aa0e01d5fe54cad5d9d8f453bcb877c1c4ad2435d4ed9bc38d4500bbb1969fb91dcf8d3d360121d4b28689d7b3826b4ba0952cd82d332d35797aa56e9bc124bbe7f52f0d5972c5382d00a621b7db87d6f2fb48607bb5a944d29a654f9767c16030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xb57eb6afb77daf487df7eda8ab9aed4e Finished request 2. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=287 Cleaning up request 2 ID 0 with timestamp +30 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 State = 0xb57eb6afb77daf487df7eda8ab9aed4e NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020300901980000000861603010046100000424104f839145d329a4cbdb161c36cb292c9115131c20957aa46660b909963df2cc05b264e9b89096a3a80293b5cf7bdce8ed7c33f9a723fc6d1ca6fe89ad23e318fc5140301000101160301003097e0dad544d475481b8bf01379064093600c28c20aa0a1ec6b1a1e0f67902b807105d3c3a1658ed58dfa482359afb87f Message-Authenticator = 0xb326ab5d585497bcfd8b60c27f528ac2 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 3 length 144 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS TLS Length 134 [peap] Length Included [peap] eaptls_verify returned 11 [peap] <<< TLS 1.0 Handshake [length 0046], ClientKeyExchange [peap] TLS_accept: SSLv3 read client key exchange A [peap] <<< TLS 1.0 ChangeCipherSpec [length 0001] [peap] <<< TLS 1.0 Handshake [length 0010], Finished [peap] TLS_accept: SSLv3 read finished A [peap] >>> TLS 1.0 ChangeCipherSpec [length 0001] [peap] TLS_accept: SSLv3 write change cipher spec A [peap] >>> TLS 1.0 Handshake [length 0010], Finished [peap] TLS_accept: SSLv3 write finished A [peap] TLS_accept: SSLv3 flush data [peap] (other): SSL negotiation finished successfully SSL Connection Established [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x010400411900140301000101160301003080f8386264c0da11b42e99f326879ed6ff9591987c4d09a9fc7999380fa81edb7c76f0329c032a87ce59420caeba05ac Message-Authenticator = 0x00000000000000000000000000000000 State = 0xb57eb6afb67aaf487df7eda8ab9aed4e Finished request 3. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=149 Cleaning up request 3 ID 0 with timestamp +30 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 State = 0xb57eb6afb67aaf487df7eda8ab9aed4e NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020400061900 Message-Authenticator = 0xadfb8deb267aa8261bf95a6699e8088e # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 4 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake is finished [peap] eaptls_verify returned 3 [peap] eaptls_process returned 3 [peap] EAPTLS_SUCCESS [peap] Session established. Decoding tunneled attributes. [peap] Peap state TUNNEL ESTABLISHED ++[eap] returns handled Sending Access-Challenge of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x0105002b19001703010020631be9e7482f0ed9b52224ffe7f3c371664a3fc24818de5e823ff5121d1fc3fa Message-Authenticator = 0x00000000000000000000000000000000 State = 0xb57eb6afb17baf487df7eda8ab9aed4e Finished request 4. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=239 Cleaning up request 4 ID 0 with timestamp +30 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 State = 0xb57eb6afb17baf487df7eda8ab9aed4e NAS-Port-Type = Wireless-802.11 EAP-Message = 0x02050060190017030100209d12b50c6122b0994c07faac25a3e0a206cd763e85764fa8d738be533f9bb54e1703010030d418c5c8329283f3658a5dd7c119b73d136374a0ce40e6289869f00bbc4250beff3c0f9d237a6181417058327ea73fb4 Message-Authenticator = 0x2eb254bdcb929ee60a6fc3d5205097cb # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 5 length 96 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] eaptls_verify returned 7 [peap] Done initial handshake [peap] eaptls_process returned 7 [peap] EAPTLS_OK [peap] Session established. Decoding tunneled attributes. [peap] Peap state WAITING FOR INNER IDENTITY [peap] Identity - usuario1(a)org12.es [peap] Got inner identity 'usuario1(a)org12.es' [peap] Setting default EAP type for tunneled EAP session. [peap] Got tunneled request EAP-Message = 0x02050016017573756172696f31406f726731322e6573 server { [peap] Setting User-Name to usuario1(a)org12.es Sending tunneled request EAP-Message = 0x02050016017573756172696f31406f726731322e6573 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "usuario1(a)org12.es" server inner-tunnel { # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel +- entering group authorize {...} ++[chap] returns noop ++[mschap] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok ++[control] returns ok [eap] EAP packet type response id 5 length 22 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [ldap] performing user authorization for usuario1 [ldap] expand: %{Stripped-User-Name} -> usuario1 [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=usuario1) [ldap] expand: dc=org12,dc=es -> dc=org12,dc=es [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in dc=org12,dc=es, with filter (uid=usuario1) [ldap] No default NMAS login sequence [ldap] looking for check items in directory... [ldap] userPassword -> Password-With-Header == "{MD5}EitzhgCg9098MxwO9ZvDTA==" [ldap] userPassword -> Password-With-Header == "usuario11" [ldap] looking for reply items in directory... [ldap] user usuario1 authorized to use remote access [ldap] ldap_release_conn: Release Id: 0 ++[ldap] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] Failed to decode Password-With-Header = "usuario11" [pap] Normalizing MD5-Password from base64 encoding [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel +- entering group authenticate {...} [eap] EAP Identity [eap] processing type mschapv2 rlm_eap_mschapv2: Issuing Challenge ++[eap] returns handled } # server inner-tunnel [peap] Got tunneled reply code 11 EAP-Message = 0x0106002b1a0106002610ec17c8fae3e31e0ef656be69a75b82547573756172696f31406f726731322e6573 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xdccc9105dcca8bf500670ad62d7e0b7e [peap] Got tunneled reply RADIUS code 11 EAP-Message = 0x0106002b1a0106002610ec17c8fae3e31e0ef656be69a75b82547573756172696f31406f726731322e6573 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xdccc9105dcca8bf500670ad62d7e0b7e [peap] Got tunneled Access-Challenge ++[eap] returns handled Sending Access-Challenge of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x0106004b1900170301004077abe44705db16fc32db81fc8a7ddcd7c9bcc99de67829786b0e9c34ea29c9d385a5e4176eb259f01303b6c521dbe54d5f15d2e0af08102982db7fef6cc11bde Message-Authenticator = 0x00000000000000000000000000000000 State = 0xb57eb6afb078af487df7eda8ab9aed4e Finished request 5. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=287 Cleaning up request 5 ID 0 with timestamp +30 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 State = 0xb57eb6afb078af487df7eda8ab9aed4e NAS-Port-Type = Wireless-802.11 EAP-Message = 0x02060090190017030100204e4d14db4ab0209c8aab507a1f9db80200f36de7f83c8cf26ac000e8838cc63f1703010060a8e0e7a84d6f48666944c29a71bae900850ea5d516691812d70d17eb10e562b77f3680d5cfa7046997bbb82b9613c59ce0f7c62e17836ac4cf6ef698a54c8607cda951b886d66fb08e01d820061914ac45a053bbeb65082d68ff525eaac82d03 Message-Authenticator = 0xf3847577324b9eab1b2132cdcf4cca6a # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 6 length 144 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] eaptls_verify returned 7 [peap] Done initial handshake [peap] eaptls_process returned 7 [peap] EAPTLS_OK [peap] Session established. Decoding tunneled attributes. [peap] Peap state phase2 [peap] EAP type mschapv2 [peap] Got tunneled request EAP-Message = 0x0206004c1a02060047318850406bfa38eab922be2d6f458091a50000000000000000ded678e6af2d8907bd1218c52e47961713dbe7fe011b3efd007573756172696f31406f726731322e6573 server { [peap] Setting User-Name to usuario1(a)org12.es Sending tunneled request EAP-Message = 0x0206004c1a02060047318850406bfa38eab922be2d6f458091a50000000000000000ded678e6af2d8907bd1218c52e47961713dbe7fe011b3efd007573756172696f31406f726731322e6573 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "usuario1(a)org12.es" State = 0xdccc9105dcca8bf500670ad62d7e0b7e server inner-tunnel { # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel +- entering group authorize {...} ++[chap] returns noop ++[mschap] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok ++[control] returns ok [eap] EAP packet type response id 6 length 76 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [ldap] performing user authorization for usuario1 [ldap] expand: %{Stripped-User-Name} -> usuario1 [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=usuario1) [ldap] expand: dc=org12,dc=es -> dc=org12,dc=es [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in dc=org12,dc=es, with filter (uid=usuario1) [ldap] No default NMAS login sequence [ldap] looking for check items in directory... [ldap] userPassword -> Password-With-Header == "{MD5}EitzhgCg9098MxwO9ZvDTA==" [ldap] userPassword -> Password-With-Header == "usuario11" [ldap] looking for reply items in directory... [ldap] user usuario1 authorized to use remote access [ldap] ldap_release_conn: Release Id: 0 ++[ldap] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] Failed to decode Password-With-Header = "usuario11" [pap] Normalizing MD5-Password from base64 encoding [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/mschapv2 [eap] processing type mschapv2 [mschapv2] # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel [mschapv2] +- entering group MS-CHAP {...} [mschap] No Cleartext-Password configured. Cannot create LM-Password. [mschap] No Cleartext-Password configured. Cannot create NT-Password. [mschap] Creating challenge hash with username: usuario1(a)org12.es [mschap] Told to do MS-CHAPv2 for usuario1(a)org12.es with NT-Password [mschap] FAILED: No NT/LM-Password. Cannot perform authentication. [mschap] FAILED: MS-CHAP2-Response is incorrect ++[mschap] returns reject [eap] Freeing handler ++[eap] returns reject Failed to authenticate the user. } # server inner-tunnel [peap] Got tunneled reply code 3 MS-CHAP-Error = "\006E=691 R=1" EAP-Message = 0x04060004 Message-Authenticator = 0x00000000000000000000000000000000 [peap] Got tunneled reply RADIUS code 3 MS-CHAP-Error = "\006E=691 R=1" EAP-Message = 0x04060004 Message-Authenticator = 0x00000000000000000000000000000000 [peap] Tunneled authentication was rejected. [peap] FAILURE ++[eap] returns handled Sending Access-Challenge of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x0107002b19001703010020ed35ac44504ffaaca55962e2910db1901367da3cf9ed1077aa91e663276e6fa2 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xb57eb6afb379af487df7eda8ab9aed4e Finished request 6. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=223 Cleaning up request 6 ID 0 with timestamp +30 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 State = 0xb57eb6afb379af487df7eda8ab9aed4e NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020700501900170301002084e69a44dc5979e77eab39f4b661b3f9619dc0dff180481602cf51bef484770f170301002045c617c5725aabb81ed2253aa04289e9a3ea4d752a20f47d58929ae7a4fc2e51 Message-Authenticator = 0x04fb5185a048b1586c11c7058705c3e5 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 7 length 80 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] eaptls_verify returned 7 [peap] Done initial handshake [peap] eaptls_process returned 7 [peap] EAPTLS_OK [peap] Session established. Decoding tunneled attributes. [peap] Peap state send tlv failure [peap] Received EAP-TLV response. [peap] The users session was previously rejected: returning reject (again.) [peap] *** This means you need to read the PREVIOUS messages in the debug output [peap] *** to find out the reason why the user was rejected. [peap] *** Look for "reject" or "fail". Those earlier messages will tell you. [peap] *** what went wrong, and how to fix the problem. [eap] Handler failed in EAP/peap [eap] Failed in EAP select ++[eap] returns invalid Failed to authenticate the user. Using Post-Auth-Type Reject # Executing group from file /etc/freeradius/sites-enabled/default +- entering group REJECT {...} [attr_filter.access_reject] expand: %{User-Name} -> usuario1(a)org12.es attr_filter: Matched entry DEFAULT at line 11 ++[attr_filter.access_reject] returns updated Delaying reject of request 7 for 1 seconds Going to the next request Waking up in 0.9 seconds. Sending delayed reject for request 7 Sending Access-Reject of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x04070004 Message-Authenticator = 0x00000000000000000000000000000000 Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=147 Cleaning up request 7 ID 0 with timestamp +30 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x02000016017573756172696f31406f726731322e6573 Message-Authenticator = 0xaf83406fc6aba82b2c722587da18454a # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 0 length 22 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [ldap] performing user authorization for usuario1 [ldap] expand: %{Stripped-User-Name} -> usuario1 [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=usuario1) [ldap] expand: dc=org12,dc=es -> dc=org12,dc=es [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in dc=org12,dc=es, with filter (uid=usuario1) [ldap] No default NMAS login sequence [ldap] looking for check items in directory... [ldap] userPassword -> Password-With-Header == "{MD5}EitzhgCg9098MxwO9ZvDTA==" [ldap] userPassword -> Password-With-Header == "usuario11" [ldap] looking for reply items in directory... [ldap] user usuario1 authorized to use remote access [ldap] ldap_release_conn: Release Id: 0 ++[ldap] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] Failed to decode Password-With-Header = "usuario11" [pap] Normalizing MD5-Password from base64 encoding [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] EAP Identity [eap] processing type tls [tls] Initiate [tls] Start returned 1 ++[eap] returns handled Sending Access-Challenge of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x010100061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xb9eabf92b9eba6785099d584534e4628 Finished request 8. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=343 Cleaning up request 8 ID 0 with timestamp +34 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 State = 0xb9eabf92b9eba6785099d584534e4628 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020100c81980000000be16030100b9010000b50301566f4b21e10e7a1099dc7159e4c332878a8debec60ea8868b19b9adb07ae65f8000048c014c00a00390038c00fc0050035c012c00800160013c00dc003000ac013c00900330032c00ec004002fc011c007c00cc002000500040015001200090014001100080006000300ff01000044000b000403000102000a00340032000100020003000400050006000700080009000a000b000c000d000e000f001000110012001300140015001600170018001900230000 Message-Authenticator = 0xb997acfc08d2b27b7f645409f3187cec # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 1 length 200 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS TLS Length 190 [peap] Length Included [peap] eaptls_verify returned 11 [peap] (other): before/accept initialization [peap] TLS_accept: before/accept initialization [peap] <<< TLS 1.0 Handshake [length 00b9], ClientHello [peap] TLS_accept: SSLv3 read client hello A [peap] >>> TLS 1.0 Handshake [length 0039], ServerHello [peap] TLS_accept: SSLv3 write server hello A [peap] >>> TLS 1.0 Handshake [length 02c6], Certificate [peap] TLS_accept: SSLv3 write certificate A [peap] >>> TLS 1.0 Handshake [length 014b], ServerKeyExchange [peap] TLS_accept: SSLv3 write key exchange A [peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone [peap] TLS_accept: SSLv3 write server done A [peap] TLS_accept: SSLv3 flush data [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A In SSL Handshake Phase In SSL Accept mode [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x0102040019c0000004621603010039020000350301bb01e6ce658173bf181d931bcfc10c9f7752087fa6eb4891847331286705599900c01400000dff01000100000b00040300010216030102c60b0002c20002bf0002bc308202b8308201a0a0030201020209008e4322a719659612300d06092a864886f70d01010b0500301431123010060355040313094f312d536572766572301e170d3135313231343232303933385a170d3235313231313232303933385a301431123010060355040313094f312d53657276657230820122300d06092a864886f70d01010105000382010f003082010a0282010100aa4952ef410918d271d25e62c24a970e5a48 EAP-Message = 0x3c0d3522dd3fe3ed96edfadb3c2bdc7d7426941ccf7b6274c2516f3bfcb87db4d032d4883d8fbbb2acbbab3dd961c6fb45a100de0da286208d3f358766c1996991c32ef19cae13854c394994f1bd07072f11c21217f57859079ae71b8c1f657996cd02c886866e192b9e37ffffc78a21f946e9d9481b13dac3ee6f47e1057aa7c0c32e802b8f42abb98253c6782de98fce3dc0e5f3736ff177e1d41da6bf14ea990e69d0c58482d2b37a2e0c17afb2042223429b2d44c3e0f6b685ae06e8f2657fa4b0f1915f901c16996d951fcd01e4cde25eafa638e233822cfc4da71a9e0ab41de67cbfc421029b45df58dfb70203010001a30d300b30090603551d EAP-Message = 0x1304023000300d06092a864886f70d01010b050003820101005d5c50cacdf0bb5a076175b04f86d79aa1a19fc1ac4afeae40c90ce3b3f9a0d31b7c1488f9fd2eeb81d824833768aa71a2a1fa1f1d88881b53ed5fc774a028fe5f617a960ed8c301a1e41403949f93197408e77b0a7ddeb6cdcc8ca79e90afa95dd08e92c6cdd48a6b0916a35f6ebcc56cbe8ceda830da6d949ebecf0fa043ecafca348621466c0f59b2edc7603eb0bd710b50eea5f4d90bd33ca0fd49da2255804bbf81a3d31a0934957e7271d2a7b3a903f0c45585832079900db22ef7f99f135cf1119051dc9c4fd40ff16d5bc6ce65dbe14d0fa2aa0ba2c3777e7f24324aa28744cc EAP-Message = 0x174c25e9d2e1b28dd5a3e3b0e423617e2b1aa0127cb1510e491c7d61160301014b0c0001470300174104ea6db294242bc663673d95b316bf7dd2c5c4a720210983b7665204a7a90f1b244c4941a48b3648ffbbadf110f718faf0d289d73b645953e59a0df5fb010a803e01005023ae769a73db4bf8e1c951451bc9eafd69a822d4ccfd8543736353c4044b94cbecec3f223d5b4e63390dc6dade7ae712808ac134bf51f82b86b2ae2da14103856ad4041ae7e27da38adc8a11e0798e5a5fee944ea5a399d9a794d64b50c09c3f6ca4f531a3c5c5a7dbf90936bf53cf8ab55e0b4a2db95699170e807e153ca10fe12f8b344f67b0c3740565af84231bd7 EAP-Message = 0x932357a80717e435be1e449a Message-Authenticator = 0x00000000000000000000000000000000 State = 0xb9eabf92b8e8a6785099d584534e4628 Finished request 9. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=149 Cleaning up request 9 ID 0 with timestamp +34 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 State = 0xb9eabf92b8e8a6785099d584534e4628 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020200061900 Message-Authenticator = 0xfe1e2747ea8a8039782c6468ea137d03 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 2 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake fragment handler [peap] eaptls_verify returned 1 [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x0103007219006ba1f3617af17faa839bb107f4669a1b544cad39f8a72179d3112d2363107a1091e0c800604227adb4b3a4b481cf46b4d7a418293759003a90b1168135be9d2dcdd5d6bc256009e09ea3a6ad0cc7484c093ab07ab1bc4f59ca78b71db2f29be2abd40016030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xb9eabf92bbe9a6785099d584534e4628 Finished request 10. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=287 Cleaning up request 10 ID 0 with timestamp +34 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 State = 0xb9eabf92bbe9a6785099d584534e4628 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x0203009019800000008616030100461000004241046dac51c702fd73d3a2a9a31f53602d1d861a63434d691ed70342ddf9a52dc2d0b17d55857dce5e26f9ccbe4a5343328f12e6e4c8c81cb2c9986b05a3652d03f71403010001011603010030ab82bc66dfed6090d832610f1a23b6ad6cb8a8150446e7c9a48b9521778064c8c3a52a041abd42ef884e3aadd6912686 Message-Authenticator = 0x9494378e4e1dae045be5ffbdf3bfcc26 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 3 length 144 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS TLS Length 134 [peap] Length Included [peap] eaptls_verify returned 11 [peap] <<< TLS 1.0 Handshake [length 0046], ClientKeyExchange [peap] TLS_accept: SSLv3 read client key exchange A [peap] <<< TLS 1.0 ChangeCipherSpec [length 0001] [peap] <<< TLS 1.0 Handshake [length 0010], Finished [peap] TLS_accept: SSLv3 read finished A [peap] >>> TLS 1.0 ChangeCipherSpec [length 0001] [peap] TLS_accept: SSLv3 write change cipher spec A [peap] >>> TLS 1.0 Handshake [length 0010], Finished [peap] TLS_accept: SSLv3 write finished A [peap] TLS_accept: SSLv3 flush data [peap] (other): SSL negotiation finished successfully SSL Connection Established [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x01040041190014030100010116030100307f0ca0e41a1e806136660d99e2947b3c396ed0835f0fdba2723d3736753d02b586ed3bd278527268cb646501c31e6d4f Message-Authenticator = 0x00000000000000000000000000000000 State = 0xb9eabf92baeea6785099d584534e4628 Finished request 11. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=149 Cleaning up request 11 ID 0 with timestamp +35 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 State = 0xb9eabf92baeea6785099d584534e4628 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020400061900 Message-Authenticator = 0xee9d5d92b3eb1fc4def4ed5522511b08 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 4 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake is finished [peap] eaptls_verify returned 3 [peap] eaptls_process returned 3 [peap] EAPTLS_SUCCESS [peap] Session established. Decoding tunneled attributes. [peap] Peap state TUNNEL ESTABLISHED ++[eap] returns handled Sending Access-Challenge of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x0105002b19001703010020cde6414def356c1e04ac07efc233ea75001725e19a36cdcc017f968df772d7a6 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xb9eabf92bdefa6785099d584534e4628 Finished request 12. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=239 Cleaning up request 12 ID 0 with timestamp +35 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 State = 0xb9eabf92bdefa6785099d584534e4628 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x0205006019001703010020f3d69103ab3df25c3bce44119edb139ed89d1dbe09c97c74f8170e00fde3d5aa17030100300684e62c1e7a0624af3dd81f5ce45b1ad365c7d2ebfd63f936ae09c0cd1d46a53996023f74a8edd74f2c1069eb0041c0 Message-Authenticator = 0x87963a4e5eb4279bf467d8050e663011 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 5 length 96 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] eaptls_verify returned 7 [peap] Done initial handshake [peap] eaptls_process returned 7 [peap] EAPTLS_OK [peap] Session established. Decoding tunneled attributes. [peap] Peap state WAITING FOR INNER IDENTITY [peap] Identity - usuario1(a)org12.es [peap] Got inner identity 'usuario1(a)org12.es' [peap] Setting default EAP type for tunneled EAP session. [peap] Got tunneled request EAP-Message = 0x02050016017573756172696f31406f726731322e6573 server { [peap] Setting User-Name to usuario1(a)org12.es Sending tunneled request EAP-Message = 0x02050016017573756172696f31406f726731322e6573 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "usuario1(a)org12.es" server inner-tunnel { # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel +- entering group authorize {...} ++[chap] returns noop ++[mschap] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok ++[control] returns ok [eap] EAP packet type response id 5 length 22 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [ldap] performing user authorization for usuario1 [ldap] expand: %{Stripped-User-Name} -> usuario1 [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=usuario1) [ldap] expand: dc=org12,dc=es -> dc=org12,dc=es [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in dc=org12,dc=es, with filter (uid=usuario1) [ldap] No default NMAS login sequence [ldap] looking for check items in directory... [ldap] userPassword -> Password-With-Header == "{MD5}EitzhgCg9098MxwO9ZvDTA==" [ldap] userPassword -> Password-With-Header == "usuario11" [ldap] looking for reply items in directory... [ldap] user usuario1 authorized to use remote access [ldap] ldap_release_conn: Release Id: 0 ++[ldap] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] Failed to decode Password-With-Header = "usuario11" [pap] Normalizing MD5-Password from base64 encoding [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel +- entering group authenticate {...} [eap] EAP Identity [eap] processing type mschapv2 rlm_eap_mschapv2: Issuing Challenge ++[eap] returns handled } # server inner-tunnel [peap] Got tunneled reply code 11 EAP-Message = 0x0106002b1a0106002610480fa33ca145b34833f1e226adb9e5f77573756172696f31406f726731322e6573 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf3a28b53f3a49133d9c4f4610c3da827 [peap] Got tunneled reply RADIUS code 11 EAP-Message = 0x0106002b1a0106002610480fa33ca145b34833f1e226adb9e5f77573756172696f31406f726731322e6573 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf3a28b53f3a49133d9c4f4610c3da827 [peap] Got tunneled Access-Challenge ++[eap] returns handled Sending Access-Challenge of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x0106004b19001703010040e1aec1d4ebbdf5675b055149b10cd1f010ab26b71363438e15084553f9d06f31df842f0521892d0c188e83be485d2cdac1366dc8508052a4b8d852735d5de459 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xb9eabf92bceca6785099d584534e4628 Finished request 13. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=287 Cleaning up request 13 ID 0 with timestamp +35 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 State = 0xb9eabf92bceca6785099d584534e4628 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020600901900170301002057c2712347441259f45d148212223c1bfc171cddcd49d048ef2f1f9b4dd2a7231703010060d34616045b2144ccb6270f9c016227a956d65eaea91ddd6e2668b4339fe1546cd84b868402de263dcafd182dd2995339b3b491732fd05ccdb35be74c25d81f4bec0f97eddabb99542026a58c74dc2637bad14f4fa0e4624b0a2d035260e03b56 Message-Authenticator = 0x390889dce3b3521b723776a7db8ce0e1 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 6 length 144 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] eaptls_verify returned 7 [peap] Done initial handshake [peap] eaptls_process returned 7 [peap] EAPTLS_OK [peap] Session established. Decoding tunneled attributes. [peap] Peap state phase2 [peap] EAP type mschapv2 [peap] Got tunneled request EAP-Message = 0x0206004c1a0206004731ffd6fac8a92ab31862d1e3590213398f000000000000000003f92e584210e311f3f7a429da02df958548c85fff171ce7007573756172696f31406f726731322e6573 server { [peap] Setting User-Name to usuario1(a)org12.es Sending tunneled request EAP-Message = 0x0206004c1a0206004731ffd6fac8a92ab31862d1e3590213398f000000000000000003f92e584210e311f3f7a429da02df958548c85fff171ce7007573756172696f31406f726731322e6573 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "usuario1(a)org12.es" State = 0xf3a28b53f3a49133d9c4f4610c3da827 server inner-tunnel { # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel +- entering group authorize {...} ++[chap] returns noop ++[mschap] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok ++[control] returns ok [eap] EAP packet type response id 6 length 76 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [ldap] performing user authorization for usuario1 [ldap] expand: %{Stripped-User-Name} -> usuario1 [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=usuario1) [ldap] expand: dc=org12,dc=es -> dc=org12,dc=es [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in dc=org12,dc=es, with filter (uid=usuario1) [ldap] No default NMAS login sequence [ldap] looking for check items in directory... [ldap] userPassword -> Password-With-Header == "{MD5}EitzhgCg9098MxwO9ZvDTA==" [ldap] userPassword -> Password-With-Header == "usuario11" [ldap] looking for reply items in directory... [ldap] user usuario1 authorized to use remote access [ldap] ldap_release_conn: Release Id: 0 ++[ldap] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] Failed to decode Password-With-Header = "usuario11" [pap] Normalizing MD5-Password from base64 encoding [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/mschapv2 [eap] processing type mschapv2 [mschapv2] # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel [mschapv2] +- entering group MS-CHAP {...} [mschap] No Cleartext-Password configured. Cannot create LM-Password. [mschap] No Cleartext-Password configured. Cannot create NT-Password. [mschap] Creating challenge hash with username: usuario1(a)org12.es [mschap] Told to do MS-CHAPv2 for usuario1(a)org12.es with NT-Password [mschap] FAILED: No NT/LM-Password. Cannot perform authentication. [mschap] FAILED: MS-CHAP2-Response is incorrect ++[mschap] returns reject [eap] Freeing handler ++[eap] returns reject Failed to authenticate the user. } # server inner-tunnel [peap] Got tunneled reply code 3 MS-CHAP-Error = "\006E=691 R=1" EAP-Message = 0x04060004 Message-Authenticator = 0x00000000000000000000000000000000 [peap] Got tunneled reply RADIUS code 3 MS-CHAP-Error = "\006E=691 R=1" EAP-Message = 0x04060004 Message-Authenticator = 0x00000000000000000000000000000000 [peap] Tunneled authentication was rejected. [peap] FAILURE ++[eap] returns handled Sending Access-Challenge of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x0107002b19001703010020d625e2fb685cecb5fb07455b4685c4e83bbb060ed8269d8147c388b7226036f3 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xb9eabf92bfeda6785099d584534e4628 Finished request 14. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=223 Cleaning up request 14 ID 0 with timestamp +35 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 State = 0xb9eabf92bfeda6785099d584534e4628 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020700501900170301002038674637d67e0d8c2f772399a45d09144ab9d2c0f492da200bbd1f8dd26ea6eb1703010020381903cd618291a22cdd1202f3a6479e2c3e797f14c136d3dc7718f05c5d57d0 Message-Authenticator = 0x29828d9d8999ff818c0fc368bcd717ec # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 7 length 80 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] eaptls_verify returned 7 [peap] Done initial handshake [peap] eaptls_process returned 7 [peap] EAPTLS_OK [peap] Session established. Decoding tunneled attributes. [peap] Peap state send tlv failure [peap] Received EAP-TLV response. [peap] The users session was previously rejected: returning reject (again.) [peap] *** This means you need to read the PREVIOUS messages in the debug output [peap] *** to find out the reason why the user was rejected. [peap] *** Look for "reject" or "fail". Those earlier messages will tell you. [peap] *** what went wrong, and how to fix the problem. [eap] Handler failed in EAP/peap [eap] Failed in EAP select ++[eap] returns invalid Failed to authenticate the user. Using Post-Auth-Type Reject # Executing group from file /etc/freeradius/sites-enabled/default +- entering group REJECT {...} [attr_filter.access_reject] expand: %{User-Name} -> usuario1(a)org12.es attr_filter: Matched entry DEFAULT at line 11 ++[attr_filter.access_reject] returns updated Delaying reject of request 15 for 1 seconds Going to the next request Waking up in 0.9 seconds. Sending delayed reject for request 15 Sending Access-Reject of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x04070004 Message-Authenticator = 0x00000000000000000000000000000000 Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=147 Cleaning up request 15 ID 0 with timestamp +35 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x02000016017573756172696f31406f726731322e6573 Message-Authenticator = 0x89d8318a057220f20ce843dc4d0be514 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 0 length 22 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [ldap] performing user authorization for usuario1 [ldap] expand: %{Stripped-User-Name} -> usuario1 [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=usuario1) [ldap] expand: dc=org12,dc=es -> dc=org12,dc=es [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in dc=org12,dc=es, with filter (uid=usuario1) [ldap] No default NMAS login sequence [ldap] looking for check items in directory... [ldap] userPassword -> Password-With-Header == "{MD5}EitzhgCg9098MxwO9ZvDTA==" [ldap] userPassword -> Password-With-Header == "usuario11" [ldap] looking for reply items in directory... [ldap] user usuario1 authorized to use remote access [ldap] ldap_release_conn: Release Id: 0 ++[ldap] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] Failed to decode Password-With-Header = "usuario11" [pap] Normalizing MD5-Password from base64 encoding [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] EAP Identity [eap] processing type tls [tls] Initiate [tls] Start returned 1 ++[eap] returns handled Sending Access-Challenge of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x010100061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x0a30575b0a314ef77ca98eba675d1087 Finished request 16. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=343 Cleaning up request 16 ID 0 with timestamp +39 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 State = 0x0a30575b0a314ef77ca98eba675d1087 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020100c81980000000be16030100b9010000b50301566f4b26968c7b96fb3d165e7162dce3f107b441f194a954beca668947dd7f4d000048c014c00a00390038c00fc0050035c012c00800160013c00dc003000ac013c00900330032c00ec004002fc011c007c00cc002000500040015001200090014001100080006000300ff01000044000b000403000102000a00340032000100020003000400050006000700080009000a000b000c000d000e000f001000110012001300140015001600170018001900230000 Message-Authenticator = 0xc585ca4bd4e11f4acd4fb117ed609eda # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 1 length 200 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS TLS Length 190 [peap] Length Included [peap] eaptls_verify returned 11 [peap] (other): before/accept initialization [peap] TLS_accept: before/accept initialization [peap] <<< TLS 1.0 Handshake [length 00b9], ClientHello [peap] TLS_accept: SSLv3 read client hello A [peap] >>> TLS 1.0 Handshake [length 0039], ServerHello [peap] TLS_accept: SSLv3 write server hello A [peap] >>> TLS 1.0 Handshake [length 02c6], Certificate [peap] TLS_accept: SSLv3 write certificate A [peap] >>> TLS 1.0 Handshake [length 014b], ServerKeyExchange [peap] TLS_accept: SSLv3 write key exchange A [peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone [peap] TLS_accept: SSLv3 write server done A [peap] TLS_accept: SSLv3 flush data [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A In SSL Handshake Phase In SSL Accept mode [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x0102040019c0000004621603010039020000350301403dd384a38efbfcf6c7055dc4a1002ea30ef90e44b2cd5347a2e8f71125ae0500c01400000dff01000100000b00040300010216030102c60b0002c20002bf0002bc308202b8308201a0a0030201020209008e4322a719659612300d06092a864886f70d01010b0500301431123010060355040313094f312d536572766572301e170d3135313231343232303933385a170d3235313231313232303933385a301431123010060355040313094f312d53657276657230820122300d06092a864886f70d01010105000382010f003082010a0282010100aa4952ef410918d271d25e62c24a970e5a48 EAP-Message = 0x3c0d3522dd3fe3ed96edfadb3c2bdc7d7426941ccf7b6274c2516f3bfcb87db4d032d4883d8fbbb2acbbab3dd961c6fb45a100de0da286208d3f358766c1996991c32ef19cae13854c394994f1bd07072f11c21217f57859079ae71b8c1f657996cd02c886866e192b9e37ffffc78a21f946e9d9481b13dac3ee6f47e1057aa7c0c32e802b8f42abb98253c6782de98fce3dc0e5f3736ff177e1d41da6bf14ea990e69d0c58482d2b37a2e0c17afb2042223429b2d44c3e0f6b685ae06e8f2657fa4b0f1915f901c16996d951fcd01e4cde25eafa638e233822cfc4da71a9e0ab41de67cbfc421029b45df58dfb70203010001a30d300b30090603551d EAP-Message = 0x1304023000300d06092a864886f70d01010b050003820101005d5c50cacdf0bb5a076175b04f86d79aa1a19fc1ac4afeae40c90ce3b3f9a0d31b7c1488f9fd2eeb81d824833768aa71a2a1fa1f1d88881b53ed5fc774a028fe5f617a960ed8c301a1e41403949f93197408e77b0a7ddeb6cdcc8ca79e90afa95dd08e92c6cdd48a6b0916a35f6ebcc56cbe8ceda830da6d949ebecf0fa043ecafca348621466c0f59b2edc7603eb0bd710b50eea5f4d90bd33ca0fd49da2255804bbf81a3d31a0934957e7271d2a7b3a903f0c45585832079900db22ef7f99f135cf1119051dc9c4fd40ff16d5bc6ce65dbe14d0fa2aa0ba2c3777e7f24324aa28744cc EAP-Message = 0x174c25e9d2e1b28dd5a3e3b0e423617e2b1aa0127cb1510e491c7d61160301014b0c00014703001741042bb91302961cc175d99d2d0f86ea4d6bafbebba61e76e998437d8c44b5ae4b2f86f097be4d74e7a61fa4600f7e1ab6a5f162f5a13555bdfbbe1f2dde7448d34b01002a0af7171c0cc43a02872b24679f349306ab4fd43a73900eb6c9f591ceecccee9da5cc13830c1c510bee60a8270b3a7c5cf2b243ab0853f6d097e4cce1055613a3c1480e2515006ae78a1067d3101c3e297829eb7b743e4a31b3015c6f4329800f53a63315174c1baa7c4093f9797053e808e3a967a7c0bbe5429e1ce6038e80789ac90ccbd571cb44f432ea88ea63f985 EAP-Message = 0xe2b8ad336614097d8bf8c9b4 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x0a30575b0b324ef77ca98eba675d1087 Finished request 17. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=149 Cleaning up request 17 ID 0 with timestamp +39 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 State = 0x0a30575b0b324ef77ca98eba675d1087 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020200061900 Message-Authenticator = 0x5307a2707651a633280db989583f6957 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 2 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake fragment handler [peap] eaptls_verify returned 1 [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x0103007219005be69beb94112150fde344c1f01ef5d0228a30e6a69d4e2642b8e20275714620286b0dfc6ab44ad4927cc6742e333fb4f48e0e7d7a341a6df57e0472e7b44bd04f88a7f253f931d44ac0566accf716c032990f691caf6705e7b0b32d9b1b74016d4c6016030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x0a30575b08334ef77ca98eba675d1087 Finished request 18. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=287 Cleaning up request 18 ID 0 with timestamp +39 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 State = 0x0a30575b08334ef77ca98eba675d1087 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020300901980000000861603010046100000424104ef751666c20169b40a28850ad8ff8a105af583269140533847dcdf8edb88a3114b55fa3f661080452e2fe78852fd7bf5435a6f9742e7663a5706521941169bab140301000101160301003011dbb46b82e8bf5783e4a7ab46d89b38a212554505399728e21d709eaf2937b7ab22c236d78d4f195a149f1a05a7e3c4 Message-Authenticator = 0xbb140038c1f82140f31417ad57fc300f # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 3 length 144 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS TLS Length 134 [peap] Length Included [peap] eaptls_verify returned 11 [peap] <<< TLS 1.0 Handshake [length 0046], ClientKeyExchange [peap] TLS_accept: SSLv3 read client key exchange A [peap] <<< TLS 1.0 ChangeCipherSpec [length 0001] [peap] <<< TLS 1.0 Handshake [length 0010], Finished [peap] TLS_accept: SSLv3 read finished A [peap] >>> TLS 1.0 ChangeCipherSpec [length 0001] [peap] TLS_accept: SSLv3 write change cipher spec A [peap] >>> TLS 1.0 Handshake [length 0010], Finished [peap] TLS_accept: SSLv3 write finished A [peap] TLS_accept: SSLv3 flush data [peap] (other): SSL negotiation finished successfully SSL Connection Established [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x0104004119001403010001011603010030588da872c692a358359d8fd0f4fb3758b50f64175e5de43736efedc7f47e1dfd831ad3e405bf32d9118d50b6b201c539 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x0a30575b09344ef77ca98eba675d1087 Finished request 19. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=149 Cleaning up request 19 ID 0 with timestamp +39 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 State = 0x0a30575b09344ef77ca98eba675d1087 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020400061900 Message-Authenticator = 0x91b81060d20b865489f5ae64692d7d67 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 4 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake is finished [peap] eaptls_verify returned 3 [peap] eaptls_process returned 3 [peap] EAPTLS_SUCCESS [peap] Session established. Decoding tunneled attributes. [peap] Peap state TUNNEL ESTABLISHED ++[eap] returns handled Sending Access-Challenge of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x0105002b19001703010020c60ce8afa449fe0b5b5f53b0d2a3920d397e8a83e4fa12fe09cf85e7051bf1c8 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x0a30575b0e354ef77ca98eba675d1087 Finished request 20. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=239 Cleaning up request 20 ID 0 with timestamp +39 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 State = 0x0a30575b0e354ef77ca98eba675d1087 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020500601900170301002042c364230c03ac7525b392d04282114bc68c1911b9d37ca4f57cc6c07350bf4217030100300e28c0029551e3e58e28c1de10121d60451a4a0ddcfc42519ff76dc35d9316383296e14832befa8b4bfed5fec3f20ba5 Message-Authenticator = 0xec3ff31b59c371099bd0ea66a030ce29 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 5 length 96 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] eaptls_verify returned 7 [peap] Done initial handshake [peap] eaptls_process returned 7 [peap] EAPTLS_OK [peap] Session established. Decoding tunneled attributes. [peap] Peap state WAITING FOR INNER IDENTITY [peap] Identity - usuario1(a)org12.es [peap] Got inner identity 'usuario1(a)org12.es' [peap] Setting default EAP type for tunneled EAP session. [peap] Got tunneled request EAP-Message = 0x02050016017573756172696f31406f726731322e6573 server { [peap] Setting User-Name to usuario1(a)org12.es Sending tunneled request EAP-Message = 0x02050016017573756172696f31406f726731322e6573 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "usuario1(a)org12.es" server inner-tunnel { # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel +- entering group authorize {...} ++[chap] returns noop ++[mschap] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok ++[control] returns ok [eap] EAP packet type response id 5 length 22 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [ldap] performing user authorization for usuario1 [ldap] expand: %{Stripped-User-Name} -> usuario1 [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=usuario1) [ldap] expand: dc=org12,dc=es -> dc=org12,dc=es [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in dc=org12,dc=es, with filter (uid=usuario1) [ldap] No default NMAS login sequence [ldap] looking for check items in directory... [ldap] userPassword -> Password-With-Header == "{MD5}EitzhgCg9098MxwO9ZvDTA==" [ldap] userPassword -> Password-With-Header == "usuario11" [ldap] looking for reply items in directory... [ldap] user usuario1 authorized to use remote access [ldap] ldap_release_conn: Release Id: 0 ++[ldap] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] Failed to decode Password-With-Header = "usuario11" [pap] Normalizing MD5-Password from base64 encoding [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel +- entering group authenticate {...} [eap] EAP Identity [eap] processing type mschapv2 rlm_eap_mschapv2: Issuing Challenge ++[eap] returns handled } # server inner-tunnel [peap] Got tunneled reply code 11 EAP-Message = 0x0106002b1a01060026107d1f79522e66c33923d1e2c3a75ba2ba7573756172696f31406f726731322e6573 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xb3fa35c1b3fc2f2801cccb1af11b0eff [peap] Got tunneled reply RADIUS code 11 EAP-Message = 0x0106002b1a01060026107d1f79522e66c33923d1e2c3a75ba2ba7573756172696f31406f726731322e6573 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xb3fa35c1b3fc2f2801cccb1af11b0eff [peap] Got tunneled Access-Challenge ++[eap] returns handled Sending Access-Challenge of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x0106004b19001703010040ab6ac1b529d43c7097e4a669eac3aef098049e010116857f4748afec75335e8fb3ac6979c85cfc654872c00f90ff9195fb48c148d183cc4aff1c4f66e6d305b4 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x0a30575b0f364ef77ca98eba675d1087 Finished request 21. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=287 Cleaning up request 21 ID 0 with timestamp +39 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 State = 0x0a30575b0f364ef77ca98eba675d1087 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x0206009019001703010020595da414692d74a1eb2b803a26baa62330ed09ce2757ddebcc7ef187f4da7b2617030100608e0dd5591ca9df9fb9ac6bd71bbb3db1825530919167a0f414df2f147f29b37e616b117eb246ae4cd9b6215fb11861f68660ce18aed6d287804d97b8b59071edb3b570c2d568c642883f14482c899adfde65b5a42b0259ae8f8ac8e749ebedd8 Message-Authenticator = 0x2e34f875787f955b6fe4e24b516697af # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 6 length 144 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] eaptls_verify returned 7 [peap] Done initial handshake [peap] eaptls_process returned 7 [peap] EAPTLS_OK [peap] Session established. Decoding tunneled attributes. [peap] Peap state phase2 [peap] EAP type mschapv2 [peap] Got tunneled request EAP-Message = 0x0206004c1a0206004731aa9c531ef9109cc18c1bf016441558950000000000000000d8ac264da19e978ae8ddb7299bff1cf87858b84d53eebf3e007573756172696f31406f726731322e6573 server { [peap] Setting User-Name to usuario1(a)org12.es Sending tunneled request EAP-Message = 0x0206004c1a0206004731aa9c531ef9109cc18c1bf016441558950000000000000000d8ac264da19e978ae8ddb7299bff1cf87858b84d53eebf3e007573756172696f31406f726731322e6573 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "usuario1(a)org12.es" State = 0xb3fa35c1b3fc2f2801cccb1af11b0eff server inner-tunnel { # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel +- entering group authorize {...} ++[chap] returns noop ++[mschap] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok ++[control] returns ok [eap] EAP packet type response id 6 length 76 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [ldap] performing user authorization for usuario1 [ldap] expand: %{Stripped-User-Name} -> usuario1 [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=usuario1) [ldap] expand: dc=org12,dc=es -> dc=org12,dc=es [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in dc=org12,dc=es, with filter (uid=usuario1) [ldap] No default NMAS login sequence [ldap] looking for check items in directory... [ldap] userPassword -> Password-With-Header == "{MD5}EitzhgCg9098MxwO9ZvDTA==" [ldap] userPassword -> Password-With-Header == "usuario11" [ldap] looking for reply items in directory... [ldap] user usuario1 authorized to use remote access [ldap] ldap_release_conn: Release Id: 0 ++[ldap] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] Failed to decode Password-With-Header = "usuario11" [pap] Normalizing MD5-Password from base64 encoding [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/mschapv2 [eap] processing type mschapv2 [mschapv2] # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel [mschapv2] +- entering group MS-CHAP {...} [mschap] No Cleartext-Password configured. Cannot create LM-Password. [mschap] No Cleartext-Password configured. Cannot create NT-Password. [mschap] Creating challenge hash with username: usuario1(a)org12.es [mschap] Told to do MS-CHAPv2 for usuario1(a)org12.es with NT-Password [mschap] FAILED: No NT/LM-Password. Cannot perform authentication. [mschap] FAILED: MS-CHAP2-Response is incorrect ++[mschap] returns reject [eap] Freeing handler ++[eap] returns reject Failed to authenticate the user. } # server inner-tunnel [peap] Got tunneled reply code 3 MS-CHAP-Error = "\006E=691 R=1" EAP-Message = 0x04060004 Message-Authenticator = 0x00000000000000000000000000000000 [peap] Got tunneled reply RADIUS code 3 MS-CHAP-Error = "\006E=691 R=1" EAP-Message = 0x04060004 Message-Authenticator = 0x00000000000000000000000000000000 [peap] Tunneled authentication was rejected. [peap] FAILURE ++[eap] returns handled Sending Access-Challenge of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x0107002b1900170301002081b02fd0c5fe8561d5b8b3bba0281a2263863f2593b482dd79c5d9d20d1bff13 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x0a30575b0c374ef77ca98eba675d1087 Finished request 22. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=223 Cleaning up request 22 ID 0 with timestamp +39 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 State = 0x0a30575b0c374ef77ca98eba675d1087 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x0207005019001703010020c6605c184c417a712dd563647207fd2364661cea07c83f18372fe46a232e3aee17030100209555831077081970d21cd47dbfb67396e25c95f088be53f2be0d64446c48b94a Message-Authenticator = 0x63d5e273bad764fb0769d03662a86a5e # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 7 length 80 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] eaptls_verify returned 7 [peap] Done initial handshake [peap] eaptls_process returned 7 [peap] EAPTLS_OK [peap] Session established. Decoding tunneled attributes. [peap] Peap state send tlv failure [peap] Received EAP-TLV response. [peap] The users session was previously rejected: returning reject (again.) [peap] *** This means you need to read the PREVIOUS messages in the debug output [peap] *** to find out the reason why the user was rejected. [peap] *** Look for "reject" or "fail". Those earlier messages will tell you. [peap] *** what went wrong, and how to fix the problem. [eap] Handler failed in EAP/peap [eap] Failed in EAP select ++[eap] returns invalid Failed to authenticate the user. Using Post-Auth-Type Reject # Executing group from file /etc/freeradius/sites-enabled/default +- entering group REJECT {...} [attr_filter.access_reject] expand: %{User-Name} -> usuario1(a)org12.es attr_filter: Matched entry DEFAULT at line 11 ++[attr_filter.access_reject] returns updated Delaying reject of request 23 for 1 seconds Going to the next request Waking up in 0.9 seconds. Sending delayed reject for request 23 Sending Access-Reject of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x04070004 Message-Authenticator = 0x00000000000000000000000000000000 Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.12.254 port 2060, id=0, length=147 Cleaning up request 23 ID 0 with timestamp +39 User-Name = "usuario1(a)org12.es" NAS-IP-Address = 192.168.12.254 Called-Station-Id = "001217dd4db7" Calling-Station-Id = "04fe31a20d46" NAS-Identifier = "001217dd4db7" NAS-Port = 41 Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x02000016017573756172696f31406f726731322e6573 Message-Authenticator = 0x30574f38f01c55998fe3d3a710aa82ac # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] Looking up realm "org12.es" for User-Name = "usuario1(a)org12.es" [suffix] Found realm "org12.es" [suffix] Adding Stripped-User-Name = "usuario1" [suffix] Adding Realm = "org12.es" [suffix] Authentication realm is LOCAL. ++[suffix] returns ok [eap] EAP packet type response id 0 length 22 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [ldap] performing user authorization for usuario1 [ldap] expand: %{Stripped-User-Name} -> usuario1 [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=usuario1) [ldap] expand: dc=org12,dc=es -> dc=org12,dc=es [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] performing search in dc=org12,dc=es, with filter (uid=usuario1) [ldap] No default NMAS login sequence [ldap] looking for check items in directory... [ldap] userPassword -> Password-With-Header == "{MD5}EitzhgCg9098MxwO9ZvDTA==" [ldap] userPassword -> Password-With-Header == "usuario11" [ldap] looking for reply items in directory... [ldap] user usuario1 authorized to use remote access [ldap] ldap_release_conn: Release Id: 0 ++[ldap] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] Failed to decode Password-With-Header = "usuario11" [pap] Normalizing MD5-Password from base64 encoding [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] EAP Identity [eap] processing type tls [tls] Initiate [tls] Start returned 1 ++[eap] returns handled Sending Access-Challenge of id 0 to 192.168.12.254 port 2060 EAP-Message = 0x010100061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x1acccdae1acdd4099df112bd40fc8d8e Finished request 24. Going to the next request Waking up in 4.9 seconds. Cleaning up request 24 ID 0 with timestamp +45 WARNING: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! WARNING: !! EAP session for state 0x1acccdae1acdd409 did not finish! WARNING: !! Please read http://wiki.freeradius.org/Certificate_Compatibility WARNING: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Ready to process requests.

2 1