Stripped-User-Name not set when using nostrip?

Júlíus Þór Bess Ríkharðsson julius.bess at nyherji.is
Wed Jul 3 19:17:43 CEST 2013




On 03/07/13 16:24, Júlíus Þór Bess Ríkharðsson wrote:
>> Hi,
>>
>> For some reason I cannot get Stripped-User-Name attribute to get
>> populated when using nostrip for a realm. Is this normal behaviour or am
>> I missing something?

> Normal. "nostrip" means "don't populate Stripped-User-Name"

Phil: When I unset nostrip the User-Name attribute gets stripped. So it made sense to me that nostrip would apply to User-Name but would still give the option of Stripped-User-Name.

Alan: The goal is to be able to use EAP and still be able to authorize user using LDAP. The objects name is obviously not named realm\user.


This is why I'm using nostrip:

        #  You MUST also use the 'nostrip' option in the 'realm'
        #  configuration.  Otherwise, the User-Name attribute
        #  in the proxied request will not match the user name
        #  hidden inside of the EAP packet, and the end server will
        #  reject the EAP request.
        #
        eap

Does this not apply to virtual-servers?



>> I need the User-Name attribute unchanged for EAP but it gets stripped as
>> expected when nostrip is unset.

> "strip" on the realm should not change User-Name; it just populates 
> Stripped-User-Name.

> Also, your debug isn't EAP.

The behaviour is the same for EAP (just longer output :)), I don't get the option of Stripped-User-Name. And when I unset nostrip; User-Name gets stripped along with Stripped-User-Name being set and the tunnel doesn't work.

Could it be because I'm using an older version? 2.1.12

Here is some EAP debug:

nostrip:

rad_recv: Access-Request packet from host 10.41.255.67 port 32769, id=82, length=260
        User-Name = "umsja\\test.juliusbess"
        Calling-Station-Id = "00-24-d7-70-50-20"
        Called-Station-Id = "50-06-04-4b-8e-a0:wifitesting"
        NAS-Port = 1
        Cisco-AVPair = "audit-session-id=0a29ff430000004d51d45b99"
        NAS-IP-Address = 10.41.255.67
        NAS-Identifier = "testingwifi"
        Airespace-Wlan-Id = 2
        Service-Type = Framed-User
        Framed-MTU = 1300
        NAS-Port-Type = Wireless-802.11
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "666"
        EAP-Message = 0x0201001a01756d736a615c746573742e6a756c69757362657373
        Message-Authenticator = 0xa37fbd1b7dd83f3241535949bca772eb
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
        expand: %{Stripped-User-Name} -> 
++[expand] returns noop
[suffix] No '@' in User-Name = "umsja\test.juliusbess", skipping NULL due to config.
++[suffix] returns noop
[ntdomain] Looking up realm "umsja" for User-Name = "umsja\test.juliusbess"
[ntdomain] Found realm "umsja"
[ntdomain] Adding Realm = "umsja"
[ntdomain] Proxying request from user test.juliusbess to realm umsja
[ntdomain] Preparing to proxy authentication request to realm "umsja" 
++[ntdomain] returns updated
        expand: %{Stripped-User-Name} -> 
++[expand] returns updated
[eap] Request is supposed to be proxied to Realm umsja.  Not doing EAP.
++[eap] returns noop
++[files] returns noop
[sql]   expand: %{User-Name} -> umsja\test.juliusbess
[sql] sql_set_user escaped user --> 'umsja\test.juliusbess'
rlm_sql (sql): Reserving sql socket id: 4
[sql]   expand: SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = 'umsja=5Ctest.juliusbess'           ORDER BY id
[sql]   expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = 'umsja=5Ctest.juliusbess'           ORDER BY priority
rlm_sql (sql): Released sql socket id: 4
[sql] User umsja\test.juliusbess not found
++[sql] returns notfound
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
  WARNING: Empty pre-proxy section.  Using default return values.
>>> Sending proxied request internally to virtual server.
server innra.umsja.is-srv {
# Executing section authorize from file /etc/raddb/sites-enabled/innra.umsja.is
+- entering group authorize {...}
++[preprocess] returns ok
[eap] EAP packet type response id 1 length 26
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[mschap-innra.umsja.is] returns noop
[ldap-innra.umsja.is] performing user authorization for umsja\test.juliusbess
[ldap-innra.umsja.is]   expand: %{Stripped-User-Name} -> 
[ldap-innra.umsja.is]   ... expanding second conditional
[ldap-innra.umsja.is]   expand: %{User-Name} -> umsja\5ctest.juliusbess
[ldap-innra.umsja.is]   expand: (sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}) -> (sAMAccountName=umsja\5ctest.juliusbess)
[ldap-innra.umsja.is]   expand: DC=innra,DC=umsja,DC=is -> DC=innra,DC=umsja,DC=is
  [ldap-innra.umsja.is] ldap_get_conn: Checking Id: 0
  [ldap-innra.umsja.is] ldap_get_conn: Got Id: 0
  [ldap-innra.umsja.is] attempting LDAP reconnection
  [ldap-innra.umsja.is] (re)connect to innra.umsja.is:389, authentication 0
  [ldap-innra.umsja.is] bind as sa.ldapFreeRadius at innra.umsja.is/tBdPLjjmnri3R1xX to innra.umsja.is:389
  [ldap-innra.umsja.is] waiting for bind result ...
  [ldap-innra.umsja.is] Bind was successful
  [ldap-innra.umsja.is] performing search in DC=innra,DC=umsja,DC=is, with filter (sAMAccountName=umsja\5ctest.juliusbess)
  [ldap-innra.umsja.is] rebind to URL ldap://DomainDnsZones.innra.umsja.is/DC=DomainDnsZones,DC=innra,DC=umsja,DC=is
  [ldap-innra.umsja.is] rebind to URL ldap://ForestDnsZones.innra.umsja.is/DC=ForestDnsZones,DC=innra,DC=umsja,DC=is
  [ldap-innra.umsja.is] object not found
[ldap-innra.umsja.is] search failed
  [ldap-innra.umsja.is] ldap_release_conn: Release Id: 0
++[ldap-innra.umsja.is] returns notfound
        expand: %{control:Ldap-UserDN} -> 
++[expand] returns notfound
        expand: %{User-Name} -> umsja\test.juliusbess
++[expand] returns notfound
        expand: %{Stripped-User-Name} -> 
++[expand] returns notfound
++? if (control:Ldap-UserDN =~ /^.+,OU=Users,OU=([^,]+),/i)
    (Attribute control:Ldap-UserDN was not found)
? Evaluating (control:Ldap-UserDN =~ /^.+,OU=Users,OU=([^,]+),/i) -> FALSE
++? if (control:Ldap-UserDN =~ /^.+,OU=Users,OU=([^,]+),/i) -> FALSE
++? if (control:Jira-Key != "")
    (Attribute control:Jira-Key was not found)
? Evaluating (control:Jira-Key != "") -> FALSE
++? if (control:Jira-Key != "") -> FALSE
++? if (Huntgroup-Name == ppp-bidlarar)
    (Attribute Huntgroup-Name was not found)
? Evaluating (Huntgroup-Name == ppp-bidlarar) -> FALSE
++? if (Huntgroup-Name == ppp-bidlarar) -> FALSE
++? if (Huntgroup-Name == vpn-nas)
    (Attribute Huntgroup-Name was not found)
? Evaluating (Huntgroup-Name == vpn-nas) -> FALSE
++? if (Huntgroup-Name == vpn-nas) -> FALSE
++[files] returns noop
++[expiration] returns noop
++[logintime] returns noop
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/innra.umsja.is
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type md5
rlm_eap_md5: Issuing Challenge
++[eap] returns handled
} # server innra.umsja.is-srv
Going to the next request
<<< Received proxied response code 11 from internal virtual server.
# Executing section post-proxy from file /etc/raddb/sites-enabled/default
+- entering group post-proxy {...}
[eap] No pre-existing handler found
++[eap] returns noop
Sending Access-Challenge of id 82 to 10.41.255.67 port 32769
        EAP-Message = 0x010200160410a5026a49f060c3baebfbfde6b36fa795
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x6065b4846067b0f403817d959797c4d5
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.41.255.67 port 32769, id=83, length=258
        User-Name = "umsja\\test.juliusbess"
        Calling-Station-Id = "00-24-d7-70-50-20"
        Called-Station-Id = "50-06-04-4b-8e-a0:wifitesting"
        NAS-Port = 1
        Cisco-AVPair = "audit-session-id=0a29ff430000004d51d45b99"
        NAS-IP-Address = 10.41.255.67
        NAS-Identifier = "testingwifi"
        Airespace-Wlan-Id = 2
        Service-Type = Framed-User
        Framed-MTU = 1300
        NAS-Port-Type = Wireless-802.11
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "666"
        EAP-Message = 0x020200060319
        State = 0x6065b4846067b0f403817d959797c4d5
        Message-Authenticator = 0xd374c237e2d7cd2841388bd697536132
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
        expand: %{Stripped-User-Name} -> 
++[expand] returns noop
[suffix] No '@' in User-Name = "umsja\test.juliusbess", skipping NULL due to config.
++[suffix] returns noop
[ntdomain] Looking up realm "umsja" for User-Name = "umsja\test.juliusbess"
[ntdomain] Found realm "umsja"
[ntdomain] Adding Realm = "umsja"
[ntdomain] Proxying request from user test.juliusbess to realm umsja
[ntdomain] Preparing to proxy authentication request to realm "umsja" 
++[ntdomain] returns updated
        expand: %{Stripped-User-Name} -> 
++[expand] returns updated
[eap] Request is supposed to be proxied to Realm umsja.  Not doing EAP.
++[eap] returns noop
++[files] returns noop
[sql]   expand: %{User-Name} -> umsja\test.juliusbess
[sql] sql_set_user escaped user --> 'umsja\test.juliusbess'
rlm_sql (sql): Reserving sql socket id: 3
[sql]   expand: SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = 'umsja=5Ctest.juliusbess'           ORDER BY id
[sql]   expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = 'umsja=5Ctest.juliusbess'           ORDER BY priority
rlm_sql (sql): Released sql socket id: 3
[sql] User umsja\test.juliusbess not found
++[sql] returns notfound
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
  WARNING: Empty pre-proxy section.  Using default return values.
>>> Sending proxied request internally to virtual server.
server innra.umsja.is-srv {
# Executing section authorize from file /etc/raddb/sites-enabled/innra.umsja.is
+- entering group authorize {...}
++[preprocess] returns ok
[eap] EAP packet type response id 2 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[mschap-innra.umsja.is] returns noop
[ldap-innra.umsja.is] performing user authorization for umsja\test.juliusbess
[ldap-innra.umsja.is]   expand: %{Stripped-User-Name} -> 
[ldap-innra.umsja.is]   ... expanding second conditional
[ldap-innra.umsja.is]   expand: %{User-Name} -> umsja\5ctest.juliusbess
[ldap-innra.umsja.is]   expand: (sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}) -> (sAMAccountName=umsja\5ctest.juliusbess)
[ldap-innra.umsja.is]   expand: DC=innra,DC=umsja,DC=is -> DC=innra,DC=umsja,DC=is
  [ldap-innra.umsja.is] ldap_get_conn: Checking Id: 0
  [ldap-innra.umsja.is] ldap_get_conn: Got Id: 0
  [ldap-innra.umsja.is] performing search in DC=innra,DC=umsja,DC=is, with filter (sAMAccountName=umsja\5ctest.juliusbess)
  [ldap-innra.umsja.is] rebind to URL ldap://DomainDnsZones.innra.umsja.is/DC=DomainDnsZones,DC=innra,DC=umsja,DC=is
  [ldap-innra.umsja.is] rebind to URL ldap://ForestDnsZones.innra.umsja.is/DC=ForestDnsZones,DC=innra,DC=umsja,DC=is
  [ldap-innra.umsja.is] object not found
[ldap-innra.umsja.is] search failed
  [ldap-innra.umsja.is] ldap_release_conn: Release Id: 0
++[ldap-innra.umsja.is] returns notfound
        expand: %{control:Ldap-UserDN} -> 
++[expand] returns notfound
        expand: %{User-Name} -> umsja\test.juliusbess
++[expand] returns notfound
        expand: %{Stripped-User-Name} -> 
++[expand] returns notfound
++? if (control:Ldap-UserDN =~ /^.+,OU=Users,OU=([^,]+),/i)
    (Attribute control:Ldap-UserDN was not found)
? Evaluating (control:Ldap-UserDN =~ /^.+,OU=Users,OU=([^,]+),/i) -> FALSE
++? if (control:Ldap-UserDN =~ /^.+,OU=Users,OU=([^,]+),/i) -> FALSE
++? if (control:Jira-Key != "")
    (Attribute control:Jira-Key was not found)
? Evaluating (control:Jira-Key != "") -> FALSE
++? if (control:Jira-Key != "") -> FALSE
++? if (Huntgroup-Name == ppp-bidlarar)
    (Attribute Huntgroup-Name was not found)
? Evaluating (Huntgroup-Name == ppp-bidlarar) -> FALSE
++? if (Huntgroup-Name == ppp-bidlarar) -> FALSE
++? if (Huntgroup-Name == vpn-nas)
    (Attribute Huntgroup-Name was not found)
? Evaluating (Huntgroup-Name == vpn-nas) -> FALSE
++? if (Huntgroup-Name == vpn-nas) -> FALSE
++[files] returns noop
++[expiration] returns noop
++[logintime] returns noop
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/innra.umsja.is
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP NAK
[eap] EAP-NAK asked for EAP-Type/peap
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1
++[eap] returns handled
} # server innra.umsja.is-srv
Going to the next request
<<< Received proxied response code 11 from internal virtual server.
# Executing section post-proxy from file /etc/raddb/sites-enabled/default
+- entering group post-proxy {...}
[eap] No pre-existing handler found
++[eap] returns noop
Sending Access-Challenge of id 83 to 10.41.255.67 port 32769
        EAP-Message = 0x010300061920
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x6065b4846166adf403817d959797c4d5
Finished request 1.
Going to the next request
Waking up in 2.9 seconds.
rad_recv: Access-Request packet from host 10.41.255.67 port 32769, id=83, length=258
Sending duplicate reply to client NYHB37WL01 port 32769 - ID: 83
Sending Access-Challenge of id 83 to 10.41.255.67 port 32769
Waking up in 2.9 seconds.
rad_recv: Access-Request packet from host 10.41.255.67 port 32769, id=84, length=483
        User-Name = "umsja\\test.juliusbess"
        Calling-Station-Id = "00-24-d7-70-50-20"
        Called-Station-Id = "50-06-04-4b-8e-a0:wifitesting"
        NAS-Port = 1
        Cisco-AVPair = "audit-session-id=0a29ff430000004d51d45b99"
        NAS-IP-Address = 10.41.255.67
        NAS-Identifier = "testingwifi"
        Airespace-Wlan-Id = 2
        Service-Type = Framed-User
        Framed-MTU = 1300
        NAS-Port-Type = Wireless-802.11
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "666"
        EAP-Message = 0x020300e71980000000dd16030100d8010000d4030151d45b9b8ea5a170f5ee4f3c83bcd9b4758b2d45a5cce528c199964a795d9c7b000066c014c00ac022c0210039003800880087c00fc00500350084c012c008c01cc01b00160013c00dc003000ac013c009c01fc01e00330032009a009900450044c00ec004002f00960041c011c007c00cc002000500040015001200090014001100080006000300ff01000045000b000403000102000a00340032000e000d0019000b000c00180009000a00160017000800060007001400150004000500120013000100020003000f00100011000f000101
        State = 0x6065b4846166adf403817d959797c4d5
        Message-Authenticator = 0x175b35c4376365e6d76c4b2c51900a55
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
        expand: %{Stripped-User-Name} -> 
++[expand] returns noop
[suffix] No '@' in User-Name = "umsja\test.juliusbess", skipping NULL due to config.
++[suffix] returns noop
[ntdomain] Looking up realm "umsja" for User-Name = "umsja\test.juliusbess"
[ntdomain] Found realm "umsja"
[ntdomain] Adding Realm = "umsja"
[ntdomain] Proxying request from user test.juliusbess to realm umsja
[ntdomain] Preparing to proxy authentication request to realm "umsja" 
++[ntdomain] returns updated
        expand: %{Stripped-User-Name} -> 
++[expand] returns updated
[eap] Request is supposed to be proxied to Realm umsja.  Not doing EAP.
++[eap] returns noop
++[files] returns noop
[sql]   expand: %{User-Name} -> umsja\test.juliusbess
[sql] sql_set_user escaped user --> 'umsja\test.juliusbess'
rlm_sql (sql): Reserving sql socket id: 2
[sql]   expand: SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = 'umsja=5Ctest.juliusbess'           ORDER BY id
[sql]   expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = 'umsja=5Ctest.juliusbess'           ORDER BY priority
rlm_sql (sql): Released sql socket id: 2
[sql] User umsja\test.juliusbess not found
++[sql] returns notfound
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
  WARNING: Empty pre-proxy section.  Using default return values.
>>> Sending proxied request internally to virtual server.
server innra.umsja.is-srv {
# Executing section authorize from file /etc/raddb/sites-enabled/innra.umsja.is
+- entering group authorize {...}
++[preprocess] returns ok
[eap] EAP packet type response id 3 length 231
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/innra.umsja.is
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
  TLS Length 221
[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 00d8], ClientHello  
[peap]     TLS_accept: SSLv3 read client hello A
[peap] >>> TLS 1.0 Handshake [length 0031], ServerHello  
[peap]     TLS_accept: SSLv3 write server hello A
[peap] >>> TLS 1.0 Handshake [length 085e], Certificate  
[peap]     TLS_accept: SSLv3 write certificate A
[peap] >>> TLS 1.0 Handshake [length 020d], 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
} # server innra.umsja.is-srv
Going to the next request
<<< Received proxied response code 11 from internal virtual server.
# Executing section post-proxy from file /etc/raddb/sites-enabled/default
+- entering group post-proxy {...}
[eap] No pre-existing handler found
++[eap] returns noop
Sending Access-Challenge of id 84 to 10.41.255.67 port 32769
        EAP-Message = 0x0104040019c000000ab416030100310200002d030151d45b9c184850a887e5477bc744c74bca76f04854d24d6125b80731ae5c2e07000039000005ff01000100160301085e0b00085a0008570003a6308203a23082028aa003020102020101300d06092a864886f70d0101050500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c65204365727469666963617465204175
        EAP-Message = 0x74686f72697479301e170d3133303230353137353230375a170d3133303430363137353230375a307c310b3009060355040613024652310f300d0603550408130652616469757331153013060355040a130c4578616d706c6520496e632e312330210603550403131a4578616d706c65205365727665722043657274696669636174653120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100c44f973e152169e754d1551dbafcf17a32d31fdcde44f4eb665447abb0ff3eb3b6c92fd8a25d6bdac49af3c31f62f21bf5bae90a65c9f9
        EAP-Message = 0xf66ea69955b2cc54e551cd56186cecb3404fe8b9cda3d5cc6b9f31b6c5a2c675911fc945c4c132dedb62ee0b11d3bf067997bfeb56d26cb3c7d8b433cd46f66b04d3b66d06243ca170f13732291669635ff1fb8d2f7d4faa5559620ab6313bc7393adac4e1cd3503f003082c6f5b274a71a2df2574b4173b4d45e656d7995b2c0c98eac7ae1bdf0caef8bd6bdb84f8e052d11679a3aad54044af54c082e13029842bf2e32fcc1522dfb114ec9010924995dd0d2dae0ea9916d05b503f61a47c6e61ae0e8c7ac23b4550203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d01010505000382010100827f
        EAP-Message = 0xbea6631325bf6ec662a7c5f5678d832f5625dfb248c3966f875be18169ad30a99fd3fcaac6e8b10444b5766f46235295d86e7b676f1e23acb1b4d2937faeacb5d8fc357d4058d7cfdb92e36f27ae164b23a4b21ca69ef588a7d6897c7ac76557392c4f949c087d008296b534c7f87ef18408ac108918512ca9529cedf4cd7cef2f3ff7b488895abf44b75d47e6fa831c4463c41135e5aaf1ebe69655662df39c2fdbf529b8976c9f243a6f963f2b725a6507211184859b35071a30fdfcea10bed6bd8d33afaf96c7af52b55c69eb87126a601593594f9f7fdb73d7bbfd4aa018146c999e12ad1408df3b75ab77a597deec17346336bc3d3db143d3bc71
        EAP-Message = 0x520004ab308204a73082038f
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x6065b4846261adf403817d959797c4d5
Finished request 2.
Going to the next request
Waking up in 2.9 seconds.
rad_recv: Access-Request packet from host 10.41.255.67 port 32769, id=85, length=258
        User-Name = "umsja\\test.juliusbess"
        Calling-Station-Id = "00-24-d7-70-50-20"
        Called-Station-Id = "50-06-04-4b-8e-a0:wifitesting"
        NAS-Port = 1
        Cisco-AVPair = "audit-session-id=0a29ff430000004d51d45b99"
        NAS-IP-Address = 10.41.255.67
        NAS-Identifier = "testingwifi"
        Airespace-Wlan-Id = 2
        Service-Type = Framed-User
        Framed-MTU = 1300
        NAS-Port-Type = Wireless-802.11
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "666"
        EAP-Message = 0x020400061900
        State = 0x6065b4846261adf403817d959797c4d5
        Message-Authenticator = 0x2f16decf6ee8a530cf750b9b6af28bf5
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
        expand: %{Stripped-User-Name} -> 
++[expand] returns noop
[suffix] No '@' in User-Name = "umsja\test.juliusbess", skipping NULL due to config.
++[suffix] returns noop
[ntdomain] Looking up realm "umsja" for User-Name = "umsja\test.juliusbess"
[ntdomain] Found realm "umsja"
[ntdomain] Adding Realm = "umsja"
[ntdomain] Proxying request from user test.juliusbess to realm umsja
[ntdomain] Preparing to proxy authentication request to realm "umsja" 
++[ntdomain] returns updated
        expand: %{Stripped-User-Name} -> 
++[expand] returns updated
[eap] Request is supposed to be proxied to Realm umsja.  Not doing EAP.
++[eap] returns noop
++[files] returns noop
[sql]   expand: %{User-Name} -> umsja\test.juliusbess
[sql] sql_set_user escaped user --> 'umsja\test.juliusbess'
rlm_sql (sql): Reserving sql socket id: 1
[sql]   expand: SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = 'umsja=5Ctest.juliusbess'           ORDER BY id
[sql]   expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = 'umsja=5Ctest.juliusbess'           ORDER BY priority
rlm_sql (sql): Released sql socket id: 1
[sql] User umsja\test.juliusbess not found
++[sql] returns notfound
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
  WARNING: Empty pre-proxy section.  Using default return values.
>>> Sending proxied request internally to virtual server.
server innra.umsja.is-srv {
# Executing section authorize from file /etc/raddb/sites-enabled/innra.umsja.is
+- entering group authorize {...}
++[preprocess] 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/raddb/sites-enabled/innra.umsja.is
+- 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
} # server innra.umsja.is-srv
Going to the next request
<<< Received proxied response code 11 from internal virtual server.
# Executing section post-proxy from file /etc/raddb/sites-enabled/default
+- entering group post-proxy {...}
[eap] No pre-existing handler found
++[eap] returns noop
Sending Access-Challenge of id 85 to 10.41.255.67 port 32769
        EAP-Message = 0x010503fc1940a00302010202090091e449f032dbca25300d06092a864886f70d0101050500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479301e170d3133303230353137353230375a170d3133303430363137353230375a308193310b3009060355040613024652310f300d0603550408130652616469757331
        EAP-Message = 0x12301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a0282010100a9cb9aa591e70f815330e7b69ad3537bea2b4559f2c67db55f225521ebdf68f6dc62a2012b96fd565add3dc95cb11d6c5a65e57be153ab37304564872e34ce043d5a04b0b534238bf2688d399f200b16969f4deb2a6434d5c5d0ec0976a93e0007d87edf99bf5da3
        EAP-Message = 0x969b21f1a9c091e940c1f7e9652f5dc3c08a794e725b4b16549581c4e9ca702a92d9c4956a071de3557c7db7a1289e0e6c6ed133e5ed8043e1e43a2c0d037e9eea8a36eeb5b0c51fd64471dc1508d1495d55d3d3ac01e8856b1dd9cfe22f466b4246ff3251339856857165ebfc65a3bb763621e701d08cee56480f14cd7f53064a7cd8e6acd3bbf6848d8ee9c17f93cc232662583d098f3d0203010001a381fb3081f8301d0603551d0e04160414a569118904c5768fcddd8a86bab54a3259d0dc153081c80603551d230481c03081bd8014a569118904c5768fcddd8a86bab54a3259d0dc15a18199a48196308193310b300906035504061302465231
        EAP-Message = 0x0f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f7269747982090091e449f032dbca25300c0603551d13040530030101ff300d06092a864886f70d010105050003820101002a3c28567d3c00b884a0bd7c4c0bb321e9998d81a6a060c63c6d79b75edd8bbf249181857fac9da549c29e16ec9abca5ac206741b02dd6cc16760a209cd8c7f31daae8c41cf09cabbb30a9
        EAP-Message = 0x023ee13376b0353f
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x6065b4846360adf403817d959797c4d5
Finished request 3.
Going to the next request
Waking up in 2.9 seconds.
rad_recv: Access-Request packet from host 10.41.255.67 port 32769, id=86, length=258
        User-Name = "umsja\\test.juliusbess"
        Calling-Station-Id = "00-24-d7-70-50-20"
        Called-Station-Id = "50-06-04-4b-8e-a0:wifitesting"
        NAS-Port = 1
        Cisco-AVPair = "audit-session-id=0a29ff430000004d51d45b99"
        NAS-IP-Address = 10.41.255.67
        NAS-Identifier = "testingwifi"
        Airespace-Wlan-Id = 2
        Service-Type = Framed-User
        Framed-MTU = 1300
        NAS-Port-Type = Wireless-802.11
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "666"
        EAP-Message = 0x020500061900
        State = 0x6065b4846360adf403817d959797c4d5
        Message-Authenticator = 0x405552f437fefb9e48fc0be764658d63
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
        expand: %{Stripped-User-Name} -> 
++[expand] returns noop
[suffix] No '@' in User-Name = "umsja\test.juliusbess", skipping NULL due to config.
++[suffix] returns noop
[ntdomain] Looking up realm "umsja" for User-Name = "umsja\test.juliusbess"
[ntdomain] Found realm "umsja"
[ntdomain] Adding Realm = "umsja"
[ntdomain] Proxying request from user test.juliusbess to realm umsja
[ntdomain] Preparing to proxy authentication request to realm "umsja" 
++[ntdomain] returns updated
        expand: %{Stripped-User-Name} -> 
++[expand] returns updated
[eap] Request is supposed to be proxied to Realm umsja.  Not doing EAP.
++[eap] returns noop
++[files] returns noop
[sql]   expand: %{User-Name} -> umsja\test.juliusbess
[sql] sql_set_user escaped user --> 'umsja\test.juliusbess'
rlm_sql (sql): Reserving sql socket id: 0
[sql]   expand: SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = 'umsja=5Ctest.juliusbess'           ORDER BY id
[sql]   expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = 'umsja=5Ctest.juliusbess'           ORDER BY priority
rlm_sql (sql): Released sql socket id: 0
[sql] User umsja\test.juliusbess not found
++[sql] returns notfound
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
  WARNING: Empty pre-proxy section.  Using default return values.
>>> Sending proxied request internally to virtual server.
server innra.umsja.is-srv {
# Executing section authorize from file /etc/raddb/sites-enabled/innra.umsja.is
+- entering group authorize {...}
++[preprocess] returns ok
[eap] EAP packet type response id 5 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/innra.umsja.is
+- 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
} # server innra.umsja.is-srv
Going to the next request
<<< Received proxied response code 11 from internal virtual server.
# Executing section post-proxy from file /etc/raddb/sites-enabled/default
+- entering group post-proxy {...}
[eap] No pre-existing handler found
++[eap] returns noop
Sending Access-Challenge of id 86 to 10.41.255.67 port 32769
        EAP-Message = 0x010602ce1900e06a92fd0b11ec061b21cda20a251c0711213bb7f98b5854f7d46c43be508c3f98b49d49e5992c6aa1f9c8ba4275ecd80c887164459c5490168ecae752bbff570ef2c6c51c58a4b1bc79aa43d90cce8dfe5855e4b22fcf934c93b6881f8608095107210412734ca8a305e78bfe10630b6ea64e2f710ded00edced92cdfe5d6c15e51fbbfdd32a35adaec3af42d77baf4a6b31f6e864275810afe0b5c7b8320e57f5f296fb65c225525948113e9160301020d0c0002090080f686f0066adbbed114d1c7eb3001393f511e48c91fa964a33d9c19ab5a3e2b10659d5af6d2488a3ef6255780a19f0bb7cdcef8999513e6f37295e3872e37a0
        EAP-Message = 0x90586461519bef31171a6576187f9276fbc188a4cff6b6ac03c6cd397e3b059b7d4c58243245bbc43fcc37b0eefb9e40aebf1745d9685ce062c61aa64bd20d0df300010200800fb917ffb1c630a802e5091e6f9064a84a8096dc023d97ace122635d8fd3edda13a2ea1429351a809059bbe826388cb6d830d953935530e26d67110f08842c7b083b6a3ff5a664d2897483ee916b2db17d0a2bb54f15c7e57600784a7732e3a64ff5780b07d82c50b8e47589ffa6eda76aa047a1b611b577ec2b93c4c85f051901002e402353171f096353370c893e5a8961d76706f1f5566beb10495de71e82d259a8cc4cfbfc26faed4022ce8c088c0989f2a07e5156
        EAP-Message = 0x55b7886210a8034f93ce89215272efa85a016cca311b9f265c0c15136ed9a8f341c0bb78bdb38ffd7c02762f8294b7b5d2a7d4085c1b947e06f38d000b8f6a385ceb46597758e5f2c3c9c76ebb0c9bb9885c3e02a0b54bca14f7fa4d016758524a993d18e1237bab6163321e34956ee345512247edcce69600f75bade260015dbe05a591d3859e853eaa5465c5a27e68e979a1ed2d9eed096a889f0e4607b6677b16fa07bd4b02ffb12c9595f62547e496431f1d903269b54d0b4780277779d1de8299c79d9f73bc18bcb616030100040e000000
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x6065b4846463adf403817d959797c4d5
Finished request 4.
Going to the next request
Waking up in 2.9 seconds.
rad_recv: Access-Request packet from host 10.41.255.67 port 32769, id=87, length=460
        User-Name = "umsja\\test.juliusbess"
        Calling-Station-Id = "00-24-d7-70-50-20"
        Called-Station-Id = "50-06-04-4b-8e-a0:wifitesting"
        NAS-Port = 1
        Cisco-AVPair = "audit-session-id=0a29ff430000004d51d45b99"
        NAS-IP-Address = 10.41.255.67
        NAS-Identifier = "testingwifi"
        Airespace-Wlan-Id = 2
        Service-Type = Framed-User
        Framed-MTU = 1300
        NAS-Port-Type = Wireless-802.11
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "666"
        EAP-Message = 0x020600d01980000000c616030100861000008200808f70361600e6884b8b880628fdf7934e73c76e9d4529b3097098c3ab1ea7f11cf81bc2a42b66daef7945d1ba3f2dd381f67a6b8e0c20fdef3f2da061e6f9c92e1ac342513f802722437170545dd218d3b4012a4465e418bf41a4a53ea2d8c8b84fdf2bb3dbf1b17e62acfc94e9dc6bbf08c7659a73e622a089f5617bca54d94914030100010116030100304ab49873224a31a202761cce95d224bb7878f8f7a99ef683eb69842ffbf11feede537e4f4b307b13856187a1c120af81
        State = 0x6065b4846463adf403817d959797c4d5
        Message-Authenticator = 0xe18e3dae1a2336df0bc743acc319e194
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
        expand: %{Stripped-User-Name} -> 
++[expand] returns noop
[suffix] No '@' in User-Name = "umsja\test.juliusbess", skipping NULL due to config.
++[suffix] returns noop
[ntdomain] Looking up realm "umsja" for User-Name = "umsja\test.juliusbess"
[ntdomain] Found realm "umsja"
[ntdomain] Adding Realm = "umsja"
[ntdomain] Proxying request from user test.juliusbess to realm umsja
[ntdomain] Preparing to proxy authentication request to realm "umsja" 
++[ntdomain] returns updated
        expand: %{Stripped-User-Name} -> 
++[expand] returns updated
[eap] Request is supposed to be proxied to Realm umsja.  Not doing EAP.
++[eap] returns noop
++[files] returns noop
[sql]   expand: %{User-Name} -> umsja\test.juliusbess
[sql] sql_set_user escaped user --> 'umsja\test.juliusbess'
rlm_sql (sql): Reserving sql socket id: 4
[sql]   expand: SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = 'umsja=5Ctest.juliusbess'           ORDER BY id
[sql]   expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = 'umsja=5Ctest.juliusbess'           ORDER BY priority
rlm_sql (sql): Released sql socket id: 4
[sql] User umsja\test.juliusbess not found
++[sql] returns notfound
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
  WARNING: Empty pre-proxy section.  Using default return values.
>>> Sending proxied request internally to virtual server.
server innra.umsja.is-srv {
# Executing section authorize from file /etc/raddb/sites-enabled/innra.umsja.is
+- entering group authorize {...}
++[preprocess] returns ok
[eap] EAP packet type response id 6 length 208
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/innra.umsja.is
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
  TLS Length 198
[peap] Length Included
[peap] eaptls_verify returned 11 
[peap] <<< TLS 1.0 Handshake [length 0086], 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
} # server innra.umsja.is-srv
Going to the next request
<<< Received proxied response code 11 from internal virtual server.
# Executing section post-proxy from file /etc/raddb/sites-enabled/default
+- entering group post-proxy {...}
[eap] No pre-existing handler found
++[eap] returns noop
Sending Access-Challenge of id 87 to 10.41.255.67 port 32769
        EAP-Message = 0x010700411900140301000101160301003017e6caef5b9b7254a4725c893be7b4d5361f4ff9aadbee5f333bfaefeef6f575b310e22fab5294313091245ae175d2fe
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x6065b4846562adf403817d959797c4d5
Finished request 5.
Going to the next request
Waking up in 2.9 seconds.
rad_recv: Access-Request packet from host 10.41.255.67 port 32769, id=88, length=258
        User-Name = "umsja\\test.juliusbess"
        Calling-Station-Id = "00-24-d7-70-50-20"
        Called-Station-Id = "50-06-04-4b-8e-a0:wifitesting"
        NAS-Port = 1
        Cisco-AVPair = "audit-session-id=0a29ff430000004d51d45b99"
        NAS-IP-Address = 10.41.255.67
        NAS-Identifier = "testingwifi"
        Airespace-Wlan-Id = 2
        Service-Type = Framed-User
        Framed-MTU = 1300
        NAS-Port-Type = Wireless-802.11
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "666"
        EAP-Message = 0x020700061900
        State = 0x6065b4846562adf403817d959797c4d5
        Message-Authenticator = 0xc0d4ea52ec3e687fe443fa366f41aaeb
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
        expand: %{Stripped-User-Name} -> 
++[expand] returns noop
[suffix] No '@' in User-Name = "umsja\test.juliusbess", skipping NULL due to config.
++[suffix] returns noop
[ntdomain] Looking up realm "umsja" for User-Name = "umsja\test.juliusbess"
[ntdomain] Found realm "umsja"
[ntdomain] Adding Realm = "umsja"
[ntdomain] Proxying request from user test.juliusbess to realm umsja
[ntdomain] Preparing to proxy authentication request to realm "umsja" 
++[ntdomain] returns updated
        expand: %{Stripped-User-Name} -> 
++[expand] returns updated
[eap] Request is supposed to be proxied to Realm umsja.  Not doing EAP.
++[eap] returns noop
++[files] returns noop
[sql]   expand: %{User-Name} -> umsja\test.juliusbess
[sql] sql_set_user escaped user --> 'umsja\test.juliusbess'
rlm_sql (sql): Reserving sql socket id: 3
[sql]   expand: SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = 'umsja=5Ctest.juliusbess'           ORDER BY id
[sql]   expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = 'umsja=5Ctest.juliusbess'           ORDER BY priority
rlm_sql (sql): Released sql socket id: 3
[sql] User umsja\test.juliusbess not found
++[sql] returns notfound
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
  WARNING: Empty pre-proxy section.  Using default return values.
>>> Sending proxied request internally to virtual server.
server innra.umsja.is-srv {
# Executing section authorize from file /etc/raddb/sites-enabled/innra.umsja.is
+- entering group authorize {...}
++[preprocess] returns ok
[eap] EAP packet type response id 7 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/innra.umsja.is
+- 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
} # server innra.umsja.is-srv
Going to the next request
<<< Received proxied response code 11 from internal virtual server.
# Executing section post-proxy from file /etc/raddb/sites-enabled/default
+- entering group post-proxy {...}
[eap] No pre-existing handler found
++[eap] returns noop
Sending Access-Challenge of id 88 to 10.41.255.67 port 32769
        EAP-Message = 0x0108002b19001703010020772c222c1fce326b0af116e8327332c0da551ea836590b36734191b014a5f1f6
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x6065b484666dadf403817d959797c4d5
Finished request 6.
Going to the next request
Waking up in 2.9 seconds.
rad_recv: Access-Request packet from host 10.41.255.67 port 32769, id=89, length=348
        User-Name = "umsja\\test.juliusbess"
        Calling-Station-Id = "00-24-d7-70-50-20"
        Called-Station-Id = "50-06-04-4b-8e-a0:wifitesting"
        NAS-Port = 1
        Cisco-AVPair = "audit-session-id=0a29ff430000004d51d45b99"
        NAS-IP-Address = 10.41.255.67
        NAS-Identifier = "testingwifi"
        Airespace-Wlan-Id = 2
        Service-Type = Framed-User
        Framed-MTU = 1300
        NAS-Port-Type = Wireless-802.11
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "666"
        EAP-Message = 0x0208006019001703010020bdfdff1470deb7f66018b90902da81491022ccfd403f062ed2841871543804b21703010030305696bfe3ca602b71ba4832195b21b5357b5e9978c2e77b49e51a85fc009ca210771f1349e1d92a0523f01aee54d3a3
        State = 0x6065b484666dadf403817d959797c4d5
        Message-Authenticator = 0x3f1ef4e25d5c0fe2b0b7f2202a442876
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
        expand: %{Stripped-User-Name} -> 
++[expand] returns noop
[suffix] No '@' in User-Name = "umsja\test.juliusbess", skipping NULL due to config.
++[suffix] returns noop
[ntdomain] Looking up realm "umsja" for User-Name = "umsja\test.juliusbess"
[ntdomain] Found realm "umsja"
[ntdomain] Adding Realm = "umsja"
[ntdomain] Proxying request from user test.juliusbess to realm umsja
[ntdomain] Preparing to proxy authentication request to realm "umsja" 
++[ntdomain] returns updated
        expand: %{Stripped-User-Name} -> 
++[expand] returns updated
[eap] Request is supposed to be proxied to Realm umsja.  Not doing EAP.
++[eap] returns noop
++[files] returns noop
[sql]   expand: %{User-Name} -> umsja\test.juliusbess
[sql] sql_set_user escaped user --> 'umsja\test.juliusbess'
rlm_sql (sql): Reserving sql socket id: 2
[sql]   expand: SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = 'umsja=5Ctest.juliusbess'           ORDER BY id
[sql]   expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = 'umsja=5Ctest.juliusbess'           ORDER BY priority
rlm_sql (sql): Released sql socket id: 2
[sql] User umsja\test.juliusbess not found
++[sql] returns notfound
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
  WARNING: Empty pre-proxy section.  Using default return values.
>>> Sending proxied request internally to virtual server.
server innra.umsja.is-srv {
# Executing section authorize from file /etc/raddb/sites-enabled/innra.umsja.is
+- entering group authorize {...}
++[preprocess] returns ok
[eap] EAP packet type response id 8 length 96
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/innra.umsja.is
+- 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 - umsja\test.juliusbess
[peap] Got inner identity 'umsja\test.juliusbess'
[peap] Setting default EAP type for tunneled EAP session.
[peap] Got tunneled request
        EAP-Message = 0x0208001a01756d736a615c746573742e6a756c69757362657373
server innra.umsja.is-srv {
[peap] Setting User-Name to umsja\test.juliusbess
Sending tunneled request
        EAP-Message = 0x0208001a01756d736a615c746573742e6a756c69757362657373
        FreeRADIUS-Proxied-To = 127.0.0.1
        User-Name = "umsja\\test.juliusbess"
server inner-tunnel {
# Executing section authorize from file /etc/raddb/sites-enabled/inner-tunnel
+- entering group authorize {...}
++[chap] returns noop
++? if (Realm == "innra.umsja.is" || "umsja")
    (Attribute Realm was not found)
? Evaluating (Realm == "innra.umsja.is" ) -> FALSE
? Evaluating ("umsja") -> TRUE
++? if (Realm == "innra.umsja.is" || "umsja") -> TRUE
++- entering if (Realm == "innra.umsja.is" || "umsja") {...}
+++[mschap-innra.umsja.is] returns noop
[ldap-innra.umsja.is] performing user authorization for umsja\test.juliusbess
[ldap-innra.umsja.is]   expand: %{Stripped-User-Name} -> 
[ldap-innra.umsja.is]   ... expanding second conditional
[ldap-innra.umsja.is]   expand: %{User-Name} -> umsja\5ctest.juliusbess
[ldap-innra.umsja.is]   expand: (sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}) -> (sAMAccountName=umsja\5ctest.juliusbess)
[ldap-innra.umsja.is]   expand: DC=innra,DC=umsja,DC=is -> DC=innra,DC=umsja,DC=is
  [ldap-innra.umsja.is] ldap_get_conn: Checking Id: 0
  [ldap-innra.umsja.is] ldap_get_conn: Got Id: 0
  [ldap-innra.umsja.is] performing search in DC=innra,DC=umsja,DC=is, with filter (sAMAccountName=umsja\5ctest.juliusbess)
  [ldap-innra.umsja.is] rebind to URL ldap://DomainDnsZones.innra.umsja.is/DC=DomainDnsZones,DC=innra,DC=umsja,DC=is
  [ldap-innra.umsja.is] rebind to URL ldap://ForestDnsZones.innra.umsja.is/DC=ForestDnsZones,DC=innra,DC=umsja,DC=is
  [ldap-innra.umsja.is] object not found
[ldap-innra.umsja.is] search failed
  [ldap-innra.umsja.is] ldap_release_conn: Release Id: 0
+++[ldap-innra.umsja.is] returns notfound
        expand: %{Stripped-User-Name} -> 
+++[expand] returns notfound
+++? if (outer.control:ldap-innra.umsja.is-Ldap-Group == "%{outer.control:Tmp-String-0}-WiFi-Allow")
        expand: %{outer.control:Tmp-String-0}-WiFi-Allow -> -WiFi-Allow
    (Attribute outer.control:ldap-innra.umsja.is-Ldap-Group was not found)
? Evaluating (outer.control:ldap-innra.umsja.is-Ldap-Group == "%{outer.control:Tmp-String-0}-WiFi-Allow") -> FALSE
+++? if (outer.control:ldap-innra.umsja.is-Ldap-Group == "%{outer.control:Tmp-String-0}-WiFi-Allow") -> FALSE
++- if (Realm == "innra.umsja.is" || "umsja") returns notfound
++ ... skipping else for request 7: Preceding "if" was taken
[suffix] No '@' in User-Name = "umsja\test.juliusbess", skipping NULL due to config.
++[suffix] returns noop
[ntdomain] Looking up realm "umsja" for User-Name = "umsja\test.juliusbess"
[ntdomain] Found realm "umsja"
[ntdomain] Adding Realm = "umsja"
[ntdomain] Proxying request from user test.juliusbess to realm umsja
[ntdomain] Preparing to proxy authentication request to realm "umsja" 
++[ntdomain] returns updated
++[control] returns updated
[eap] EAP packet type response id 8 length 26
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/inner-tunnel
+- entering group authenticate {...}
[eap] Multiple levels of TLS nesting is invalid.
[eap] Failed in EAP select
++[eap] returns invalid
Failed to authenticate the user.
} # server inner-tunnel
[peap] Got tunneled reply code 3
        EAP-Message = 0x04080004
        Message-Authenticator = 0x00000000000000000000000000000000
[peap] Got tunneled reply RADIUS code 3
        EAP-Message = 0x04080004
        Message-Authenticator = 0x00000000000000000000000000000000
[peap] Tunneled authentication was rejected.
[peap] FAILURE
++[eap] returns handled
} # server innra.umsja.is-srv
Going to the next request
<<< Received proxied response code 11 from internal virtual server.
# Executing section post-proxy from file /etc/raddb/sites-enabled/default
+- entering group post-proxy {...}
[eap] No pre-existing handler found
++[eap] returns noop
Sending Access-Challenge of id 89 to 10.41.255.67 port 32769
        EAP-Message = 0x0109002b19001703010020f20d45942f22ed3fa167e5585a2fa95db6fe991859bdb5f43d9495fdd4d899e9
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x6065b484676cadf403817d959797c4d5
Finished request 7.
Going to the next request
Waking up in 2.9 seconds.
rad_recv: Access-Request packet from host 10.41.255.67 port 32769, id=90, length=332
        User-Name = "umsja\\test.juliusbess"
        Calling-Station-Id = "00-24-d7-70-50-20"
        Called-Station-Id = "50-06-04-4b-8e-a0:wifitesting"
        NAS-Port = 1
        Cisco-AVPair = "audit-session-id=0a29ff430000004d51d45b99"
        NAS-IP-Address = 10.41.255.67
        NAS-Identifier = "testingwifi"
        Airespace-Wlan-Id = 2
        Service-Type = Framed-User
        Framed-MTU = 1300
        NAS-Port-Type = Wireless-802.11
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "666"
        EAP-Message = 0x0209005019001703010020f14d195b0edd328bcdc520e9f77e7303eae5cb2ea0496db5b804a3f17d0f2a3717030100207865dafd65dce078abc49fcb221a8727501b4ed9a3d1aebfb9fa7a73ba3f7643
        State = 0x6065b484676cadf403817d959797c4d5
        Message-Authenticator = 0x9dc5ed031427a9e0a4c23499bb0aa25e
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
        expand: %{Stripped-User-Name} -> 
++[expand] returns noop
[suffix] No '@' in User-Name = "umsja\test.juliusbess", skipping NULL due to config.
++[suffix] returns noop
[ntdomain] Looking up realm "umsja" for User-Name = "umsja\test.juliusbess"
[ntdomain] Found realm "umsja"
[ntdomain] Adding Realm = "umsja"
[ntdomain] Proxying request from user test.juliusbess to realm umsja
[ntdomain] Preparing to proxy authentication request to realm "umsja" 
++[ntdomain] returns updated
        expand: %{Stripped-User-Name} -> 
++[expand] returns updated
[eap] Request is supposed to be proxied to Realm umsja.  Not doing EAP.
++[eap] returns noop
++[files] returns noop
[sql]   expand: %{User-Name} -> umsja\test.juliusbess
[sql] sql_set_user escaped user --> 'umsja\test.juliusbess'
rlm_sql (sql): Reserving sql socket id: 1
[sql]   expand: SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = 'umsja=5Ctest.juliusbess'           ORDER BY id
[sql]   expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = 'umsja=5Ctest.juliusbess'           ORDER BY priority
rlm_sql (sql): Released sql socket id: 1
[sql] User umsja\test.juliusbess not found
++[sql] returns notfound
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
  WARNING: Empty pre-proxy section.  Using default return values.
>>> Sending proxied request internally to virtual server.
server innra.umsja.is-srv {
# Executing section authorize from file /etc/raddb/sites-enabled/innra.umsja.is
+- entering group authorize {...}
++[preprocess] returns ok
[eap] EAP packet type response id 9 length 80
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/innra.umsja.is
+- 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.
} # server innra.umsja.is-srv
Going to the next request
<<< Received proxied response code 3 from internal virtual server.
# Executing section post-proxy from file /etc/raddb/sites-enabled/default
+- entering group post-proxy {...}
[eap] No pre-existing handler found
++[eap] returns noop
Using Post-Auth-Type Reject
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group REJECT {...}
[attr_filter.access_reject]     expand: %{User-Name} -> umsja\test.juliusbess
attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] returns updated
Delaying reject of request 8 for 1 seconds
Going to the next request
Waking up in 0.9 seconds.
Sending delayed reject for request 8
Sending Access-Reject of id 90 to 10.41.255.67 port 32769
        EAP-Message = 0x04090004
        Message-Authenticator = 0x00000000000000000000000000000000
Waking up in 1.9 seconds.


###############################################################
###############################################################

Without nostrip:

rad_recv: Access-Request packet from host 10.41.255.67 port 32769, id=81, length=260
        User-Name = "umsja\\test.juliusbess"
        Calling-Station-Id = "00-24-d7-70-50-20"
        Called-Station-Id = "50-06-04-4b-8e-a0:wifitesting"
        NAS-Port = 1
        Cisco-AVPair = "audit-session-id=0a29ff430000004c51d45858"
        NAS-IP-Address = 10.41.255.67
        NAS-Identifier = "testingwifi"
        Airespace-Wlan-Id = 2
        Service-Type = Framed-User
        Framed-MTU = 1300
        NAS-Port-Type = Wireless-802.11
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        Tunnel-Private-Group-Id:0 = "666"
        EAP-Message = 0x0201001a01756d736a615c746573742e6a756c69757362657373
        Message-Authenticator = 0xbf9b0ad3aaaaa4fbb3b96a2a6d61b6f8
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
        expand: %{Stripped-User-Name} -> 
++[expand] returns noop
[suffix] No '@' in User-Name = "umsja\test.juliusbess", skipping NULL due to config.
++[suffix] returns noop
[ntdomain] Looking up realm "umsja" for User-Name = "umsja\test.juliusbess"
[ntdomain] Found realm "umsja"
[ntdomain] Adding Stripped-User-Name = "test.juliusbess"
[ntdomain] Adding Realm = "umsja"
[ntdomain] Proxying request from user test.juliusbess to realm umsja
[ntdomain] Preparing to proxy authentication request to realm "umsja" 
++[ntdomain] returns updated
        expand: %{Stripped-User-Name} -> test.juliusbess
++[expand] returns updated
[eap] Request is supposed to be proxied to Realm umsja.  Not doing EAP.
++[eap] returns noop
++[files] returns noop
[sql]   expand: %{User-Name} -> umsja\test.juliusbess
[sql] sql_set_user escaped user --> 'umsja\test.juliusbess'
rlm_sql (sql): Reserving sql socket id: 2
[sql]   expand: SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = 'umsja=5Ctest.juliusbess'           ORDER BY id
[sql]   expand: SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           FROM radusergroup           WHERE username = 'umsja=5Ctest.juliusbess'           ORDER BY priority
rlm_sql (sql): Released sql socket id: 2
[sql] User umsja\test.juliusbess not found
++[sql] returns notfound
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
  WARNING: Empty pre-proxy section.  Using default return values.
>>> Sending proxied request internally to virtual server.
server innra.umsja.is-srv {
# Executing section authorize from file /etc/raddb/sites-enabled/innra.umsja.is
+- entering group authorize {...}
++[preprocess] returns ok
[eap] EAP packet type response id 1 length 26
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[mschap-innra.umsja.is] returns noop
[ldap-innra.umsja.is] performing user authorization for test.juliusbess
[ldap-innra.umsja.is]   expand: %{Stripped-User-Name} -> test.juliusbess
[ldap-innra.umsja.is]   expand: (sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}) -> (sAMAccountName=test.juliusbess)
[ldap-innra.umsja.is]   expand: DC=innra,DC=umsja,DC=is -> DC=innra,DC=umsja,DC=is
  [ldap-innra.umsja.is] ldap_get_conn: Checking Id: 0
  [ldap-innra.umsja.is] ldap_get_conn: Got Id: 0
  [ldap-innra.umsja.is] performing search in DC=innra,DC=umsja,DC=is, with filter (sAMAccountName=test.juliusbess)
  [ldap-innra.umsja.is] rebind to URL ldap://ForestDnsZones.innra.umsja.is/DC=ForestDnsZones,DC=innra,DC=umsja,DC=is
  [ldap-innra.umsja.is] rebind to URL ldap://DomainDnsZones.innra.umsja.is/DC=DomainDnsZones,DC=innra,DC=umsja,DC=is
[ldap-innra.umsja.is] looking for check items in directory...
  [ldap-innra.umsja.is] extensionAttribute10 -> Jira-Key == "MEF"
[ldap-innra.umsja.is] looking for reply items in directory...
WARNING: No "known good" password was found in LDAP.  Are you sure that the user is configured correctly?
[ldap-innra.umsja.is] user test.juliusbess authorized to use remote access
  [ldap-innra.umsja.is] ldap_release_conn: Release Id: 0
++[ldap-innra.umsja.is] returns ok
        expand: %{control:Ldap-UserDN} -> CN=Júlíus �?ór Bess - Test,OU=Test Accounts,OU=Users,OU=NYH,OU=Nyherji Group,DC=innra,DC=umsja,DC=is
++[expand] returns ok
        expand: %{User-Name} -> test.juliusbess <<<---------------
++[expand] returns ok
        expand: %{Stripped-User-Name} -> test.juliusbess  <<<---------------
++[expand] returns ok
++? if (control:Ldap-UserDN =~ /^.+,OU=Users,OU=([^,]+),/i)
? Evaluating (control:Ldap-UserDN =~ /^.+,OU=Users,OU=([^,]+),/i) -> TRUE
++? if (control:Ldap-UserDN =~ /^.+,OU=Users,OU=([^,]+),/i) -> TRUE
++- entering if (control:Ldap-UserDN =~ /^.+,OU=Users,OU=([^,]+),/i) {...}
        expand: %{1} -> NYH
+++[control] returns ok
        expand: %{control:Tmp-String-0} -> NYH
+++[expand] returns ok
++- if (control:Ldap-UserDN =~ /^.+,OU=Users,OU=([^,]+),/i) returns ok
++? if (control:Jira-Key != "")
? Evaluating (control:Jira-Key != "") -> TRUE
++? if (control:Jira-Key != "") -> TRUE
++- entering if (control:Jira-Key != "") {...}
        expand: %{control:Jira-Key} -> MEF
+++[expand] returns ok
++- if (control:Jira-Key != "") returns ok
++? if (Huntgroup-Name == ppp-bidlarar)
    (Attribute Huntgroup-Name was not found)
? Evaluating (Huntgroup-Name == ppp-bidlarar) -> FALSE
++? if (Huntgroup-Name == ppp-bidlarar) -> FALSE
++? if (Huntgroup-Name == vpn-nas)
    (Attribute Huntgroup-Name was not found)
? Evaluating (Huntgroup-Name == vpn-nas) -> FALSE
++? if (Huntgroup-Name == vpn-nas) -> FALSE
++[files] returns noop
++[expiration] returns noop
++[logintime] returns noop
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/innra.umsja.is
+- entering group authenticate {...}
[eap] Identity does not match User-Name, setting from EAP Identity. <<<---- without nostrip
[eap] Failed in handler
++[eap] returns invalid
Failed to authenticate the user.
} # server innra.umsja.is-srv
Going to the next request
<<< Received proxied response code 3 from internal virtual server.
# Executing section post-proxy from file /etc/raddb/sites-enabled/default
+- entering group post-proxy {...}
[eap] No pre-existing handler found
++[eap] returns noop
Using Post-Auth-Type Reject
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group REJECT {...}
[attr_filter.access_reject]     expand: %{User-Name} -> umsja\test.juliusbess
attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] returns updated
Delaying reject of request 2 for 1 seconds
Going to the next request
Waking up in 0.9 seconds.
Sending delayed reject for request 2
Sending Access-Reject of id 81 to 10.41.255.67 port 32769
Waking up in 4.9 seconds.
Cleaning up request 2 ID 81 with timestamp +76
Ready to process requests.



-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html


More information about the Freeradius-Users mailing list