Hello, I'm using FreeRADIUS version 2.1.10 I would like to return diferent values of a personal atribute (Codigo-Reject) in a Access-Reject. I would like to do this in PEAPv0, EAP-TTLS-PAP and EAP-TTLS-MsCHAPv2 With my configuration I can return Codigo-Reject in EAP-TTLS-PAP and EAP-TTLS-MsCHAPv2 but I can't in PEAP. My config: cat /etc/freeradius/users ... DEFAULT Intentos-Reject > 10, Auth-Type := Reject Reply-Message += "NUMERO DE INTENTOS FALLIDOS (%{Intentos-Reject}) EXCEDIDO PARA %{%{Stripped-User-Name}:-%{ User-Name}}", Codigo-Reject = Cuenta-Bloqueada-Intentos-Reject, Fall-Through = yes ... cat /etc/freeradius/sites-enabled/e server e { authorize { auth_log suffix files eap { ok = return } } authenticate { eap } post-auth { ... Post-Auth-Type REJECT { update reply { Codigo-Reject = Credenciales-Erroneas } sql{ fail=1 } if (fail) { ... } } #server e cat /etc/freeradius/sites-enabled/inner-tunnel server inner-tunnel { authorize { update outer.request { User-Name := "%u" } mschap auth_log suffix update control { Proxy-To-Realm := LOCAL } eap { ok = return } if ("%{Realm}"=='test.es'){ update request { Intentos-Reject = "%{sql:SELECT COUNT(*) from radpostauth WHERE username = '%{User-Name}' AND authdate > CURRENT_DATE and reply = 'Access-Reject'}" Intentos-Reject += "%{sqlradiusba:SELECT COUNT(*) from radpostauth WHERE username = '%{User-Name}' AND authdate > CURRENT_DATE and reply = 'Access-Reject'}" } } files if ("%{control:Auth-Type}" == 'Reject') { update outer.reply { Codigo-Reject = "%{reply:Codigo-Reject}" } reject } ... pap } authenticate { Auth-Type PAP { pap } Auth-Type MS-CHAP { mschap } eap } post-auth { sql{ fail=1 } if (fail) { ... } reply_log } } # -inner-tunnel server block LOG EAP-TTLS-PAP: Fri Aug 24 13:37:07 2012 : Info: [ttls] Got tunneled request User-Name = "prueba@test.es" User-Password = "530" FreeRADIUS-Proxied-To = 127.0.0.1 Fri Aug 24 13:37:07 2012 : Info: [ttls] Sending tunneled request User-Name = "prueba@test.es" User-Password = "530" FreeRADIUS-Proxied-To = 127.0.0.1 NAS-IP-Address = 127.0.0.1 Calling-Station-Id = "02:00:00:00:00:01" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" server inner-tunnel { Fri Aug 24 13:37:07 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel Fri Aug 24 13:37:07 2012 : Info: +- entering group authorize {...} Fri Aug 24 13:37:07 2012 : Info: expand: %u -> prueba@test.es Fri Aug 24 13:37:07 2012 : Info: ++[outer.request] returns notfound Fri Aug 24 13:37:07 2012 : Info: ++[mschap] returns noop Fri Aug 24 13:37:07 2012 : Info: [auth_log] expand: /var/log/freeradius/radacct/%Y/%m/%d/%{Client-IP-Address}-auth-detail-%Y%m%d -> /var/log/freeradius/radacct/2012/08/24/1.2.3.4-auth-detail-20120824 Fri Aug 24 13:37:07 2012 : Info: [auth_log] /var/log/freeradius/radacct/%Y/%m/%d/%{Client-IP-Address}-auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/2012/08/24/1.2.3.4-auth-detail-20120824 Fri Aug 24 13:37:07 2012 : Info: [auth_log] expand: %t -> Fri Aug 24 13:37:07 2012 Fri Aug 24 13:37:07 2012 : Info: ++[auth_log] returns ok Fri Aug 24 13:37:07 2012 : Info: [suffix] Looking up realm "test.es" for User-Name = "prueba@test.es" Fri Aug 24 13:37:07 2012 : Info: [suffix] Found realm "test.es" Fri Aug 24 13:37:07 2012 : Info: [suffix] Adding Stripped-User-Name = "prueba" Fri Aug 24 13:37:07 2012 : Info: [suffix] Adding Realm = "test.es" Fri Aug 24 13:37:07 2012 : Info: [suffix] Authentication realm is LOCAL. Fri Aug 24 13:37:07 2012 : Info: ++[suffix] returns ok Fri Aug 24 13:37:07 2012 : Info: ++[control] returns ok Fri Aug 24 13:37:07 2012 : Info: [eap] No EAP-Message, not doing EAP Fri Aug 24 13:37:07 2012 : Info: ++[eap] returns noop Fri Aug 24 13:37:07 2012 : Info: ++? if ("%{Realm}"=='test.es') Fri Aug 24 13:37:07 2012 : Info: expand: %{Realm} -> test.es Fri Aug 24 13:37:07 2012 : Info: ?? Evaluating ("%{Realm}"=='test.es') -> TRUE Fri Aug 24 13:37:07 2012 : Info: ++? if ("%{Realm}"=='test.es') -> TRUE Fri Aug 24 13:37:07 2012 : Info: ++- entering if ("%{Realm}"=='test.es') {...} Fri Aug 24 13:37:07 2012 : Info: sql_xlat Fri Aug 24 13:37:07 2012 : Info: expand: %{Stripped-User-Name} -> prueba Fri Aug 24 13:37:07 2012 : Info: expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> prueba Fri Aug 24 13:37:07 2012 : Info: sql_set_user escaped user --> 'prueba' Fri Aug 24 13:37:07 2012 : Info: expand: SELECT COUNT(*) from radpostauth WHERE username = '%{User-Name}' AND authdate > CURRENT_DATE and reply = 'Access-Reject' -> SELECT COUNT(*) from radpostauth WHERE username = 'prueba@test.es' AND authdate > CURRENT_DATE and reply = 'Access-Reject' Fri Aug 24 13:37:07 2012 : Debug: rlm_sql (sql): Reserving sql socket id: 3 Fri Aug 24 13:37:07 2012 : Info: sql_xlat finished Fri Aug 24 13:37:07 2012 : Debug: rlm_sql (sql): Released sql socket id: 3 Fri Aug 24 13:37:07 2012 : Info: expand: %{sql:SELECT COUNT(*) from radpostauth WHERE username = '%{User-Name}' AND authdate > CURRENT_DATE and reply = 'Access-Reject'} -> 26 Fri Aug 24 13:37:07 2012 : Info: sql_xlat Fri Aug 24 13:37:07 2012 : Info: expand: %{Stripped-User-Name} -> prueba Fri Aug 24 13:37:07 2012 : Info: expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> prueba Fri Aug 24 13:37:07 2012 : Info: sql_set_user escaped user --> 'prueba' Fri Aug 24 13:37:07 2012 : Info: expand: SELECT COUNT(*) from radpostauth WHERE username = '%{User-Name}' AND authdate > CURRENT_DATE and reply = 'Access-Reject' -> SELECT COUNT(*) from radpostauth WHERE username = 'prueba@test.es' AND authdate > CURRENT_DATE and reply = 'Access-Reject' Fri Aug 24 13:37:07 2012 : Debug: rlm_sql (sqlradiusba): Reserving sql socket id: 4 Fri Aug 24 13:37:08 2012 : Info: sql_xlat finished Fri Aug 24 13:37:08 2012 : Debug: rlm_sql (sqlradiusba): Released sql socket id: 4 Fri Aug 24 13:37:08 2012 : Info: expand: %{sqlradiusba:SELECT COUNT(*) from radpostauth WHERE username = '%{User-Name}' AND authdate > CURRENT_DATE and reply = 'Access-Reject'} -> 0 Fri Aug 24 13:37:08 2012 : Info: +++[request] returns noop Fri Aug 24 13:37:08 2012 : Info: ++- if ("%{Realm}"=='test.es') returns noop Fri Aug 24 13:37:08 2012 : Info: [files] users: Matched entry DEFAULT at line 29 Fri Aug 24 13:37:08 2012 : Info: [files] expand: %{Stripped-User-Name} -> prueba Fri Aug 24 13:37:08 2012 : Info: [files] expand: NUMERO DE INTENTOS FALLIDOS (%{Intentos-Reject}) EXCEDIDO PARA %{%{Stripped-User-Name}:-%{User-Name}} -> NUMERO DE INTENTOS FALLIDOS (26) EXCEDIDO PARA prueba Fri Aug 24 13:37:08 2012 : Info: [files] users: Matched entry DEFAULT at line 36 Fri Aug 24 13:37:08 2012 : Info: ++[files] returns ok Fri Aug 24 13:37:08 2012 : Info: ++? if ("%{control:Auth-Type}" == 'Reject') Fri Aug 24 13:37:08 2012 : Info: expand: %{control:Auth-Type} -> Reject Fri Aug 24 13:37:08 2012 : Info: ? Evaluating ("%{control:Auth-Type}" == 'Reject') -> TRUE Fri Aug 24 13:37:08 2012 : Info: ++? if ("%{control:Auth-Type}" == 'Reject') -> TRUE Fri Aug 24 13:37:08 2012 : Info: ++- entering if ("%{control:Auth-Type}" == 'Reject') {...} Fri Aug 24 13:37:08 2012 : Info: expand: %{reply:Codigo-Reject} -> Cuenta-Bloqueada-Intentos-Reject Fri Aug 24 13:37:08 2012 : Info: +++[outer.reply] returns ok Fri Aug 24 13:37:08 2012 : Info: +++[reject] returns reject Fri Aug 24 13:37:08 2012 : Info: ++- if ("%{control:Auth-Type}" == 'Reject') returns reject } # server inner-tunnel Fri Aug 24 13:37:08 2012 : Info: [ttls] Got tunneled reply code 3 Reply-Message += "NUMERO DE INTENTOS FALLIDOS (26) EXCEDIDO PARA prueba" Codigo-Reject = Cuenta-Bloqueada-Intentos-Reject Fri Aug 24 13:37:08 2012 : Info: [ttls] Got tunneled Access-Reject Fri Aug 24 13:37:08 2012 : Info: [eap] Handler failed in EAP/ttls Fri Aug 24 13:37:08 2012 : Info: [eap] Failed in EAP select Fri Aug 24 13:37:08 2012 : Info: ++[eap] returns invalid Fri Aug 24 13:37:08 2012 : Info: Failed to authenticate the user. Fri Aug 24 13:37:08 2012 : Info: } # server Fri Aug 24 13:37:08 2012 : Info: Using Post-Auth-Type Reject Fri Aug 24 13:37:08 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/ Fri Aug 24 13:37:08 2012 : Info: +- entering group REJECT {...} Fri Aug 24 13:37:08 2012 : Info: ++[reply] returns noop Fri Aug 24 13:37:08 2012 : Info: [sql] expand: %{Stripped-User-Name} -> Fri Aug 24 13:37:08 2012 : Info: [sql] ... expanding second conditional Fri Aug 24 13:37:08 2012 : Info: [sql] expand: %{User-Name} -> prueba@test.es Fri Aug 24 13:37:08 2012 : Info: [sql] expand: %{%{User-Name}:-DEFAULT} -> prueba@test.es Fri Aug 24 13:37:08 2012 : Info: [sql] expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> prueba@test.es Fri Aug 24 13:37:08 2012 : Info: [sql] sql_set_user escaped user --> ' prueba@test.es' Fri Aug 24 13:37:08 2012 : Info: [sql] expand: INSERT INTO radpostauth (username, mac, client, reply, authdate,codreject,radauth) VALUES ( LOWER('%{User-Name}'), LOWER('%i'), '%C', '%{reply:Packet-Type}', NOW(), '%{reply:Codigo-Reject}','radiuscc') -> INSERT INTO radpostauth (username, mac, client, reply, authdate,codreject,radauth) VALUES ( LOWER('prueba@test.es'), LOWER('02:00:00:00:00:01'), 'CAU1', 'Access-Reject', NOW(), 'Cuenta-Bloqueada-Intentos-Reject','radiuscc') Fri Aug 24 13:37:08 2012 : Debug: rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, mac, client, reply, authdate,codreject,radauth) VALUES ( LOWER('prueba@test.es'), LOWER('02:00:00:00:00:01'), 'CAU1', 'Access-Reject', NOW(), 'Cuenta-Bloqueada-Intentos-Reject','radiuscc') Fri Aug 24 13:37:08 2012 : Debug: rlm_sql (sql): Reserving sql socket id: 2 Fri Aug 24 13:37:08 2012 : Debug: rlm_sql (sql): Released sql socket id: 2 Fri Aug 24 13:37:08 2012 : Info: ++[sql] returns ok Fri Aug 24 13:37:08 2012 : Info: ++? if (fail) Fri Aug 24 13:37:08 2012 : Info: ? Evaluating (fail) -> FALSE Fri Aug 24 13:37:08 2012 : Info: ++? if (fail) -> FALSE Sending Access-Reject of id 8 to 1.2.3.4 port 53575 Codigo-Reject = Cuenta-Bloqueada-Intentos-Reject EAP-Message = 0x04080004 Message-Authenticator = 0x00000000000000000000000000000000 LOG PEAP: Fri Aug 24 13:20:41 2012 : Debug: PEAP: Setting User-Name to prueba@test.es Sending tunneled request EAP-Message = 0x0208001501303237343736333240756e65782e6573 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "prueba@test.es" NAS-IP-Address = 2.2.2.2 NAS-Port-Type = Wireless-802.11 NAS-Port = 2 Framed-MTU = 1400 Calling-Station-Id = "C4:46:19:75:7B:B1" Called-Station-Id = "00-18-6E-D0-EC-04" NAS-Identifier = "Enterprise Wireless AP" server inner-tunnel { Fri Aug 24 13:20:41 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel Fri Aug 24 13:20:41 2012 : Info: +- entering group authorize {...} Fri Aug 24 13:20:41 2012 : Info: expand: %u -> prueba@test.es Fri Aug 24 13:20:41 2012 : Info: ++[outer.request] returns notfound Fri Aug 24 13:20:41 2012 : Info: ++[mschap] returns noop Fri Aug 24 13:20:41 2012 : Info: [auth_log] expand: /var/log/freeradius/radacct/%Y/%m/%d/%{Client-IP-Address}-auth-detail-%Y%m%d -> /var/log/freeradius/radacct/2012/08/24/2.2.2.2-auth-detail-20120824 Fri Aug 24 13:20:41 2012 : Info: [auth_log] /var/log/freeradius/radacct/%Y/%m/%d/%{Client-IP-Address}-auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/2012/08/24/2.2.2.2-auth-detail-20120824 Fri Aug 24 13:20:41 2012 : Info: [auth_log] expand: %t -> Fri Aug 24 13:20:41 2012 Fri Aug 24 13:20:41 2012 : Info: ++[auth_log] returns ok Fri Aug 24 13:20:41 2012 : Info: [suffix] Looking up realm "test.es" for User-Name = "prueba@test.es" Fri Aug 24 13:20:41 2012 : Info: [suffix] Found realm "test.es" Fri Aug 24 13:20:41 2012 : Info: [suffix] Adding Stripped-User-Name = "prueba" Fri Aug 24 13:20:41 2012 : Info: [suffix] Adding Realm = "test.es" Fri Aug 24 13:20:41 2012 : Info: [suffix] Authentication realm is LOCAL. Fri Aug 24 13:20:41 2012 : Info: ++[suffix] returns ok Fri Aug 24 13:20:41 2012 : Info: ++[control] returns ok Fri Aug 24 13:20:41 2012 : Info: [eap] EAP packet type response id 8 length 21 Fri Aug 24 13:20:41 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Fri Aug 24 13:20:41 2012 : Info: ++[eap] returns updated Fri Aug 24 13:20:41 2012 : Info: ++? if ("%{Realm}"=='test.es') Fri Aug 24 13:20:41 2012 : Info: expand: %{Realm} -> test.es Fri Aug 24 13:20:41 2012 : Info: ?? Evaluating ("%{Realm}"=='test.es') -> TRUE Fri Aug 24 13:20:41 2012 : Info: ++? if ("%{Realm}"=='test.es') -> TRUE Fri Aug 24 13:20:41 2012 : Info: ++- entering if ("%{Realm}"=='test.es') {...} Fri Aug 24 13:20:41 2012 : Info: sql_xlat Fri Aug 24 13:20:41 2012 : Info: expand: %{Stripped-User-Name} -> prueba Fri Aug 24 13:20:41 2012 : Info: expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> prueba Fri Aug 24 13:20:41 2012 : Info: sql_set_user escaped user --> 'prueba' Fri Aug 24 13:20:41 2012 : Info: expand: SELECT COUNT(*) from radpostauth WHERE username = '%{User-Name}' AND authdate > CURRENT_DATE and reply = 'Access-Reject' -> SELECT COUNT(*) from radpostauth WHERE username = 'prueba@test.es' AND authdate > CURRENT_DATE and reply = 'Access-Reject' Fri Aug 24 13:20:41 2012 : Debug: rlm_sql (sql): Reserving sql socket id: 3 Fri Aug 24 13:20:42 2012 : Info: sql_xlat finished Fri Aug 24 13:20:42 2012 : Debug: rlm_sql (sql): Released sql socket id: 3 Fri Aug 24 13:20:42 2012 : Info: expand: %{sql:SELECT COUNT(*) from radpostauth WHERE username = '%{User-Name}' AND authdate > CURRENT_DATE and reply = 'Access-Reject'} -> 7 Fri Aug 24 13:20:42 2012 : Info: sql_xlat Fri Aug 24 13:20:42 2012 : Info: expand: %{Stripped-User-Name} -> prueba Fri Aug 24 13:20:42 2012 : Info: expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> prueba Fri Aug 24 13:20:42 2012 : Info: sql_set_user escaped user --> 'prueba' Fri Aug 24 13:20:42 2012 : Info: expand: SELECT COUNT(*) from radpostauth WHERE username = '%{User-Name}' AND authdate > CURRENT_DATE and reply = 'Access-Reject' -> SELECT COUNT(*) from radpostauth WHERE username = 'prueba@test.es' AND authdate > CURRENT_DATE and reply = 'Access-Reject' Fri Aug 24 13:20:42 2012 : Debug: rlm_sql (sqlradiusba): Reserving sql socket id: 4 Fri Aug 24 13:20:42 2012 : Info: sql_xlat finished Fri Aug 24 13:20:42 2012 : Debug: rlm_sql (sqlradiusba): Released sql socket id: 4 Fri Aug 24 13:20:42 2012 : Info: expand: %{sqlradiusba:SELECT COUNT(*) from radpostauth WHERE username = '%{User-Name}' AND authdate > CURRENT_DATE and reply = 'Access-Reject'} -> 0 Fri Aug 24 13:20:42 2012 : Info: +++[request] returns updated Fri Aug 24 13:20:42 2012 : Info: ++- if ("%{Realm}"=='test.es') returns updated Fri Aug 24 13:20:42 2012 : Info: [files] users: Matched entry DEFAULT at line 29 Fri Aug 24 13:20:42 2012 : Info: [files] expand: %{Stripped-User-Name} -> prueba Fri Aug 24 13:20:42 2012 : Info: [files] expand: NUMERO DE INTENTOS FALLIDOS (%{Intentos-Reject}) EXCEDIDO PARA %{%{Stripped-User-Name}:-%{User-Name}} -> NUMERO DE INTENTOS FALLIDOS (7) EXCEDIDO PARA prueba Fri Aug 24 13:20:42 2012 : Info: [files] users: Matched entry DEFAULT at line 36 Fri Aug 24 13:20:42 2012 : Info: ++[files] returns ok Fri Aug 24 13:20:42 2012 : Info: ++? if ("%{control:Auth-Type}" == 'Reject') Fri Aug 24 13:20:42 2012 : Info: expand: %{control:Auth-Type} -> Reject Fri Aug 24 13:20:42 2012 : Info: ? Evaluating ("%{control:Auth-Type}" == 'Reject') -> TRUE Fri Aug 24 13:20:42 2012 : Info: ++? if ("%{control:Auth-Type}" == 'Reject') -> TRUE Fri Aug 24 13:20:42 2012 : Info: ++- entering if ("%{control:Auth-Type}" == 'Reject') {...} Fri Aug 24 13:20:42 2012 : Info: expand: %{reply:Codigo-Reject} -> Cuenta-Bloqueada-Intentos-Reject Fri Aug 24 13:20:42 2012 : Info: +++[outer.reply] returns ok Fri Aug 24 13:20:42 2012 : Info: +++[reject] returns reject Fri Aug 24 13:20:42 2012 : Info: ++- if ("%{control:Auth-Type}" == 'Reject') returns reject } # server inner-tunnel Fri Aug 24 13:20:42 2012 : Info: [peap] Got tunneled reply code 3 Reply-Message += "NUMERO DE INTENTOS FALLIDOS (7) EXCEDIDO PARA prueba" Codigo-Reject = Cuenta-Bloqueada-Intentos-Reject Fri Aug 24 13:20:42 2012 : Info: [peap] Got tunneled reply RADIUS code 3 Reply-Message += "NUMERO DE INTENTOS FALLIDOS (7) EXCEDIDO PARA prueba" Codigo-Reject = Cuenta-Bloqueada-Intentos-Reject Fri Aug 24 13:20:42 2012 : Info: [peap] Tunneled authentication was rejected. Fri Aug 24 13:20:42 2012 : Info: [peap] FAILURE Fri Aug 24 13:20:42 2012 : Info: ++[eap] returns handled Fri Aug 24 13:20:42 2012 : Info: } # server Sending Access-Challenge of id 32 to 2.2.2.2 port 1500 Codigo-Reject = Cuenta-Bloqueada-Intentos-Reject EAP-Message = 0x0109002b190017030100205f329253b5d9c4913c1f8f6f154f9d8771fa5a48be2993d753c9848b55710216 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xcbd9304bccd029a9cfcde266d7e75d03 Fri Aug 24 13:20:42 2012 : Info: Finished request 7. Fri Aug 24 13:20:42 2012 : Debug: Going to the next request Fri Aug 24 13:20:42 2012 : Debug: Waking up in 3.2 seconds. rad_recv: Access-Request packet from host 2.2.2.2 port 1501, id=33, length=205 NAS-IP-Address = 2.2.2.2 NAS-Port-Type = Wireless-802.11 NAS-Port = 2 Framed-MTU = 1400 User-Name = "prueba@test.es" Calling-Station-Id = "C4-46-19-75-7B-B1" Called-Station-Id = "00-18-6E-D0-EC-04" NAS-Identifier = "Enterprise Wireless AP" State = 0xcbd9304bccd029a9cfcde266d7e75d03 EAP-Message = 0x0209002b19001703010020d99c0d3ff24027b3d2f3d9ff6b999c50343b16224b5ea431c4f061165e9d7bbd Message-Authenticator = 0x9ea3d3262c5cf1762dfcc08226e0ff14 Fri Aug 24 13:20:42 2012 : Info: server { Fri Aug 24 13:20:42 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/ Fri Aug 24 13:20:42 2012 : Info: +- entering group authorize {...} Fri Aug 24 13:20:42 2012 : Info: ++? if ("%{request:Calling-Station-Id}" =~ /^([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2})$/i ) Fri Aug 24 13:20:42 2012 : Info: expand: %{request:Calling-Station-Id} -> C4-46-19-75-7B-B1 Fri Aug 24 13:20:42 2012 : Info: ? Evaluating ("%{request:Calling-Station-Id}" =~ /^([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2})$/i) -> TRUE Fri Aug 24 13:20:42 2012 : Info: ++? if ("%{request:Calling-Station-Id}" =~ /^([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2})$/i ) -> TRUE Fri Aug 24 13:20:42 2012 : Info: ++- entering if ("%{request:Calling-Station-Id}" =~ /^([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2})$/i ) {...} Fri Aug 24 13:20:42 2012 : Info: expand: %{1}:%{2}:%{3}:%{4}:%{5}:%{6} -> C4:46:19:75:7B:B1 Fri Aug 24 13:20:42 2012 : Info: +++[request] returns notfound Fri Aug 24 13:20:42 2012 : Info: ++- if ("%{request:Calling-Station-Id}" =~ /^([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2})$/i ) returns notfound Fri Aug 24 13:20:42 2012 : Info: [auth_log] expand: /var/log/freeradius/radacct/%Y/%m/%d/%{Client-IP-Address}-auth-detail-%Y%m%d -> /var/log/freeradius/radacct/2012/08/24/2.2.2.2-auth-detail-20120824 Fri Aug 24 13:20:42 2012 : Info: [auth_log] /var/log/freeradius/radacct/%Y/%m/%d/%{Client-IP-Address}-auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/2012/08/24/2.2.2.2-auth-detail-20120824 Fri Aug 24 13:20:42 2012 : Info: [auth_log] expand: %t -> Fri Aug 24 13:20:42 2012 Fri Aug 24 13:20:42 2012 : Info: ++[auth_log] returns ok Fri Aug 24 13:20:42 2012 : Info: [suffix] Looking up realm "test.es" for User-Name = "prueba@test.es" Fri Aug 24 13:20:42 2012 : Info: [suffix] Found realm "test.es" Fri Aug 24 13:20:42 2012 : Info: [suffix] Adding Stripped-User-Name = "prueba" Fri Aug 24 13:20:42 2012 : Info: [suffix] Adding Realm = "test.es" Fri Aug 24 13:20:42 2012 : Info: [suffix] Authentication realm is LOCAL. Fri Aug 24 13:20:42 2012 : Info: ++[suffix] returns ok Fri Aug 24 13:20:42 2012 : Info: [files] users: Matched entry DEFAULT at line 36 Fri Aug 24 13:20:42 2012 : Info: ++[files] returns ok Fri Aug 24 13:20:42 2012 : Info: [eap] EAP packet type response id 9 length 43 Fri Aug 24 13:20:42 2012 : Info: [eap] Continuing tunnel setup. Fri Aug 24 13:20:42 2012 : Info: ++[eap] returns ok Fri Aug 24 13:20:42 2012 : Info: Found Auth-Type = eap Fri Aug 24 13:20:42 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/ Fri Aug 24 13:20:42 2012 : Info: +- entering group authenticate {...} Fri Aug 24 13:20:42 2012 : Info: [eap] Request found, released from the list Fri Aug 24 13:20:42 2012 : Info: [eap] EAP/peap Fri Aug 24 13:20:42 2012 : Info: [eap] processing type peap Fri Aug 24 13:20:42 2012 : Info: [peap] processing EAP-TLS Fri Aug 24 13:20:42 2012 : Info: [peap] eaptls_verify returned 7 Fri Aug 24 13:20:42 2012 : Info: [peap] Done initial handshake Fri Aug 24 13:20:42 2012 : Info: [peap] eaptls_process returned 7 Fri Aug 24 13:20:42 2012 : Info: [peap] EAPTLS_OK Fri Aug 24 13:20:42 2012 : Info: [peap] Session established. Decoding tunneled attributes. Fri Aug 24 13:20:42 2012 : Info: [peap] Peap state send tlv failure Fri Aug 24 13:20:42 2012 : Info: [peap] Received EAP-TLV response. Fri Aug 24 13:20:42 2012 : Info: [peap] The users session was previously rejected: returning reject (again.) Fri Aug 24 13:20:42 2012 : Info: [peap] *** This means you need to read the PREVIOUS messages in the debug output Fri Aug 24 13:20:42 2012 : Info: [peap] *** to find out the reason why the user was rejected. Fri Aug 24 13:20:42 2012 : Info: [peap] *** Look for "reject" or "fail". Those earlier messages will tell you. Fri Aug 24 13:20:42 2012 : Info: [peap] *** what went wrong, and how to fix the problem. Fri Aug 24 13:20:42 2012 : Info: [eap] Handler failed in EAP/peap Fri Aug 24 13:20:42 2012 : Info: [eap] Failed in EAP select Fri Aug 24 13:20:42 2012 : Info: ++[eap] returns invalid Fri Aug 24 13:20:42 2012 : Info: Failed to authenticate the user. Fri Aug 24 13:20:42 2012 : Info: } # server Fri Aug 24 13:20:42 2012 : Info: Using Post-Auth-Type Reject Fri Aug 24 13:20:42 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/ Fri Aug 24 13:20:42 2012 : Info: +- entering group REJECT {...} Fri Aug 24 13:20:42 2012 : Info: ++[reply] returns noop Fri Aug 24 13:20:42 2012 : Info: [sql] expand: %{Stripped-User-Name} -> prueba Fri Aug 24 13:20:42 2012 : Info: [sql] expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> prueba Fri Aug 24 13:20:42 2012 : Info: [sql] sql_set_user escaped user --> 'prueba' Fri Aug 24 13:20:42 2012 : Info: [sql] expand: INSERT INTO radpostauth (username, mac, client, reply, authdate,codreject,radauth) VALUES ( LOWER('%{User-Name}'), LOWER('%i'), '%C', '%{reply:Packet-Type}', NOW(), '%{reply:Codigo-Reject}','radiuscc') -> INSERT INTO radpostauth (username, mac, client, reply, authdate,codreject,radauth) VALUES ( LOWER('prueba@test.es'), LOWER('C4:46:19:75:7B:B1'), 'PACCIPV601I', 'Access-Reject', NOW(), 'Credenciales-Erroneas','radiuscc') Fri Aug 24 13:20:42 2012 : Debug: rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, mac, client, reply, authdate,codreject,radauth) VALUES ( LOWER('prueba@test.es'), LOWER('C4:46:19:75:7B:B1'), 'PACCIPV601I', 'Access-Reject', NOW(), 'Credenciales-Erroneas','radiuscc') Fri Aug 24 13:20:42 2012 : Debug: rlm_sql (sql): Reserving sql socket id: 2 Fri Aug 24 13:20:42 2012 : Debug: rlm_sql (sql): Released sql socket id: 2 Fri Aug 24 13:20:42 2012 : Info: ++[sql] returns ok Fri Aug 24 13:20:42 2012 : Info: ++? if (fail) Fri Aug 24 13:20:42 2012 : Info: ? Evaluating (fail) -> FALSE Fri Aug 24 13:20:42 2012 : Info: ++? if (fail) -> FALSE Fri Aug 24 13:20:42 2012 : Info: Delaying reject of request 8 for 1 seconds Fri Aug 24 13:20:42 2012 : Debug: Going to the next request Fri Aug 24 13:20:42 2012 : Debug: Waking up in 0.9 seconds. Fri Aug 24 13:20:43 2012 : Info: Sending delayed reject for request 8 Sending Access-Reject of id 33 to 2.2.2.2 port 1501 EAP-Message = 0x04090004 Message-Authenticator = 0x00000000000000000000000000000000 Codigo-Reject = Credenciales-Erroneas Any ideas about how can I do that? Thank you very much and sorry for my english -- :::::::::::::::::::::::::::::::::::: :: Ana Gallardo Gómez :: ::::::::::::::::::::::::::::::::::::
Ana Gallardo Gómez wrote:
I would like to return diferent values of a personal atribute (Codigo-Reject) in a Access-Reject. I would like to do this in PEAPv0, EAP-TTLS-PAP and EAP-TTLS-MsCHAPv2
With my configuration I can return Codigo-Reject in EAP-TTLS-PAP and EAP-TTLS-MsCHAPv2 but I can't in PEAP.
That's been discussed before. The attributes from an inner tunnel reject aren't saved. Only the ones from an inner tunnel accept are saved. The reason it works for TTLS and not for PEAP is differences in the internal implementation. I'd suggest moving those rules to the outside of the tunnel. Alan DeKok.
Hello, I'm using FreeRADIUS version 2.1.10 I would like to return diferent values of a personal atribute (Codigo-Reject) in a Access-Reject. I would like to do this in PEAPv0, EAP-TTLS-PAP and EAP-TTLS-MsCHAPv2 With my configuration I can return Codigo-Reject in EAP-TTLS-PAP and EAP-TTLS-MsCHAPv2 but I can't in PEAP. My config: cat /etc/freeradius/users ... DEFAULT Intentos-Reject > 10, Auth-Type := Reject Reply-Message += "NUMERO DE INTENTOS FALLIDOS (%{Intentos-Reject}) EXCEDIDO PARA %{%{Stripped-User-Name}:-%{ User-Name}}", Codigo-Reject = Cuenta-Bloqueada-Intentos-Reject, Fall-Through = yes ... cat /etc/freeradius/sites-enabled/e server e { authorize { auth_log suffix files eap { ok = return } } authenticate { eap } post-auth { ... Post-Auth-Type REJECT { update reply { Codigo-Reject = Credenciales-Erroneas } sql{ fail=1 } if (fail) { ... } } #server e cat /etc/freeradius/sites-enabled/inner-tunnel server inner-tunnel { authorize { update outer.request { User-Name := "%u" } mschap auth_log suffix update control { Proxy-To-Realm := LOCAL } eap { ok = return } if ("%{Realm}"=='test.es'){ update request { Intentos-Reject = "%{sql:SELECT COUNT(*) from radpostauth WHERE username = '%{User-Name}' AND authdate > CURRENT_DATE and reply = 'Access-Reject'}" Intentos-Reject += "%{sqlradiusba:SELECT COUNT(*) from radpostauth WHERE username = '%{User-Name}' AND authdate > CURRENT_DATE and reply = 'Access-Reject'}" } } files if ("%{control:Auth-Type}" == 'Reject') { update outer.reply { Codigo-Reject = "%{reply:Codigo-Reject}" } reject } ... pap } authenticate { Auth-Type PAP { pap } Auth-Type MS-CHAP { mschap } eap } post-auth { sql{ fail=1 } if (fail) { ... } reply_log } } # -inner-tunnel server block LOG EAP-TTLS-PAP: Fri Aug 24 13:37:07 2012 : Info: [ttls] Got tunneled request User-Name = "prueba@test.es" User-Password = "530" FreeRADIUS-Proxied-To = 127.0.0.1 Fri Aug 24 13:37:07 2012 : Info: [ttls] Sending tunneled request User-Name = "prueba@test.es" User-Password = "530" FreeRADIUS-Proxied-To = 127.0.0.1 NAS-IP-Address = 127.0.0.1 Calling-Station-Id = "02:00:00:00:00:01" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" server inner-tunnel { Fri Aug 24 13:37:07 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel Fri Aug 24 13:37:07 2012 : Info: +- entering group authorize {...} Fri Aug 24 13:37:07 2012 : Info: expand: %u -> prueba@test.es Fri Aug 24 13:37:07 2012 : Info: ++[outer.request] returns notfound Fri Aug 24 13:37:07 2012 : Info: ++[mschap] returns noop Fri Aug 24 13:37:07 2012 : Info: [auth_log] expand: /var/log/freeradius/radacct/%Y/%m/%d/%{Client-IP-Address}-auth-detail-%Y%m%d -> /var/log/freeradius/radacct/2012/08/24/1.2.3.4-auth-detail-20120824 Fri Aug 24 13:37:07 2012 : Info: [auth_log] /var/log/freeradius/radacct/%Y/%m/%d/%{Client-IP-Address}-auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/2012/08/24/1.2.3.4-auth-detail-20120824 Fri Aug 24 13:37:07 2012 : Info: [auth_log] expand: %t -> Fri Aug 24 13:37:07 2012 Fri Aug 24 13:37:07 2012 : Info: ++[auth_log] returns ok Fri Aug 24 13:37:07 2012 : Info: [suffix] Looking up realm "test.es" for User-Name = "prueba@test.es" Fri Aug 24 13:37:07 2012 : Info: [suffix] Found realm "test.es" Fri Aug 24 13:37:07 2012 : Info: [suffix] Adding Stripped-User-Name = "prueba" Fri Aug 24 13:37:07 2012 : Info: [suffix] Adding Realm = "test.es" Fri Aug 24 13:37:07 2012 : Info: [suffix] Authentication realm is LOCAL. Fri Aug 24 13:37:07 2012 : Info: ++[suffix] returns ok Fri Aug 24 13:37:07 2012 : Info: ++[control] returns ok Fri Aug 24 13:37:07 2012 : Info: [eap] No EAP-Message, not doing EAP Fri Aug 24 13:37:07 2012 : Info: ++[eap] returns noop Fri Aug 24 13:37:07 2012 : Info: ++? if ("%{Realm}"=='test.es') Fri Aug 24 13:37:07 2012 : Info: expand: %{Realm} -> test.es Fri Aug 24 13:37:07 2012 : Info: ?? Evaluating ("%{Realm}"=='test.es') -> TRUE Fri Aug 24 13:37:07 2012 : Info: ++? if ("%{Realm}"=='test.es') -> TRUE Fri Aug 24 13:37:07 2012 : Info: ++- entering if ("%{Realm}"=='test.es') {...} Fri Aug 24 13:37:07 2012 : Info: sql_xlat Fri Aug 24 13:37:07 2012 : Info: expand: %{Stripped-User-Name} -> prueba Fri Aug 24 13:37:07 2012 : Info: expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> prueba Fri Aug 24 13:37:07 2012 : Info: sql_set_user escaped user --> 'prueba' Fri Aug 24 13:37:07 2012 : Info: expand: SELECT COUNT(*) from radpostauth WHERE username = '%{User-Name}' AND authdate > CURRENT_DATE and reply = 'Access-Reject' -> SELECT COUNT(*) from radpostauth WHERE username = 'prueba@test.es' AND authdate > CURRENT_DATE and reply = 'Access-Reject' Fri Aug 24 13:37:07 2012 : Debug: rlm_sql (sql): Reserving sql socket id: 3 Fri Aug 24 13:37:07 2012 : Info: sql_xlat finished Fri Aug 24 13:37:07 2012 : Debug: rlm_sql (sql): Released sql socket id: 3 Fri Aug 24 13:37:07 2012 : Info: expand: %{sql:SELECT COUNT(*) from radpostauth WHERE username = '%{User-Name}' AND authdate > CURRENT_DATE and reply = 'Access-Reject'} -> 26 Fri Aug 24 13:37:07 2012 : Info: sql_xlat Fri Aug 24 13:37:07 2012 : Info: expand: %{Stripped-User-Name} -> prueba Fri Aug 24 13:37:07 2012 : Info: expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> prueba Fri Aug 24 13:37:07 2012 : Info: sql_set_user escaped user --> 'prueba' Fri Aug 24 13:37:07 2012 : Info: expand: SELECT COUNT(*) from radpostauth WHERE username = '%{User-Name}' AND authdate > CURRENT_DATE and reply = 'Access-Reject' -> SELECT COUNT(*) from radpostauth WHERE username = 'prueba@test.es' AND authdate > CURRENT_DATE and reply = 'Access-Reject' Fri Aug 24 13:37:07 2012 : Debug: rlm_sql (sqlradiusba): Reserving sql socket id: 4 Fri Aug 24 13:37:08 2012 : Info: sql_xlat finished Fri Aug 24 13:37:08 2012 : Debug: rlm_sql (sqlradiusba): Released sql socket id: 4 Fri Aug 24 13:37:08 2012 : Info: expand: %{sqlradiusba:SELECT COUNT(*) from radpostauth WHERE username = '%{User-Name}' AND authdate > CURRENT_DATE and reply = 'Access-Reject'} -> 0 Fri Aug 24 13:37:08 2012 : Info: +++[request] returns noop Fri Aug 24 13:37:08 2012 : Info: ++- if ("%{Realm}"=='test.es') returns noop Fri Aug 24 13:37:08 2012 : Info: [files] users: Matched entry DEFAULT at line 29 Fri Aug 24 13:37:08 2012 : Info: [files] expand: %{Stripped-User-Name} -> prueba Fri Aug 24 13:37:08 2012 : Info: [files] expand: NUMERO DE INTENTOS FALLIDOS (%{Intentos-Reject}) EXCEDIDO PARA %{%{Stripped-User-Name}:-%{User-Name}} -> NUMERO DE INTENTOS FALLIDOS (26) EXCEDIDO PARA prueba Fri Aug 24 13:37:08 2012 : Info: [files] users: Matched entry DEFAULT at line 36 Fri Aug 24 13:37:08 2012 : Info: ++[files] returns ok Fri Aug 24 13:37:08 2012 : Info: ++? if ("%{control:Auth-Type}" == 'Reject') Fri Aug 24 13:37:08 2012 : Info: expand: %{control:Auth-Type} -> Reject Fri Aug 24 13:37:08 2012 : Info: ? Evaluating ("%{control:Auth-Type}" == 'Reject') -> TRUE Fri Aug 24 13:37:08 2012 : Info: ++? if ("%{control:Auth-Type}" == 'Reject') -> TRUE Fri Aug 24 13:37:08 2012 : Info: ++- entering if ("%{control:Auth-Type}" == 'Reject') {...} Fri Aug 24 13:37:08 2012 : Info: expand: %{reply:Codigo-Reject} -> Cuenta-Bloqueada-Intentos-Reject Fri Aug 24 13:37:08 2012 : Info: +++[outer.reply] returns ok Fri Aug 24 13:37:08 2012 : Info: +++[reject] returns reject Fri Aug 24 13:37:08 2012 : Info: ++- if ("%{control:Auth-Type}" == 'Reject') returns reject } # server inner-tunnel Fri Aug 24 13:37:08 2012 : Info: [ttls] Got tunneled reply code 3 Reply-Message += "NUMERO DE INTENTOS FALLIDOS (26) EXCEDIDO PARA prueba" Codigo-Reject = Cuenta-Bloqueada-Intentos-Reject Fri Aug 24 13:37:08 2012 : Info: [ttls] Got tunneled Access-Reject Fri Aug 24 13:37:08 2012 : Info: [eap] Handler failed in EAP/ttls Fri Aug 24 13:37:08 2012 : Info: [eap] Failed in EAP select Fri Aug 24 13:37:08 2012 : Info: ++[eap] returns invalid Fri Aug 24 13:37:08 2012 : Info: Failed to authenticate the user. Fri Aug 24 13:37:08 2012 : Info: } # server Fri Aug 24 13:37:08 2012 : Info: Using Post-Auth-Type Reject Fri Aug 24 13:37:08 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/ Fri Aug 24 13:37:08 2012 : Info: +- entering group REJECT {...} Fri Aug 24 13:37:08 2012 : Info: ++[reply] returns noop Fri Aug 24 13:37:08 2012 : Info: [sql] expand: %{Stripped-User-Name} -> Fri Aug 24 13:37:08 2012 : Info: [sql] ... expanding second conditional Fri Aug 24 13:37:08 2012 : Info: [sql] expand: %{User-Name} -> prueba@test.es Fri Aug 24 13:37:08 2012 : Info: [sql] expand: %{%{User-Name}:-DEFAULT} -> prueba@test.es Fri Aug 24 13:37:08 2012 : Info: [sql] expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> prueba@test.es Fri Aug 24 13:37:08 2012 : Info: [sql] sql_set_user escaped user --> ' prueba@test.es' Fri Aug 24 13:37:08 2012 : Info: [sql] expand: INSERT INTO radpostauth (username, mac, client, reply, authdate,codreject,radauth) VALUES ( LOWER('%{User-Name}'), LOWER('%i'), '%C', '%{reply:Packet-Type}', NOW(), '%{reply:Codigo-Reject}','radiuscc') -> INSERT INTO radpostauth (username, mac, client, reply, authdate,codreject,radauth) VALUES ( LOWER('prueba@test.es'), LOWER('02:00:00:00:00:01'), 'CAU1', 'Access-Reject', NOW(), 'Cuenta-Bloqueada-Intentos-Reject','radiuscc') Fri Aug 24 13:37:08 2012 : Debug: rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, mac, client, reply, authdate,codreject,radauth) VALUES ( LOWER('prueba@test.es'), LOWER('02:00:00:00:00:01'), 'CAU1', 'Access-Reject', NOW(), 'Cuenta-Bloqueada-Intentos-Reject','radiuscc') Fri Aug 24 13:37:08 2012 : Debug: rlm_sql (sql): Reserving sql socket id: 2 Fri Aug 24 13:37:08 2012 : Debug: rlm_sql (sql): Released sql socket id: 2 Fri Aug 24 13:37:08 2012 : Info: ++[sql] returns ok Fri Aug 24 13:37:08 2012 : Info: ++? if (fail) Fri Aug 24 13:37:08 2012 : Info: ? Evaluating (fail) -> FALSE Fri Aug 24 13:37:08 2012 : Info: ++? if (fail) -> FALSE Sending Access-Reject of id 8 to 1.2.3.4 port 53575 Codigo-Reject = Cuenta-Bloqueada-Intentos-Reject EAP-Message = 0x04080004 Message-Authenticator = 0x00000000000000000000000000000000 LOG PEAP: Fri Aug 24 13:20:41 2012 : Debug: PEAP: Setting User-Name to prueba@test.es Sending tunneled request EAP-Message = 0x0208001501303237343736333240756e65782e6573 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "prueba@test.es" NAS-IP-Address = 2.2.2.2 NAS-Port-Type = Wireless-802.11 NAS-Port = 2 Framed-MTU = 1400 Calling-Station-Id = "C4:46:19:75:7B:B1" Called-Station-Id = "00-18-6E-D0-EC-04" NAS-Identifier = "Enterprise Wireless AP" server inner-tunnel { Fri Aug 24 13:20:41 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel Fri Aug 24 13:20:41 2012 : Info: +- entering group authorize {...} Fri Aug 24 13:20:41 2012 : Info: expand: %u -> prueba@test.es Fri Aug 24 13:20:41 2012 : Info: ++[outer.request] returns notfound Fri Aug 24 13:20:41 2012 : Info: ++[mschap] returns noop Fri Aug 24 13:20:41 2012 : Info: [auth_log] expand: /var/log/freeradius/radacct/%Y/%m/%d/%{Client-IP-Address}-auth-detail-%Y%m%d -> /var/log/freeradius/radacct/2012/08/24/2.2.2.2-auth-detail-20120824 Fri Aug 24 13:20:41 2012 : Info: [auth_log] /var/log/freeradius/radacct/%Y/%m/%d/%{Client-IP-Address}-auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/2012/08/24/2.2.2.2-auth-detail-20120824 Fri Aug 24 13:20:41 2012 : Info: [auth_log] expand: %t -> Fri Aug 24 13:20:41 2012 Fri Aug 24 13:20:41 2012 : Info: ++[auth_log] returns ok Fri Aug 24 13:20:41 2012 : Info: [suffix] Looking up realm "test.es" for User-Name = "prueba@test.es" Fri Aug 24 13:20:41 2012 : Info: [suffix] Found realm "test.es" Fri Aug 24 13:20:41 2012 : Info: [suffix] Adding Stripped-User-Name = "prueba" Fri Aug 24 13:20:41 2012 : Info: [suffix] Adding Realm = "test.es" Fri Aug 24 13:20:41 2012 : Info: [suffix] Authentication realm is LOCAL. Fri Aug 24 13:20:41 2012 : Info: ++[suffix] returns ok Fri Aug 24 13:20:41 2012 : Info: ++[control] returns ok Fri Aug 24 13:20:41 2012 : Info: [eap] EAP packet type response id 8 length 21 Fri Aug 24 13:20:41 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Fri Aug 24 13:20:41 2012 : Info: ++[eap] returns updated Fri Aug 24 13:20:41 2012 : Info: ++? if ("%{Realm}"=='test.es') Fri Aug 24 13:20:41 2012 : Info: expand: %{Realm} -> test.es Fri Aug 24 13:20:41 2012 : Info: ?? Evaluating ("%{Realm}"=='test.es') -> TRUE Fri Aug 24 13:20:41 2012 : Info: ++? if ("%{Realm}"=='test.es') -> TRUE Fri Aug 24 13:20:41 2012 : Info: ++- entering if ("%{Realm}"=='test.es') {...} Fri Aug 24 13:20:41 2012 : Info: sql_xlat Fri Aug 24 13:20:41 2012 : Info: expand: %{Stripped-User-Name} -> prueba Fri Aug 24 13:20:41 2012 : Info: expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> prueba Fri Aug 24 13:20:41 2012 : Info: sql_set_user escaped user --> 'prueba' Fri Aug 24 13:20:41 2012 : Info: expand: SELECT COUNT(*) from radpostauth WHERE username = '%{User-Name}' AND authdate > CURRENT_DATE and reply = 'Access-Reject' -> SELECT COUNT(*) from radpostauth WHERE username = 'prueba@test.es' AND authdate > CURRENT_DATE and reply = 'Access-Reject' Fri Aug 24 13:20:41 2012 : Debug: rlm_sql (sql): Reserving sql socket id: 3 Fri Aug 24 13:20:42 2012 : Info: sql_xlat finished Fri Aug 24 13:20:42 2012 : Debug: rlm_sql (sql): Released sql socket id: 3 Fri Aug 24 13:20:42 2012 : Info: expand: %{sql:SELECT COUNT(*) from radpostauth WHERE username = '%{User-Name}' AND authdate > CURRENT_DATE and reply = 'Access-Reject'} -> 7 Fri Aug 24 13:20:42 2012 : Info: sql_xlat Fri Aug 24 13:20:42 2012 : Info: expand: %{Stripped-User-Name} -> prueba Fri Aug 24 13:20:42 2012 : Info: expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> prueba Fri Aug 24 13:20:42 2012 : Info: sql_set_user escaped user --> 'prueba' Fri Aug 24 13:20:42 2012 : Info: expand: SELECT COUNT(*) from radpostauth WHERE username = '%{User-Name}' AND authdate > CURRENT_DATE and reply = 'Access-Reject' -> SELECT COUNT(*) from radpostauth WHERE username = 'prueba@test.es' AND authdate > CURRENT_DATE and reply = 'Access-Reject' Fri Aug 24 13:20:42 2012 : Debug: rlm_sql (sqlradiusba): Reserving sql socket id: 4 Fri Aug 24 13:20:42 2012 : Info: sql_xlat finished Fri Aug 24 13:20:42 2012 : Debug: rlm_sql (sqlradiusba): Released sql socket id: 4 Fri Aug 24 13:20:42 2012 : Info: expand: %{sqlradiusba:SELECT COUNT(*) from radpostauth WHERE username = '%{User-Name}' AND authdate > CURRENT_DATE and reply = 'Access-Reject'} -> 0 Fri Aug 24 13:20:42 2012 : Info: +++[request] returns updated Fri Aug 24 13:20:42 2012 : Info: ++- if ("%{Realm}"=='test.es') returns updated Fri Aug 24 13:20:42 2012 : Info: [files] users: Matched entry DEFAULT at line 29 Fri Aug 24 13:20:42 2012 : Info: [files] expand: %{Stripped-User-Name} -> prueba Fri Aug 24 13:20:42 2012 : Info: [files] expand: NUMERO DE INTENTOS FALLIDOS (%{Intentos-Reject}) EXCEDIDO PARA %{%{Stripped-User-Name}:-%{User-Name}} -> NUMERO DE INTENTOS FALLIDOS (7) EXCEDIDO PARA prueba Fri Aug 24 13:20:42 2012 : Info: [files] users: Matched entry DEFAULT at line 36 Fri Aug 24 13:20:42 2012 : Info: ++[files] returns ok Fri Aug 24 13:20:42 2012 : Info: ++? if ("%{control:Auth-Type}" == 'Reject') Fri Aug 24 13:20:42 2012 : Info: expand: %{control:Auth-Type} -> Reject Fri Aug 24 13:20:42 2012 : Info: ? Evaluating ("%{control:Auth-Type}" == 'Reject') -> TRUE Fri Aug 24 13:20:42 2012 : Info: ++? if ("%{control:Auth-Type}" == 'Reject') -> TRUE Fri Aug 24 13:20:42 2012 : Info: ++- entering if ("%{control:Auth-Type}" == 'Reject') {...} Fri Aug 24 13:20:42 2012 : Info: expand: %{reply:Codigo-Reject} -> Cuenta-Bloqueada-Intentos-Reject Fri Aug 24 13:20:42 2012 : Info: +++[outer.reply] returns ok Fri Aug 24 13:20:42 2012 : Info: +++[reject] returns reject Fri Aug 24 13:20:42 2012 : Info: ++- if ("%{control:Auth-Type}" == 'Reject') returns reject } # server inner-tunnel Fri Aug 24 13:20:42 2012 : Info: [peap] Got tunneled reply code 3 Reply-Message += "NUMERO DE INTENTOS FALLIDOS (7) EXCEDIDO PARA prueba" Codigo-Reject = Cuenta-Bloqueada-Intentos-Reject Fri Aug 24 13:20:42 2012 : Info: [peap] Got tunneled reply RADIUS code 3 Reply-Message += "NUMERO DE INTENTOS FALLIDOS (7) EXCEDIDO PARA prueba" Codigo-Reject = Cuenta-Bloqueada-Intentos-Reject Fri Aug 24 13:20:42 2012 : Info: [peap] Tunneled authentication was rejected. Fri Aug 24 13:20:42 2012 : Info: [peap] FAILURE Fri Aug 24 13:20:42 2012 : Info: ++[eap] returns handled Fri Aug 24 13:20:42 2012 : Info: } # server Sending Access-Challenge of id 32 to 2.2.2.2 port 1500 Codigo-Reject = Cuenta-Bloqueada-Intentos-Reject EAP-Message = 0x0109002b190017030100205f329253b5d9c4913c1f8f6f154f9d8771fa5a48be2993d753c9848b55710216 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xcbd9304bccd029a9cfcde266d7e75d03 Fri Aug 24 13:20:42 2012 : Info: Finished request 7. Fri Aug 24 13:20:42 2012 : Debug: Going to the next request Fri Aug 24 13:20:42 2012 : Debug: Waking up in 3.2 seconds. rad_recv: Access-Request packet from host 2.2.2.2 port 1501, id=33, length=205 NAS-IP-Address = 2.2.2.2 NAS-Port-Type = Wireless-802.11 NAS-Port = 2 Framed-MTU = 1400 User-Name = "prueba@test.es" Calling-Station-Id = "C4-46-19-75-7B-B1" Called-Station-Id = "00-18-6E-D0-EC-04" NAS-Identifier = "Enterprise Wireless AP" State = 0xcbd9304bccd029a9cfcde266d7e75d03 EAP-Message = 0x0209002b19001703010020d99c0d3ff24027b3d2f3d9ff6b999c50343b16224b5ea431c4f061165e9d7bbd Message-Authenticator = 0x9ea3d3262c5cf1762dfcc08226e0ff14 Fri Aug 24 13:20:42 2012 : Info: server { Fri Aug 24 13:20:42 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/ Fri Aug 24 13:20:42 2012 : Info: +- entering group authorize {...} Fri Aug 24 13:20:42 2012 : Info: ++? if ("%{request:Calling-Station-Id}" =~ /^([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2})$/i ) Fri Aug 24 13:20:42 2012 : Info: expand: %{request:Calling-Station-Id} -> C4-46-19-75-7B-B1 Fri Aug 24 13:20:42 2012 : Info: ? Evaluating ("%{request:Calling-Station-Id}" =~ /^([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2})$/i) -> TRUE Fri Aug 24 13:20:42 2012 : Info: ++? if ("%{request:Calling-Station-Id}" =~ /^([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2})$/i ) -> TRUE Fri Aug 24 13:20:42 2012 : Info: ++- entering if ("%{request:Calling-Station-Id}" =~ /^([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2})$/i ) {...} Fri Aug 24 13:20:42 2012 : Info: expand: %{1}:%{2}:%{3}:%{4}:%{5}:%{6} -> C4:46:19:75:7B:B1 Fri Aug 24 13:20:42 2012 : Info: +++[request] returns notfound Fri Aug 24 13:20:42 2012 : Info: ++- if ("%{request:Calling-Station-Id}" =~ /^([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2}).?([0-9a-f]{2})$/i ) returns notfound Fri Aug 24 13:20:42 2012 : Info: [auth_log] expand: /var/log/freeradius/radacct/%Y/%m/%d/%{Client-IP-Address}-auth-detail-%Y%m%d -> /var/log/freeradius/radacct/2012/08/24/2.2.2.2-auth-detail-20120824 Fri Aug 24 13:20:42 2012 : Info: [auth_log] /var/log/freeradius/radacct/%Y/%m/%d/%{Client-IP-Address}-auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/2012/08/24/2.2.2.2-auth-detail-20120824 Fri Aug 24 13:20:42 2012 : Info: [auth_log] expand: %t -> Fri Aug 24 13:20:42 2012 Fri Aug 24 13:20:42 2012 : Info: ++[auth_log] returns ok Fri Aug 24 13:20:42 2012 : Info: [suffix] Looking up realm "test.es" for User-Name = "prueba@test.es" Fri Aug 24 13:20:42 2012 : Info: [suffix] Found realm "test.es" Fri Aug 24 13:20:42 2012 : Info: [suffix] Adding Stripped-User-Name = "prueba" Fri Aug 24 13:20:42 2012 : Info: [suffix] Adding Realm = "test.es" Fri Aug 24 13:20:42 2012 : Info: [suffix] Authentication realm is LOCAL. Fri Aug 24 13:20:42 2012 : Info: ++[suffix] returns ok Fri Aug 24 13:20:42 2012 : Info: [files] users: Matched entry DEFAULT at line 36 Fri Aug 24 13:20:42 2012 : Info: ++[files] returns ok Fri Aug 24 13:20:42 2012 : Info: [eap] EAP packet type response id 9 length 43 Fri Aug 24 13:20:42 2012 : Info: [eap] Continuing tunnel setup. Fri Aug 24 13:20:42 2012 : Info: ++[eap] returns ok Fri Aug 24 13:20:42 2012 : Info: Found Auth-Type = eap Fri Aug 24 13:20:42 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/ Fri Aug 24 13:20:42 2012 : Info: +- entering group authenticate {...} Fri Aug 24 13:20:42 2012 : Info: [eap] Request found, released from the list Fri Aug 24 13:20:42 2012 : Info: [eap] EAP/peap Fri Aug 24 13:20:42 2012 : Info: [eap] processing type peap Fri Aug 24 13:20:42 2012 : Info: [peap] processing EAP-TLS Fri Aug 24 13:20:42 2012 : Info: [peap] eaptls_verify returned 7 Fri Aug 24 13:20:42 2012 : Info: [peap] Done initial handshake Fri Aug 24 13:20:42 2012 : Info: [peap] eaptls_process returned 7 Fri Aug 24 13:20:42 2012 : Info: [peap] EAPTLS_OK Fri Aug 24 13:20:42 2012 : Info: [peap] Session established. Decoding tunneled attributes. Fri Aug 24 13:20:42 2012 : Info: [peap] Peap state send tlv failure Fri Aug 24 13:20:42 2012 : Info: [peap] Received EAP-TLV response. Fri Aug 24 13:20:42 2012 : Info: [peap] The users session was previously rejected: returning reject (again.) Fri Aug 24 13:20:42 2012 : Info: [peap] *** This means you need to read the PREVIOUS messages in the debug output Fri Aug 24 13:20:42 2012 : Info: [peap] *** to find out the reason why the user was rejected. Fri Aug 24 13:20:42 2012 : Info: [peap] *** Look for "reject" or "fail". Those earlier messages will tell you. Fri Aug 24 13:20:42 2012 : Info: [peap] *** what went wrong, and how to fix the problem. Fri Aug 24 13:20:42 2012 : Info: [eap] Handler failed in EAP/peap Fri Aug 24 13:20:42 2012 : Info: [eap] Failed in EAP select Fri Aug 24 13:20:42 2012 : Info: ++[eap] returns invalid Fri Aug 24 13:20:42 2012 : Info: Failed to authenticate the user. Fri Aug 24 13:20:42 2012 : Info: } # server Fri Aug 24 13:20:42 2012 : Info: Using Post-Auth-Type Reject Fri Aug 24 13:20:42 2012 : Info: # Executing group from file /etc/freeradius/sites-enabled/ Fri Aug 24 13:20:42 2012 : Info: +- entering group REJECT {...} Fri Aug 24 13:20:42 2012 : Info: ++[reply] returns noop Fri Aug 24 13:20:42 2012 : Info: [sql] expand: %{Stripped-User-Name} -> prueba Fri Aug 24 13:20:42 2012 : Info: [sql] expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} -> prueba Fri Aug 24 13:20:42 2012 : Info: [sql] sql_set_user escaped user --> 'prueba' Fri Aug 24 13:20:42 2012 : Info: [sql] expand: INSERT INTO radpostauth (username, mac, client, reply, authdate,codreject,radauth) VALUES ( LOWER('%{User-Name}'), LOWER('%i'), '%C', '%{reply:Packet-Type}', NOW(), '%{reply:Codigo-Reject}','radiuscc') -> INSERT INTO radpostauth (username, mac, client, reply, authdate,codreject,radauth) VALUES ( LOWER('prueba@test.es'), LOWER('C4:46:19:75:7B:B1'), 'PACCIPV601I', 'Access-Reject', NOW(), 'Credenciales-Erroneas','radiuscc') Fri Aug 24 13:20:42 2012 : Debug: rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, mac, client, reply, authdate,codreject,radauth) VALUES ( LOWER('prueba@test.es'), LOWER('C4:46:19:75:7B:B1'), 'PACCIPV601I', 'Access-Reject', NOW(), 'Credenciales-Erroneas','radiuscc') Fri Aug 24 13:20:42 2012 : Debug: rlm_sql (sql): Reserving sql socket id: 2 Fri Aug 24 13:20:42 2012 : Debug: rlm_sql (sql): Released sql socket id: 2 Fri Aug 24 13:20:42 2012 : Info: ++[sql] returns ok Fri Aug 24 13:20:42 2012 : Info: ++? if (fail) Fri Aug 24 13:20:42 2012 : Info: ? Evaluating (fail) -> FALSE Fri Aug 24 13:20:42 2012 : Info: ++? if (fail) -> FALSE Fri Aug 24 13:20:42 2012 : Info: Delaying reject of request 8 for 1 seconds Fri Aug 24 13:20:42 2012 : Debug: Going to the next request Fri Aug 24 13:20:42 2012 : Debug: Waking up in 0.9 seconds. Fri Aug 24 13:20:43 2012 : Info: Sending delayed reject for request 8 Sending Access-Reject of id 33 to 2.2.2.2 port 1501 EAP-Message = 0x04090004 Message-Authenticator = 0x00000000000000000000000000000000 Codigo-Reject = Credenciales-Erroneas Any ideas about how can I do that? Thank you very much and sorry for my english :::::::::::::::::::::::::::::::::::: :: Ana Gallardo Gómez :: ::::::::::::::::::::::::::::::::::::
participants (2)
-
Alan DeKok -
Ana Gallardo Gómez