OpenLDAP Group membership to Filter-ID

Alex Gregory alex at c2company.com
Wed Aug 13 21:22:41 CEST 2014 

I did not have that in there.  I added it into the ldap module so my config now looks like:

ldap {
        server = "localhost"
        identity = "cn=admin,dc=team,dc=company,dc=com"
        password = xxxxx
        basedn = "ou=Users,dc=team,dc=company,dc=com"
        scope = “sub”
        filter = "(uid=%{%{Stripped-User-Name}:-%{User-Name}})”
...
}




Here is the output from -XXX

rad_recv: Access-Request packet from host xxx.xxx.xxx.xxx port 32768, id=101, length=215
	User-Name = "joeuser"
	Chargeable-User-Identity = ""
	Location-Capable = Civix-Location
	Calling-Station-Id = "78-31-c1-be-89-a8"
	Called-Station-Id = "d4-a0-2a-15-7f-00:C2_Test"
	NAS-Port = 4
	Cisco-AVPair = "audit-session-id=0a210082000006c453ebb861"
	NAS-IP-Address = 10.33.0.130
	NAS-Identifier = "inWebo"
	Airespace-Wlan-Id = 6
	Service-Type = Framed-User
	Framed-MTU = 1300
	NAS-Port-Type = Wireless-802.11
	EAP-Message = 0x0201000c016a6f6575736572
	Message-Authenticator = 0x882183e2a08a2bce65b1792c44079165
Wed Aug 13 19:11:30 2014 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Aug 13 19:11:30 2014 : Info: +- entering group authorize {...}
Wed Aug 13 19:11:30 2014 : Info: ++[preprocess] returns ok
Wed Aug 13 19:11:30 2014 : Info: ++[chap] returns noop
Wed Aug 13 19:11:30 2014 : Info: ++[mschap] returns noop
Wed Aug 13 19:11:30 2014 : Info: ++[digest] returns noop
Wed Aug 13 19:11:30 2014 : Info: [suffix] No '@' in User-Name = "joeuser", looking up realm NULL
Wed Aug 13 19:11:30 2014 : Info: [suffix] No such realm "NULL"
Wed Aug 13 19:11:30 2014 : Info: ++[suffix] returns noop
Wed Aug 13 19:11:30 2014 : Info: [eap] EAP packet type response id 1 length 12
Wed Aug 13 19:11:30 2014 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Wed Aug 13 19:11:30 2014 : Info: ++[eap] returns updated
Wed Aug 13 19:11:30 2014 : Info: ++[files] returns noop
Wed Aug 13 19:11:30 2014 : Info: [ldap] performing user authorization for joeuser
Wed Aug 13 19:11:30 2014 : Info: [ldap] 	expand: %{Stripped-User-Name} -> 
Wed Aug 13 19:11:30 2014 : Info: [ldap] 	... expanding second conditional
Wed Aug 13 19:11:30 2014 : Info: [ldap] 	expand: %{User-Name} -> joeuser
Wed Aug 13 19:11:30 2014 : Info: [ldap] 	expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=joeuser)
Wed Aug 13 19:11:30 2014 : Info: [ldap] 	expand: ou=Users,dc=team,dc=company,dc=com -> ou=Users,dc=team,dc=company,dc=com
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] ldap_get_conn: Got Id: 0
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] attempting LDAP reconnection
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] (re)connect to localhost:389, authentication 0
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] bind as cn=admin,dc=team,dc=company,dc=com/653776d05374 to localhost:389
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] waiting for bind result ...
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] Bind was successful
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] performing search in ou=Users,dc=team,dc=company,dc=com, with filter (uid=joeuser)
Wed Aug 13 19:11:30 2014 : Info: [ldap] No default NMAS login sequence
Wed Aug 13 19:11:30 2014 : Info: [ldap] looking for check items in directory...
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] userPassword -> Password-With-Header == "{MD5}X03MO1qnZdYdgyfeuILPmQ=="
Wed Aug 13 19:11:30 2014 : Info: [ldap] looking for reply items in directory...
Wed Aug 13 19:11:30 2014 : Info: [ldap] user joeuser authorized to use remote access
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Wed Aug 13 19:11:30 2014 : Info: ++[ldap] returns ok
Wed Aug 13 19:11:30 2014 : Info: ++[expiration] returns noop
Wed Aug 13 19:11:30 2014 : Info: ++[logintime] returns noop
Wed Aug 13 19:11:30 2014 : Info: [pap] WARNING: Auth-Type already set.  Not setting to PAP
Wed Aug 13 19:11:30 2014 : Info: ++[pap] returns noop
Wed Aug 13 19:11:30 2014 : Info: Found Auth-Type = EAP
Wed Aug 13 19:11:30 2014 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Aug 13 19:11:30 2014 : Info: +- entering group authenticate {...}
Wed Aug 13 19:11:30 2014 : Info: [eap] EAP Identity
Wed Aug 13 19:11:30 2014 : Info: [eap] processing type tls
Wed Aug 13 19:11:30 2014 : Info: [tls] Initiate
Wed Aug 13 19:11:30 2014 : Info: [tls] Start returned 1
Wed Aug 13 19:11:30 2014 : Info: ++[eap] returns handled
Sending Access-Challenge of id 101 to xxx.xxx.xxx.xxx port 32768
	EAP-Message = 0x010200061520
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xce049ae9ce068f152ab18dd0a9f47460
Wed Aug 13 19:11:30 2014 : Info: Finished request 0.
Wed Aug 13 19:11:30 2014 : Debug: Going to the next request
Wed Aug 13 19:11:30 2014 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host xxx.xxx.xxx.xxx port 32768, id=102, length=373
	User-Name = "joeuser"
	Chargeable-User-Identity = ""
	Location-Capable = Civix-Location
	Calling-Station-Id = "78-31-c1-be-89-a8"
	Called-Station-Id = "d4-a0-2a-15-7f-00:C2_Test"
	NAS-Port = 4
	Cisco-AVPair = "audit-session-id=0a210082000006c453ebb861"
	NAS-IP-Address = 10.33.0.130
	NAS-Identifier = "inWebo"
	Airespace-Wlan-Id = 6
	Service-Type = Framed-User
	Framed-MTU = 1300
	NAS-Port-Type = Wireless-802.11
	EAP-Message = 0x0202009815800000008e160301008901000085030153ebb86267f54fc71b8caba32338c6ac7b304b74e7b8ea6d3121e26a2ed7c8d800004a00ffc024c023c00ac009c007c008c028c027c014c013c011c012c026c025c02ac029c005c004c002c003c00fc00ec00cc00d003d003c002f000500040035000a0067006b00330039001601000012000a00080006001700180019000b00020100
	State = 0xce049ae9ce068f152ab18dd0a9f47460
	Message-Authenticator = 0x5bde15e0f296c2eec38dd20a652cce44
Wed Aug 13 19:11:30 2014 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Aug 13 19:11:30 2014 : Info: +- entering group authorize {...}
Wed Aug 13 19:11:30 2014 : Info: ++[preprocess] returns ok
Wed Aug 13 19:11:30 2014 : Info: ++[chap] returns noop
Wed Aug 13 19:11:30 2014 : Info: ++[mschap] returns noop
Wed Aug 13 19:11:30 2014 : Info: ++[digest] returns noop
Wed Aug 13 19:11:30 2014 : Info: [suffix] No '@' in User-Name = "joeuser", looking up realm NULL
Wed Aug 13 19:11:30 2014 : Info: [suffix] No such realm "NULL"
Wed Aug 13 19:11:30 2014 : Info: ++[suffix] returns noop
Wed Aug 13 19:11:30 2014 : Info: [eap] EAP packet type response id 2 length 152
Wed Aug 13 19:11:30 2014 : Info: [eap] Continuing tunnel setup.
Wed Aug 13 19:11:30 2014 : Info: ++[eap] returns ok
Wed Aug 13 19:11:30 2014 : Info: Found Auth-Type = EAP
Wed Aug 13 19:11:30 2014 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Aug 13 19:11:30 2014 : Info: +- entering group authenticate {...}
Wed Aug 13 19:11:30 2014 : Info: [eap] Request found, released from the list
Wed Aug 13 19:11:30 2014 : Info: [eap] EAP/ttls
Wed Aug 13 19:11:30 2014 : Info: [eap] processing type ttls
Wed Aug 13 19:11:30 2014 : Info: [ttls] Authenticate
Wed Aug 13 19:11:30 2014 : Info: [ttls] processing EAP-TLS
Wed Aug 13 19:11:30 2014 : Debug:   TLS Length 142
Wed Aug 13 19:11:30 2014 : Info: [ttls] Length Included
Wed Aug 13 19:11:30 2014 : Info: [ttls] eaptls_verify returned 11 
Wed Aug 13 19:11:30 2014 : Info: [ttls]     (other): before/accept initialization
Wed Aug 13 19:11:30 2014 : Info: [ttls]     TLS_accept: before/accept initialization
Wed Aug 13 19:11:30 2014 : Info: [ttls] <<< TLS 1.0 Handshake [length 0089], ClientHello  
Wed Aug 13 19:11:30 2014 : Info: [ttls]     TLS_accept: SSLv3 read client hello A
Wed Aug 13 19:11:30 2014 : Info: [ttls] >>> TLS 1.0 Handshake [length 0039], ServerHello  
Wed Aug 13 19:11:30 2014 : Info: [ttls]     TLS_accept: SSLv3 write server hello A
Wed Aug 13 19:11:30 2014 : Info: [ttls] >>> TLS 1.0 Handshake [length 02c4], Certificate  
Wed Aug 13 19:11:30 2014 : Info: [ttls]     TLS_accept: SSLv3 write certificate A
Wed Aug 13 19:11:30 2014 : Info: [ttls] >>> TLS 1.0 Handshake [length 014b], ServerKeyExchange  
Wed Aug 13 19:11:30 2014 : Info: [ttls]     TLS_accept: SSLv3 write key exchange A
Wed Aug 13 19:11:30 2014 : Info: [ttls] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone  
Wed Aug 13 19:11:30 2014 : Info: [ttls]     TLS_accept: SSLv3 write server done A
Wed Aug 13 19:11:30 2014 : Info: [ttls]     TLS_accept: SSLv3 flush data
Wed Aug 13 19:11:30 2014 : Info: [ttls]     TLS_accept: Need to read more data: SSLv3 read client certificate A
Wed Aug 13 19:11:30 2014 : Debug: In SSL Handshake Phase 
Wed Aug 13 19:11:30 2014 : Debug: In SSL Accept mode  
Wed Aug 13 19:11:30 2014 : Info: [ttls] eaptls_process returned 13 
Wed Aug 13 19:11:30 2014 : Info: ++[eap] returns handled
Sending Access-Challenge of id 102 to xxx.xxx.xxx.xxx port 32768
	EAP-Message = 0x0103040015c000000460160301003902000035030153ebb862012b65c4fb6e4f52554f17ee124440bd460ba5b87053e8744206bfc600c01400000dff01000100000b00040300010216030102c40b0002c00002bd0002ba308202b63082019ea003020102020900b507e231935d6b3f300d06092a864886f70d010105050030133111300f060355040313086f70656e6c646170301e170d3134303830373232333035385a170d3234303830343232333035385a30133111300f060355040313086f70656e6c64617030820122300d06092a864886f70d01010105000382010f003082010a0282010100bae7e24798efa862ea1659a17ac74864a297d09a
	EAP-Message = 0x249d8e467e1a40a3fc4fdcf36e73ac43cc11e5df4978020ae6af6c12d0a98f7c90d0352eae9c5b9c8364cffe115b833c52bfbcb43c292c303ee0f8cca82a3732ed53bcdba3905a9f030c9bf242e7482f28c0a30e5210afbf064e6129cef1358e30942581621b927da448fcea0fcca181c7ea6ac7385946513bd092e7ccf41df13f7a4f498533947d1f0451659c20977cfddeb5ffadef948b8f876a1bbba0f2a574e05daf8fe696a828973f21674abc246ca73279dcd5fe1720f1140b3f351427fc5be4a4158fb31d2b46643e0bbef9297b892cea88babfcb26e53bcc981bec71b84d0fb21760176f5d12adc90203010001a30d300b30090603551d1304
	EAP-Message = 0x023000300d06092a864886f70d010105050003820101009a35e4dddb99265dfbe96dbd2dd5efcec97ebbb6111d42b313a0d7b6f29a4a4cc378c154afc028a986a118ddf1e611aa3fda9ed59c9f745663fcfd2655891584047b99042c2f7d3757ff92e86d008a55dac7e1e2a8f7e67711fec590812461e9de753eacf30285e44c3c7ecc31671d4ccbfdc6de65536e8b780cbf05ca5e0442748ccc7356f315baac1cc9bb528198bba1526d18213171b26e3676162be28056600762ed21df47ca64f29fb8b9853b8e84731708c7e7c5b0862c3d61aa07b37b89eb915e0fb7f5867a9eb9346574bfc112aa4ea45ae9bae8fdf44b9cedbd3ba5082046a7de23
	EAP-Message = 0xc8fefa2502dad1e8da8bf54443bc2b061a301dd93689ce6867d9160301014b0c000147030017410435796b6c770b407c2ebab35a3d09b54da0cc51fc29e0127a4e712087f927a4ec66a4001d8e03338aca7c1dc10908145a3965b1b289246e63ea9af938293a140201008264e93ba4a0e00fe8a2a603aa05a33cdaf5c24318fc220ad64b624ef88b45fba17d3acc2c10d3e5637b914657ace3c36cab6a5f1c364cb4d73ada622674017ddaecbb02453a2b48ed183114904b75fd62beccbc2e9af4aebffb4914aab0ac1bb3c9e69c5b8556b8bb6d5144fcf81eb91ed845f3280442d546b1b4a5ab6867e9d5f50773d21d4f335f695b5fc386f0d37beefc
	EAP-Message = 0x56c2aca56a2c087629999c71
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xce049ae9cf078f152ab18dd0a9f47460
Wed Aug 13 19:11:30 2014 : Info: Finished request 1.
Wed Aug 13 19:11:30 2014 : Debug: Going to the next request
Wed Aug 13 19:11:30 2014 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host xxx.xxx.xxx.xxx port 32768, id=103, length=227
	User-Name = "joeuser"
	Chargeable-User-Identity = ""
	Location-Capable = Civix-Location
	Calling-Station-Id = "78-31-c1-be-89-a8"
	Called-Station-Id = "d4-a0-2a-15-7f-00:C2_Test"
	NAS-Port = 4
	Cisco-AVPair = "audit-session-id=0a210082000006c453ebb861"
	NAS-IP-Address = 10.33.0.130
	NAS-Identifier = "inWebo"
	Airespace-Wlan-Id = 6
	Service-Type = Framed-User
	Framed-MTU = 1300
	NAS-Port-Type = Wireless-802.11
	EAP-Message = 0x020300061500
	State = 0xce049ae9cf078f152ab18dd0a9f47460
	Message-Authenticator = 0xb8e667ae4d70cf7ba99ff183a7a889cb
Wed Aug 13 19:11:30 2014 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Aug 13 19:11:30 2014 : Info: +- entering group authorize {...}
Wed Aug 13 19:11:30 2014 : Info: ++[preprocess] returns ok
Wed Aug 13 19:11:30 2014 : Info: ++[chap] returns noop
Wed Aug 13 19:11:30 2014 : Info: ++[mschap] returns noop
Wed Aug 13 19:11:30 2014 : Info: ++[digest] returns noop
Wed Aug 13 19:11:30 2014 : Info: [suffix] No '@' in User-Name = "joeuser", looking up realm NULL
Wed Aug 13 19:11:30 2014 : Info: [suffix] No such realm "NULL"
Wed Aug 13 19:11:30 2014 : Info: ++[suffix] returns noop
Wed Aug 13 19:11:30 2014 : Info: [eap] EAP packet type response id 3 length 6
Wed Aug 13 19:11:30 2014 : Info: [eap] Continuing tunnel setup.
Wed Aug 13 19:11:30 2014 : Info: ++[eap] returns ok
Wed Aug 13 19:11:30 2014 : Info: Found Auth-Type = EAP
Wed Aug 13 19:11:30 2014 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Aug 13 19:11:30 2014 : Info: +- entering group authenticate {...}
Wed Aug 13 19:11:30 2014 : Info: [eap] Request found, released from the list
Wed Aug 13 19:11:30 2014 : Info: [eap] EAP/ttls
Wed Aug 13 19:11:30 2014 : Info: [eap] processing type ttls
Wed Aug 13 19:11:30 2014 : Info: [ttls] Authenticate
Wed Aug 13 19:11:30 2014 : Info: [ttls] processing EAP-TLS
Wed Aug 13 19:11:30 2014 : Info: [ttls] Received TLS ACK
Wed Aug 13 19:11:30 2014 : Info: [ttls] ACK handshake fragment handler
Wed Aug 13 19:11:30 2014 : Info: [ttls] eaptls_verify returned 1 
Wed Aug 13 19:11:30 2014 : Info: [ttls] eaptls_process returned 13 
Wed Aug 13 19:11:30 2014 : Info: ++[eap] returns handled
Sending Access-Challenge of id 103 to xxx.xxx.xxx.xxx port 32768
	EAP-Message = 0x01040074158000000460f3411c40ef6cbf1635e4b4c7c71d18b883360ad6c27db542a4ffa0196c0b2ff8daca2101a3b4a35171415bdf6b68817425eb344c2e5e5a6794c0f1002aa59f631cb9c5135d716d9664afa8a76e9f2ee942decefd1b459b2dbb216aa655697391b416030100040e000000
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xce049ae9cc008f152ab18dd0a9f47460
Wed Aug 13 19:11:30 2014 : Info: Finished request 2.
Wed Aug 13 19:11:30 2014 : Debug: Going to the next request
Wed Aug 13 19:11:30 2014 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host xxx.xxx.xxx.xxx port 32768, id=104, length=365
	User-Name = "joeuser"
	Chargeable-User-Identity = ""
	Location-Capable = Civix-Location
	Calling-Station-Id = "78-31-c1-be-89-a8"
	Called-Station-Id = "d4-a0-2a-15-7f-00:C2_Test"
	NAS-Port = 4
	Cisco-AVPair = "audit-session-id=0a210082000006c453ebb861"
	NAS-IP-Address = 10.33.0.130
	NAS-Identifier = "inWebo"
	Airespace-Wlan-Id = 6
	Service-Type = Framed-User
	Framed-MTU = 1300
	NAS-Port-Type = Wireless-802.11
	EAP-Message = 0x020400901580000000861603010046100000424104004576a5ac3ee43c0112ce47d295aa54d21d71076fd64b293d0d59fff21795217e1ac2b3934427d9740a789cd8731e1bd52c246904d4414a1877b375e67df9f31403010001011603010030da43e9a2a8d1bb853ae1740aaf5964dc58b28263a25f1dbc40149b8d0aa0a62b22a690caf5fa2c9663e53591a55e3100
	State = 0xce049ae9cc008f152ab18dd0a9f47460
	Message-Authenticator = 0x9582ab96a0b46bdb12bc99449a415f67
Wed Aug 13 19:11:30 2014 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Aug 13 19:11:30 2014 : Info: +- entering group authorize {...}
Wed Aug 13 19:11:30 2014 : Info: ++[preprocess] returns ok
Wed Aug 13 19:11:30 2014 : Info: ++[chap] returns noop
Wed Aug 13 19:11:30 2014 : Info: ++[mschap] returns noop
Wed Aug 13 19:11:30 2014 : Info: ++[digest] returns noop
Wed Aug 13 19:11:30 2014 : Info: [suffix] No '@' in User-Name = "joeuser", looking up realm NULL
Wed Aug 13 19:11:30 2014 : Info: [suffix] No such realm "NULL"
Wed Aug 13 19:11:30 2014 : Info: ++[suffix] returns noop
Wed Aug 13 19:11:30 2014 : Info: [eap] EAP packet type response id 4 length 144
Wed Aug 13 19:11:30 2014 : Info: [eap] Continuing tunnel setup.
Wed Aug 13 19:11:30 2014 : Info: ++[eap] returns ok
Wed Aug 13 19:11:30 2014 : Info: Found Auth-Type = EAP
Wed Aug 13 19:11:30 2014 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Aug 13 19:11:30 2014 : Info: +- entering group authenticate {...}
Wed Aug 13 19:11:30 2014 : Info: [eap] Request found, released from the list
Wed Aug 13 19:11:30 2014 : Info: [eap] EAP/ttls
Wed Aug 13 19:11:30 2014 : Info: [eap] processing type ttls
Wed Aug 13 19:11:30 2014 : Info: [ttls] Authenticate
Wed Aug 13 19:11:30 2014 : Info: [ttls] processing EAP-TLS
Wed Aug 13 19:11:30 2014 : Debug:   TLS Length 134
Wed Aug 13 19:11:30 2014 : Info: [ttls] Length Included
Wed Aug 13 19:11:30 2014 : Info: [ttls] eaptls_verify returned 11 
Wed Aug 13 19:11:30 2014 : Info: [ttls] <<< TLS 1.0 Handshake [length 0046], ClientKeyExchange  
Wed Aug 13 19:11:30 2014 : Info: [ttls]     TLS_accept: SSLv3 read client key exchange A
Wed Aug 13 19:11:30 2014 : Info: [ttls] <<< TLS 1.0 ChangeCipherSpec [length 0001]  
Wed Aug 13 19:11:30 2014 : Info: [ttls] <<< TLS 1.0 Handshake [length 0010], Finished  
Wed Aug 13 19:11:30 2014 : Info: [ttls]     TLS_accept: SSLv3 read finished A
Wed Aug 13 19:11:30 2014 : Info: [ttls] >>> TLS 1.0 ChangeCipherSpec [length 0001]  
Wed Aug 13 19:11:30 2014 : Info: [ttls]     TLS_accept: SSLv3 write change cipher spec A
Wed Aug 13 19:11:30 2014 : Info: [ttls] >>> TLS 1.0 Handshake [length 0010], Finished  
Wed Aug 13 19:11:30 2014 : Info: [ttls]     TLS_accept: SSLv3 write finished A
Wed Aug 13 19:11:30 2014 : Info: [ttls]     TLS_accept: SSLv3 flush data
Wed Aug 13 19:11:30 2014 : Info: [ttls]     (other): SSL negotiation finished successfully
Wed Aug 13 19:11:30 2014 : Debug: SSL Connection Established 
Wed Aug 13 19:11:30 2014 : Info: [ttls] eaptls_process returned 13 
Wed Aug 13 19:11:30 2014 : Info: ++[eap] returns handled
Sending Access-Challenge of id 104 to xxx.xxx.xxx.xxx port 32768
	EAP-Message = 0x0105004515800000003b1403010001011603010030479426af6e1c12503738a32e262e84a4c666ea99fb6f5a80df674f2146e70be7e6187626844cccb9362ac032ee1b5de3
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xce049ae9cd018f152ab18dd0a9f47460
Wed Aug 13 19:11:30 2014 : Info: Finished request 3.
Wed Aug 13 19:11:30 2014 : Debug: Going to the next request
Wed Aug 13 19:11:30 2014 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host xxx.xxx.xxx.xxx port 32768, id=105, length=300
	User-Name = "joeuser"
	Chargeable-User-Identity = ""
	Location-Capable = Civix-Location
	Calling-Station-Id = "78-31-c1-be-89-a8"
	Called-Station-Id = "d4-a0-2a-15-7f-00:C2_Test"
	NAS-Port = 4
	Cisco-AVPair = "audit-session-id=0a210082000006c453ebb861"
	NAS-IP-Address = 10.33.0.130
	NAS-Identifier = "inWebo"
	Airespace-Wlan-Id = 6
	Service-Type = Framed-User
	Framed-MTU = 1300
	NAS-Port-Type = Wireless-802.11
	EAP-Message = 0x0205004f15800000004517030100407bbbae1e3e6f6eee806cadf4038fc633b025b87de4bfe6c62065214c14dc49fba070a2a5ae82ba25538125ce60ed1e16eebeb7ad9c5eaa990c2be82e7b18f38e
	State = 0xce049ae9cd018f152ab18dd0a9f47460
	Message-Authenticator = 0x641909bf4fd27987f4b839410ca1f707
Wed Aug 13 19:11:30 2014 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Wed Aug 13 19:11:30 2014 : Info: +- entering group authorize {...}
Wed Aug 13 19:11:30 2014 : Info: ++[preprocess] returns ok
Wed Aug 13 19:11:30 2014 : Info: ++[chap] returns noop
Wed Aug 13 19:11:30 2014 : Info: ++[mschap] returns noop
Wed Aug 13 19:11:30 2014 : Info: ++[digest] returns noop
Wed Aug 13 19:11:30 2014 : Info: [suffix] No '@' in User-Name = "joeuser", looking up realm NULL
Wed Aug 13 19:11:30 2014 : Info: [suffix] No such realm "NULL"
Wed Aug 13 19:11:30 2014 : Info: ++[suffix] returns noop
Wed Aug 13 19:11:30 2014 : Info: [eap] EAP packet type response id 5 length 79
Wed Aug 13 19:11:30 2014 : Info: [eap] Continuing tunnel setup.
Wed Aug 13 19:11:30 2014 : Info: ++[eap] returns ok
Wed Aug 13 19:11:30 2014 : Info: Found Auth-Type = EAP
Wed Aug 13 19:11:30 2014 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Wed Aug 13 19:11:30 2014 : Info: +- entering group authenticate {...}
Wed Aug 13 19:11:30 2014 : Info: [eap] Request found, released from the list
Wed Aug 13 19:11:30 2014 : Info: [eap] EAP/ttls
Wed Aug 13 19:11:30 2014 : Info: [eap] processing type ttls
Wed Aug 13 19:11:30 2014 : Info: [ttls] Authenticate
Wed Aug 13 19:11:30 2014 : Info: [ttls] processing EAP-TLS
Wed Aug 13 19:11:30 2014 : Debug:   TLS Length 69
Wed Aug 13 19:11:30 2014 : Info: [ttls] Length Included
Wed Aug 13 19:11:30 2014 : Info: [ttls] eaptls_verify returned 11 
Wed Aug 13 19:11:30 2014 : Info: [ttls] eaptls_process returned 7 
Wed Aug 13 19:11:30 2014 : Info: [ttls] Session established.  Proceeding to decode tunneled attributes.
  TTLS tunnel data in 0000: 00 00 00 01 00 00 00 0f 6a 6f 65 75 73 65 72 00 
  TTLS tunnel data in 0010: 00 00 00 02 00 00 00 18 70 61 73 73 77 6f 72 64 
  TTLS tunnel data in 0020: 00 00 00 00 00 00 00 00 
Wed Aug 13 19:11:30 2014 : Info: [ttls] Got tunneled request
	User-Name = "joeuser"
	User-Password = "password"
	FreeRADIUS-Proxied-To = 127.0.0.1
Wed Aug 13 19:11:30 2014 : Info: [ttls] Sending tunneled request
	User-Name = "joeuser"
	User-Password = "password"
	FreeRADIUS-Proxied-To = 127.0.0.1
	Chargeable-User-Identity = ""
	Location-Capable = Civix-Location
	Calling-Station-Id = "78-31-c1-be-89-a8"
	Called-Station-Id = "d4-a0-2a-15-7f-00:C2_Test"
	NAS-Port = 4
	Cisco-AVPair = "audit-session-id=0a210082000006c453ebb861"
	NAS-IP-Address = 10.33.0.130
	NAS-Identifier = "inWebo"
	Airespace-Wlan-Id = 6
	Service-Type = Framed-User
	Framed-MTU = 1300
	NAS-Port-Type = Wireless-802.11
server inner-tunnel {
Wed Aug 13 19:11:30 2014 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel
Wed Aug 13 19:11:30 2014 : Info: +- entering group authorize {...}
Wed Aug 13 19:11:30 2014 : Info: ++? if (Ldap-Group =~ /ou=corp,ou=Users,dc=team,dc=company,dc=com/  )
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] Entering ldap_groupcmp()
Wed Aug 13 19:11:30 2014 : Info: 	expand: ou=Users,dc=team,dc=company,dc=com -> ou=Users,dc=team,dc=company,dc=com
Wed Aug 13 19:11:30 2014 : Info: 	expand: %{Stripped-User-Name} -> 
Wed Aug 13 19:11:30 2014 : Info: 	... expanding second conditional
Wed Aug 13 19:11:30 2014 : Info: 	expand: %{User-Name} -> joeuser
Wed Aug 13 19:11:30 2014 : Info: 	expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=joeuser)
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] ldap_get_conn: Got Id: 0
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] performing search in ou=Users,dc=team,dc=company,dc=com, with filter (uid=joeuser)
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Wed Aug 13 19:11:30 2014 : Info: 	expand: (|(&(objectClass=GroupOfNames)(member=%{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{Ldap-UserDn}))) -> (|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=)))
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] ldap_get_conn: Got Id: 0
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] performing search in ou=corp,ou=Users,dc=team,dc=company,dc=com, with filter (|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=)))
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] object not found
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Wed Aug 13 19:11:30 2014 : Debug: rlm_ldap::ldap_groupcmp: Group ou=corp,ou=Users,dc=team,dc=company,dc=com not found or user is not a member.
Wed Aug 13 19:11:30 2014 : Info: ? Evaluating (Ldap-Group =~ /ou=corp,ou=Users,dc=team,dc=company,dc=com/) -> FALSE
Wed Aug 13 19:11:30 2014 : Info: ++? if (Ldap-Group =~ /ou=corp,ou=Users,dc=team,dc=company,dc=com/  ) -> FALSE
Wed Aug 13 19:11:30 2014 : Info: ++? if (Ldap-Group =~ /ou=dev,ou=Users,dc=team,dc=company,dc=com/  )
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] Entering ldap_groupcmp()
Wed Aug 13 19:11:30 2014 : Info: 	expand: ou=Users,dc=team,dc=company,dc=com -> ou=Users,dc=team,dc=company,dc=com
Wed Aug 13 19:11:30 2014 : Info: 	expand: (|(&(objectClass=GroupOfNames)(member=%{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{Ldap-UserDn}))) -> (|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=)))
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] ldap_get_conn: Got Id: 0
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] performing search in ou=dev,ou=Users,dc=team,dc=company,dc=com, with filter (|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=)))
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] object not found
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Wed Aug 13 19:11:30 2014 : Debug: rlm_ldap::ldap_groupcmp: Group ou=dev,ou=Users,dc=team,dc=company,dc=com not found or user is not a member.
Wed Aug 13 19:11:30 2014 : Info: ? Evaluating (Ldap-Group =~ /ou=dev,ou=Users,dc=team,dc=company,dc=com/) -> FALSE
Wed Aug 13 19:11:30 2014 : Info: ++? if (Ldap-Group =~ /ou=dev,ou=Users,dc=team,dc=company,dc=com/  ) -> FALSE
Wed Aug 13 19:11:30 2014 : Info: ++[chap] returns noop
Wed Aug 13 19:11:30 2014 : Info: ++[mschap] returns noop
Wed Aug 13 19:11:30 2014 : Info: [suffix] No '@' in User-Name = "joeuser", looking up realm NULL
Wed Aug 13 19:11:30 2014 : Info: [suffix] No such realm "NULL"
Wed Aug 13 19:11:30 2014 : Info: ++[suffix] returns noop
Wed Aug 13 19:11:30 2014 : Info: ++[control] returns noop
Wed Aug 13 19:11:30 2014 : Info: [eap] No EAP-Message, not doing EAP
Wed Aug 13 19:11:30 2014 : Info: ++[eap] returns noop
Wed Aug 13 19:11:30 2014 : Info: ++[files] returns noop
Wed Aug 13 19:11:30 2014 : Info: [ldap] performing user authorization for joeuser
Wed Aug 13 19:11:30 2014 : Info: [ldap] 	expand: %{Stripped-User-Name} -> 
Wed Aug 13 19:11:30 2014 : Info: [ldap] 	... expanding second conditional
Wed Aug 13 19:11:30 2014 : Info: [ldap] 	expand: %{User-Name} -> joeuser
Wed Aug 13 19:11:30 2014 : Info: [ldap] 	expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=joeuser)
Wed Aug 13 19:11:30 2014 : Info: [ldap] 	expand: ou=Users,dc=team,dc=company,dc=com -> ou=Users,dc=team,dc=company,dc=com
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] ldap_get_conn: Got Id: 0
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] performing search in ou=Users,dc=team,dc=company,dc=com, with filter (uid=joeuser)
Wed Aug 13 19:11:30 2014 : Info: [ldap] No default NMAS login sequence
Wed Aug 13 19:11:30 2014 : Info: [ldap] looking for check items in directory...
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] userPassword -> Password-With-Header == "{MD5}X03MO1qnZdYdgyfeuILPmQ=="
Wed Aug 13 19:11:30 2014 : Info: [ldap] looking for reply items in directory...
Wed Aug 13 19:11:30 2014 : Info: [ldap] user joeuser authorized to use remote access
Wed Aug 13 19:11:30 2014 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Wed Aug 13 19:11:30 2014 : Info: ++[ldap] returns ok
Wed Aug 13 19:11:30 2014 : Info: ++[expiration] returns noop
Wed Aug 13 19:11:30 2014 : Info: ++[logintime] returns noop
Wed Aug 13 19:11:30 2014 : Info: ++[pap] returns updated
Wed Aug 13 19:11:30 2014 : Info: Found Auth-Type = PAP
Wed Aug 13 19:11:30 2014 : Info: # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
Wed Aug 13 19:11:30 2014 : Info: +- entering group PAP {...}
Wed Aug 13 19:11:30 2014 : Info: [pap] login attempt with password "password"
Wed Aug 13 19:11:30 2014 : Info: [pap] Using MD5 encryption.
Wed Aug 13 19:11:30 2014 : Info: [pap] Normalizing MD5-Password from base64 encoding
Wed Aug 13 19:11:30 2014 : Info: [pap] User authenticated successfully
Wed Aug 13 19:11:30 2014 : Info: ++[pap] returns ok
Wed Aug 13 19:11:30 2014 : Info: # Executing section post-auth from file /etc/freeradius/sites-enabled/inner-tunnel
Wed Aug 13 19:11:30 2014 : Info: +- entering group post-auth {...}
Wed Aug 13 19:11:30 2014 : Info: 	expand: %{control:Tmp-String-1} -> 
Wed Aug 13 19:11:30 2014 : Info: ++[reply] returns noop
} # server inner-tunnel
Wed Aug 13 19:11:30 2014 : Info: [ttls] Got tunneled reply code 2
	Filter-Id = ""
Wed Aug 13 19:11:30 2014 : Info: [ttls] Got tunneled Access-Accept
Wed Aug 13 19:11:30 2014 : Info: [eap] Freeing handler
Wed Aug 13 19:11:30 2014 : Info: ++[eap] returns ok
Wed Aug 13 19:11:30 2014 : Info: # Executing section post-auth from file /etc/freeradius/sites-enabled/default
Wed Aug 13 19:11:30 2014 : Info: +- entering group post-auth {...}
Wed Aug 13 19:11:30 2014 : Info: ++[exec] returns noop
Sending Access-Accept of id 105 to xxx.xxx.xxx.xxx port 32768
	Filter-Id = ""
	MS-MPPE-Recv-Key = 0x973c07e31d3c62b129b86e8e3c753157d7d3fa68a4a77314fa71358e280a02a8
	MS-MPPE-Send-Key = 0x4a82fcf322b22593fb75a29e51144d16c5698583f60d170a3fe559c800065eec
	EAP-Message = 0x03050004
	Message-Authenticator = 0x00000000000000000000000000000000
	User-Name = "joeuser"
Wed Aug 13 19:11:30 2014 : Info: Finished request 4.
Wed Aug 13 19:11:30 2014 : Debug: Going to the next request
Wed Aug 13 19:11:30 2014 : Debug: Waking up in 4.8 seconds.
Wed Aug 13 19:11:35 2014 : Info: Cleaning up request 0 ID 101 with timestamp +40
Wed Aug 13 19:11:35 2014 : Info: Cleaning up request 1 ID 102 with timestamp +40
Wed Aug 13 19:11:35 2014 : Info: Cleaning up request 2 ID 103 with timestamp +40
Wed Aug 13 19:11:35 2014 : Info: Cleaning up request 3 ID 104 with timestamp +40
Wed Aug 13 19:11:35 2014 : Info: Cleaning up request 4 ID 105 with timestamp +40
Wed Aug 13 19:11:35 2014 : Info: Ready to process requests.



On Aug 13, 2014, at 11:38 AM, Stefan Paetow <Stefan.Paetow at ja.net> wrote:

> Ok… 
> 
> If you are not using "scope='sub'" in the ldap module (a full output from 'freeradius -X' is specifically requested for the reason that we can see the complete config), then yes, the nesting could be the problem. 
> 
> Stefan
> 
> ________________________________________
> From: freeradius-users-bounces+stefan.paetow=ja.net at lists.freeradius.org [freeradius-users-bounces+stefan.paetow=ja.net at lists.freeradius.org] on behalf of Alex Gregory [alex at c2company.com]
> Sent: 13 August 2014 18:38
> To: FreeRadius users mailing list
> Subject: Re: OpenLDAP Group membership to Filter-ID
> 
> Joe User is a part of Corp (which is under Users - could nesting be the problem?):
> 
> root at openldap ~# ldapsearch -x -h localhost -p 389 -b "ou=Users,dc=team,dc=company,dc=com" -s sub "cn=joe user"
> # extended LDIF
> #
> # LDAPv3
> # base <ou=Users,dc=team,dc=company,dc=com> with scope subtree
> # filter: cn=joe user
> # requesting: ALL
> #
> 
> # Joe User, corp, Users, team.company.com
> dn: cn=Joe User,ou=corp,ou=Users,dc=team,dc=company,dc=com
> givenName: Joe
> sn: User
> cn: Joe User
> uid: joeuser
> uidNumber: 1008
> gidNumber: 500
> homeDirectory: /home/users/joeuser
> loginShell: /bin/sh
> objectClass: inetOrgPerson
> objectClass: posixAccount
> objectClass: top
> 
> # search result
> search: 2
> result: 0 Success
> 
> # numResponses: 2
> # numEntries: 1
> 
> Is my entry in the authorize section formatted correctly?
> 
> Thanks,
> 
> Alex
> 
> 
> On Aug 13, 2014, at 2:46 AM, Stefan Paetow <Stefan.Paetow at ja.net> wrote:
> 
>> According to the LDAP search, the user is not part of either the Corp or the Dev OUs.
>> 
>> Which one of the two is 'joeuser' part of?
>> 
>> What happens when you try using ldapsearch to search for 'joeuser' in your AD?
>> 
>> Stefan
>> 
>> 
>> -----Original Message-----
>> From: freeradius-users-bounces+stefan.paetow=ja.net at lists.freeradius.org [mailto:freeradius-users-bounces+stefan.paetow=ja.net at lists.freeradius.org] On Behalf Of Alex Gregory
>> Sent: 13 August 2014 00:32
>> To: FreeRadius users mailing list
>> Subject: OpenLDAP Group membership to Filter-ID
>> 
>> Hello-
>> 
>> I would like to make it so that the users in:
>> 
>> ou=corp,ou=Users,dc=team,dc=company,dc=com
>> 
>> Get mapped a Filter-ID of corp and the users in:
>> 
>> ou=dev,ou=Users,dc=team,dc=company,dc=com
>> 
>> Get mapped a Filter-ID of dev.  I can then apply firewall rules to give them access to certain resources and not others.  This will also make it so that if they access the wrong network they should not have the proper access without the correct group membership.
>> 
>> In inner-tunnel I have:
>> 
>> authorize {
>> if ( Ldap-Group =~ /ou=corp,ou=Users,dc=team,dc=affirm,dc=com/  ) {
>>   update control {
>>   Tmp-String-1 := "corp"
>>       }
>>       }
>> if ( Ldap-Group =~ /ou=dev,ou=Users,dc=team,dc=affirm,dc=com/  ) {
>>   update control {
>>   Tmp-String-1 := "dev"
>>       }
>>       }
>> 
>> post-auth {
>> update reply {
>>       Filter-Id := "%{control:Tmp-String-1}"
>> }
>> 
>> I can see in the log that its not matching which means I am not matching correctly.  It ends up passing the Filter-ID which is blank.  So I know the post auth section is working correctly.
>> 
>> Here is the relevant log info:
>> 
>> Tue Aug 12 22:50:47 2014 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel
>> Tue Aug 12 22:50:47 2014 : Info: +- entering group authorize {...}
>> Tue Aug 12 22:50:47 2014 : Info: ++? if (Ldap-Group =~ /ou=corp,ou=Users,dc=team,dc=company,dc=com/  )
>> Tue Aug 12 22:50:47 2014 : Debug:   [ldap] Entering ldap_groupcmp()
>> Tue Aug 12 22:50:47 2014 : Info:      expand: ou=Users,dc=team,dc=company,dc=com -> ou=Users,dc=team,dc=company,dc=com
>> Tue Aug 12 22:50:47 2014 : Info:      expand: %{Stripped-User-Name} ->
>> Tue Aug 12 22:50:47 2014 : Info:      ... expanding second conditional
>> Tue Aug 12 22:50:47 2014 : Info:      expand: %{User-Name} -> joeuser
>> Tue Aug 12 22:50:47 2014 : Info:      expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=joeuser)
>> Tue Aug 12 22:50:47 2014 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
>> Tue Aug 12 22:50:47 2014 : Debug:   [ldap] ldap_get_conn: Got Id: 0
>> Tue Aug 12 22:50:47 2014 : Debug:   [ldap] performing search in ou=Users,dc=team,dc=company,dc=com, with filter (uid=joeuser)
>> Tue Aug 12 22:50:47 2014 : Debug:   [ldap] ldap_release_conn: Release Id: 0
>> Tue Aug 12 22:50:47 2014 : Info:      expand: (|(&(objectClass=GroupOfNames)(member=%{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{Ldap-UserDn}))) -> (|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=)))
>> Tue Aug 12 22:50:47 2014 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
>> Tue Aug 12 22:50:47 2014 : Debug:   [ldap] ldap_get_conn: Got Id: 0
>> Tue Aug 12 22:50:47 2014 : Debug:   [ldap] performing search in ou=corp,ou=Users,dc=team,dc=company,dc=com, with filter (|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=)))
>> Tue Aug 12 22:50:47 2014 : Debug:   [ldap] object not found
>> Tue Aug 12 22:50:47 2014 : Debug:   [ldap] ldap_release_conn: Release Id: 0
>> Tue Aug 12 22:50:47 2014 : Debug: rlm_ldap::ldap_groupcmp: Group ou=corp,ou=Users,dc=team,dc=company,dc=com not found or user is not a member.
>> Tue Aug 12 22:50:47 2014 : Info: ? Evaluating (Ldap-Group =~ /ou=corp,ou=Users,dc=team,dc=company,dc=com/) -> FALSE
>> Tue Aug 12 22:50:47 2014 : Info: ++? if (Ldap-Group =~ /ou=corp,ou=Users,dc=team,dc=company,dc=com/  ) -> FALSE
>> Tue Aug 12 22:50:47 2014 : Info: ++? if (Ldap-Group =~ /ou=dev,ou=Users,dc=team,dc=company,dc=com/  )
>> Tue Aug 12 22:50:47 2014 : Debug:   [ldap] Entering ldap_groupcmp()
>> Tue Aug 12 22:50:47 2014 : Info:      expand: ou=Users,dc=team,dc=company,dc=com -> ou=Users,dc=team,dc=company,dc=com
>> Tue Aug 12 22:50:47 2014 : Info:      expand: (|(&(objectClass=GroupOfNames)(member=%{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{Ldap-UserDn}))) -> (|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=)))
>> Tue Aug 12 22:50:47 2014 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
>> Tue Aug 12 22:50:47 2014 : Debug:   [ldap] ldap_get_conn: Got Id: 0
>> Tue Aug 12 22:50:47 2014 : Debug:   [ldap] performing search in ou=dev,ou=Users,dc=team,dc=company,dc=com, with filter (|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=)))
>> Tue Aug 12 22:50:47 2014 : Debug:   [ldap] object not found
>> Tue Aug 12 22:50:47 2014 : Debug:   [ldap] ldap_release_conn: Release Id: 0
>> Tue Aug 12 22:50:47 2014 : Debug: rlm_ldap::ldap_groupcmp: Group ou=dev,ou=Users,dc=team,dc=company,dc=com not found or user is not a member.
>> Tue Aug 12 22:50:47 2014 : Info: ? Evaluating (Ldap-Group =~ /ou=dev,ou=Users,dc=team,dc=company,dc=com/) -> FALSE
>> Tue Aug 12 22:50:47 2014 : Info: ++? if (Ldap-Group =~ /ou=dev,ou=Users,dc=team,dc=company,dc=com/  ) -> FALSE
>> Tue Aug 12 22:50:47 2014 : Info: ++[chap] returns noop
>> Tue Aug 12 22:50:47 2014 : Info: ++[mschap] returns noop
>> Tue Aug 12 22:50:47 2014 : Info: [suffix] No '@' in User-Name = "joeuser", looking up realm NULL
>> Tue Aug 12 22:50:47 2014 : Info: [suffix] No such realm "NULL"
>> Tue Aug 12 22:50:47 2014 : Info: ++[suffix] returns noop
>> Tue Aug 12 22:50:47 2014 : Info: ++[control] returns noop
>> Tue Aug 12 22:50:47 2014 : Info: [eap] No EAP-Message, not doing EAP
>> Tue Aug 12 22:50:47 2014 : Info: ++[eap] returns noop
>> Tue Aug 12 22:50:47 2014 : Info: ++[files] returns noop
>> Tue Aug 12 22:50:47 2014 : Info: [ldap] performing user authorization for joeuser
>> Tue Aug 12 22:50:47 2014 : Info: [ldap]       expand: %{Stripped-User-Name} ->
>> Tue Aug 12 22:50:47 2014 : Info: [ldap]       ... expanding second conditional
>> Tue Aug 12 22:50:47 2014 : Info: [ldap]       expand: %{User-Name} -> joeuser
>> Tue Aug 12 22:50:47 2014 : Info: [ldap]       expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=joeuser)
>> Tue Aug 12 22:50:47 2014 : Info: [ldap]       expand: ou=Users,dc=team,dc=company,dc=com -> ou=Users,dc=team,dc=company,dc=com
>> Tue Aug 12 22:50:47 2014 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
>> Tue Aug 12 22:50:47 2014 : Debug:   [ldap] ldap_get_conn: Got Id: 0
>> Tue Aug 12 22:50:47 2014 : Debug:   [ldap] performing search in ou=Users,dc=team,dc=company,dc=com, with filter (uid=joeuser)
>> Tue Aug 12 22:50:47 2014 : Info: [ldap] No default NMAS login sequence
>> Tue Aug 12 22:50:47 2014 : Info: [ldap] looking for check items in directory...
>> Tue Aug 12 22:50:47 2014 : Debug:   [ldap] userPassword -> Password-With-Header == "{MD5}hashreplaced"
>> Tue Aug 12 22:50:47 2014 : Info: [ldap] looking for reply items in directory...
>> Tue Aug 12 22:50:47 2014 : Info: [ldap] user joeuser authorized to use remote access
>> Tue Aug 12 22:50:47 2014 : Debug:   [ldap] ldap_release_conn: Release Id: 0
>> Tue Aug 12 22:50:47 2014 : Info: ++[ldap] returns ok
>> Tue Aug 12 22:50:47 2014 : Info: ++[expiration] returns noop
>> Tue Aug 12 22:50:47 2014 : Info: ++[logintime] returns noop
>> Tue Aug 12 22:50:47 2014 : Info: ++[pap] returns updated
>> Tue Aug 12 22:50:47 2014 : Info: Found Auth-Type = PAP
>> Tue Aug 12 22:50:47 2014 : Info: # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
>> Tue Aug 12 22:50:47 2014 : Info: +- entering group PAP {...}
>> Tue Aug 12 22:50:47 2014 : Info: [pap] login attempt with password "password"
>> Tue Aug 12 22:50:47 2014 : Info: [pap] Using MD5 encryption.
>> Tue Aug 12 22:50:47 2014 : Info: [pap] Normalizing MD5-Password from base64 encoding
>> Tue Aug 12 22:50:47 2014 : Info: [pap] User authenticated successfully
>> Tue Aug 12 22:50:47 2014 : Info: ++[pap] returns ok
>> Tue Aug 12 22:50:47 2014 : Info: # Executing section post-auth from file /etc/freeradius/sites-enabled/inner-tunnel
>> Tue Aug 12 22:50:47 2014 : Info: +- entering group post-auth {...}
>> Tue Aug 12 22:50:47 2014 : Info:      expand: %{control:Tmp-String-1} ->
>> Tue Aug 12 22:50:47 2014 : Info: ++[reply] returns noop
>> } # server inner-tunnel
>> Tue Aug 12 22:50:47 2014 : Info: [ttls] Got tunneled reply code 2
>>      Filter-Id = ""
>> Tue Aug 12 22:50:47 2014 : Info: [ttls] Got tunneled Access-Accept
>> Tue Aug 12 22:50:47 2014 : Info: [eap] Freeing handler
>> Tue Aug 12 22:50:47 2014 : Info: ++[eap] returns ok
>> Tue Aug 12 22:50:47 2014 : Info: # Executing section post-auth from file /etc/freeradius/sites-enabled/default
>> Tue Aug 12 22:50:47 2014 : Info: +- entering group post-auth {...}
>> Tue Aug 12 22:50:47 2014 : Info: ++[exec] returns noop
>> Sending Access-Accept of id 16 to xxx.xxx.xxx.xxx port 32768
>>      Filter-Id = ""
>>      MS-MPPE-Recv-Key = 0x85725d86e7ab1448510e48ba9b900cd3cbf3d7436f36f9b391dab4d35b3d69b1
>>      MS-MPPE-Send-Key = 0x191e9e59df4f7108ac1542e48434330db030957911f7a3fb75ae40456057bf1f
>>      EAP-Message = 0x03050004
>>      Message-Authenticator = 0x00000000000000000000000000000000
>>      User-Name = "joeuser"
>> Tue Aug 12 22:50:47 2014 : Info: Finished request 9.
>> 
>> Thank you for the help.  I appreciate it.  BTW if this does't make sense I can provide more details as to what I am trying to do.  I figured I would spare that unless needed.
>> 
>> Thanks,
>> 
>> Alex
>> 
>> -
>> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
>> 
>> Janet(UK) is a trading name of Jisc Collections and Janet Limited, a
>> not-for-profit company which is registered in England under No. 2881024
>> and whose Registered Office is at Lumen House, Library Avenue,
>> Harwell Oxford, Didcot, Oxfordshire. OX11 0SG. VAT No. 614944238
>> 
>> -
>> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
> 
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
> 
> Janet(UK) is a trading name of Jisc Collections and Janet Limited, a 
> not-for-profit company which is registered in England under No. 2881024 
> and whose Registered Office is at Lumen House, Library Avenue,
> Harwell Oxford, Didcot, Oxfordshire. OX11 0SG. VAT No. 614944238
> 
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

More information about the Freeradius-Users mailing list