groupcmp fails during tunneled request

[Matthieu Lazaro]

Ivan Kalik a écrit :
>> I'm having an issue with the group check (ldap_groupcmp).
>>
>> Everything is fine until the request is tunnelled, and I can't find out
>> why my user is rejected there....
>> It seems that he ends in this section during this phase:
>> DEFAULT Ldap-Group == BANNED , Auth-Type := Reject
>>         Reply-Message = "Account disabled.  Please call the helpdesk."
>>
>>     
>
> No. That didn't match.
>
>   
>> Tue Apr 28 11:42:35 2009 : Debug: rlm_ldap::groupcmp: Group BANNED not
>> found or user not a member
>>     
>
> See.
>
>   
>> Tue Apr 28 11:42:35 2009 : Debug: rlm_ldap: ldap_release_conn: Release Id:
>> 0
>> Tue Apr 28 11:42:35 2009 : Info: [files] users: Matched entry DEFAULT at
>> line 15
>>     
>
> But something else did. What is on line 15 in users file?
>   
DEFAULT Auth-Type := Reject
 Reply-Message = "Please call the helpdesk."
>   
>> Tell me if you need more debug output...
>>     
>
> We do. This doesn't show anything. Post the debug with whole inner tunnel
> exchange.
>
>   
>> It was working perfectly before I introduced the group check using the
>> huntgroups.
>>
>>     
>
> Huntgroups?
>
>
>   
Content of my huntgroup file.
WIFI            NAS-Identifier == "accessPoint-Manager"
                Ldap-Group  == wireless,
                Ldap-Group  == wireless2,
REM             NAS-IP-Address == 10.44.12.2
                Ldap-Group == REM

Content of my user file:
DEFAULT Framed-Protocol == PPP
        Framed-Protocol = PPP,
        Framed-Compression = Van-Jacobson-TCP-IP
DEFAULT Hint == "CSLIP"
        Framed-Protocol = SLIP,
        Framed-Compression = Van-Jacobson-TCP-IP
DEFAULT Hint == "SLIP"
        Framed-Protocol = SLIP
DEFAULT Ldap-Group == BANNED , Auth-Type := Reject
        Reply-Message = "Account disabled.  Please call the helpdesk."
DEFAULT Huntgroup-Name == WIFI, Auth-Type = eap
        Fall-Through = no,
DEFAULT Huntgroup-Name == REM, Auth-Type = ldap
        Fall-Through = no,
DEFAULT Auth-Type := Reject
        Reply-Message = "Please call the helpdesk."

Invalid operator for item NAS-Identifier: reverting to '=='
==> I have corrected this now

Full Debug:

rad_recv: Access-Request packet from host 10.0.0.2 port 32769, id=13,
length=219
        User-Name = "alicebob"
        Calling-Station-Id = "00-13-02-25-CF-40"
        Called-Station-Id = "00-1E-13-1C-87-00:WiFi-TEST"
        NAS-Port = 1
        NAS-IP-Address = 192.168.225.8
        NAS-Identifier = "accessPoint-Manager"
        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 = "502"
        EAP-Message =
0x0207002219001703010017d6d3387b7eed6b4b21f289092b99288904cc4970a60bfc
        State = 0x6416d65c6011cf1de638dad1d46f61b2
        Message-Authenticator = 0x0b5692123f68b20d631e3b7b45b39069
+- entering group authorize {...}
Invalid operator for item NAS-Identifier: reverting to '=='
rlm_ldap: Entering ldap_groupcmp()
[preprocess]    expand: dc=companyname,dc=com -> dc=companyname,dc=com
[preprocess] WARNING: Deprecated conditional expansion ":-".  See "man
unlang" for details
[preprocess]    expand: (uid=%{Stripped-User-Name:-%{User-Name}}) ->
(uid=alicebob)
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in dc=companyname,dc=com, with filter
(uid=alicebob)
rlm_ldap: ldap_release_conn: Release Id: 0
[preprocess]    expand:
(|(&(objectClass=GroupOfNames)(member=%{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{Ldap-UserDn})))
->
(|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=)))
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in dc=companyname,dc=com, with filter
(&(radiusGroupName=wireless)(|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=))))
rlm_ldap: object not found or got ambiguous search result
rlm_ldap: ldap_release_conn: Release Id: 0
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in
uid=alicebob,ou=companystaff,dc=companyname,dc=com, with filter
(objectclass=*)
rlm_ldap::ldap_groupcmp: User found in group wireless
rlm_ldap: ldap_release_conn: Release Id: 0
++[preprocess] returns ok
[auth_log]      expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/freeradius/radacct/10.0.0.2/auth-detail-20090428
[auth_log]
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/10.0.0.2/auth-detail-20090428
[auth_log]      expand: %t -> Tue Apr 28 16:10:52 2009
++[auth_log] returns ok
++[mschap] returns noop
[suffix] No '@' in User-Name = "alicebob", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 7 length 34
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- 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] Identity - alicebob
[peap] Got tunnled request
        EAP-Message = 0x0207000b01676269676f74
server (null) {
  PEAP: Got tunneled identity of alicebob
  PEAP: Setting default EAP type for tunneled EAP session.
  PEAP: Setting User-Name to alicebob
Sending tunneled request
        EAP-Message = 0x0207000b01676269676f74
        FreeRADIUS-Proxied-To = 127.0.0.1
        User-Name = "alicebob"
        Calling-Station-Id = "00-13-02-25-CF-40"
        Called-Station-Id = "00-1E-13-1C-87-00:WiFi-TEST"
        NAS-Port = 1
        NAS-IP-Address = 192.168.225.8
        NAS-Identifier = "accessPoint-Manager"
        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 = "502"
server inner-tunnel {
+- entering group authorize {...}
++[mschap] returns noop
[suffix] No '@' in User-Name = "alicebob", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 7 length 11
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
rlm_ldap: Entering ldap_groupcmp()
[files]         expand: dc=companyname,dc=com -> dc=companyname,dc=com
[files] WARNING: Deprecated conditional expansion ":-".  See "man
unlang" for details
[files]         expand: (uid=%{Stripped-User-Name:-%{User-Name}}) ->
(uid=alicebob)
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in dc=companyname,dc=com, with filter
(uid=alicebob)
rlm_ldap: ldap_release_conn: Release Id: 0
[files]         expand:
(|(&(objectClass=GroupOfNames)(member=%{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{Ldap-UserDn})))
->
(|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=)))
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in dc=companyname,dc=com, with filter
(&(radiusGroupName=BANNED)(|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=))))
rlm_ldap: object not found or got ambiguous search result
rlm_ldap: ldap_release_conn: Release Id: 0
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in
uid=alicebob,ou=companystaff,dc=companyname,dc=com, with filter
(objectclass=*)
rlm_ldap::groupcmp: Group BANNED not found or user not a member
rlm_ldap: ldap_release_conn: Release Id: 0
[files] users: Matched entry DEFAULT at line 15
++[files] returns ok
[ldap] performing user authorization for alicebob
[ldap] WARNING: Deprecated conditional expansion ":-".  See "man unlang"
for details
[ldap]  expand: (uid=%{Stripped-User-Name:-%{User-Name}}) -> (uid=alicebob)
[ldap]  expand: dc=companyname,dc=com -> dc=companyname,dc=com
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in dc=companyname,dc=com, with filter
(uid=alicebob)
[ldap] Added User-Password =
$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$ in check items
[ldap] No default NMAS login sequence
[ldap] looking for check items in directory...
rlm_ldap: userPassword -> User-Password ==
$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$
rlm_ldap: sambaNtPassword -> NT-Password ==
$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$
rlm_ldap: sambaLmPassword -> LM-Password ==
$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$
rlm_ldap: ntPassword -> NT-Password ==
$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$
rlm_ldap: lmPassword -> LM-Password ==
$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$
[ldap] looking for reply items in directory...
[ldap] user alicebob authorized to use remote access
rlm_ldap: ldap_release_conn: Release Id: 0
++[ldap] returns ok
++[expiration] returns noop
++[logintime] returns noop
Found Auth-Type = Reject
Auth-Type = Reject, rejecting user
Failed to authenticate the user.
Login incorrect: [alicebob] (from client CISCO-accessPoint-Manager-2
port 1 cli 00-13-02-25-CF-40 via TLS tunnel)
} # server inner-tunnel
[peap] Got tunneled reply code 3
        Reply-Message = "Please call the helpdesk %U."
[peap] Got tunneled reply RADIUS code 3
        Reply-Message = "Please call the helpdesk %U."
[peap] Tunneled authentication was rejected.
[peap] FAILURE
++[eap] returns handled
Sending Access-Challenge of id 13 to 10.0.0.2 port 32769
        EAP-Message =
0x010800261900170301001b5b6043fec0507512af4f169b40a858699db4e6504960eb527935ac
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x6416d65c611ecf1de638dad1d46f61b2
Finished request 47.
Going to the next request
Waking up in 4.6 seconds.
rad_recv: Access-Request packet from host 10.0.0.2 port 32769, id=14,
length=223
        User-Name = "alicebob"
        Calling-Station-Id = "00-13-02-25-CF-40"
        Called-Station-Id = "00-1E-13-1C-87-00:WiFi-TEST"
        NAS-Port = 1
        NAS-IP-Address = 192.168.225.8
        NAS-Identifier = "accessPoint-Manager"
        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 = "502"
        EAP-Message =
0x020800261900170301001b662cc66e46b4785af06a9b655bca5a955b8506e46291a28450960a
        State = 0x6416d65c611ecf1de638dad1d46f61b2
        Message-Authenticator = 0xb88eef22e530f6c65ab2fe53a9789189
+- entering group authorize {...}
Invalid operator for item NAS-Identifier: reverting to '=='
rlm_ldap: Entering ldap_groupcmp()
[preprocess]    expand: dc=companyname,dc=com -> dc=companyname,dc=com
[preprocess] WARNING: Deprecated conditional expansion ":-".  See "man
unlang" for details
[preprocess]    expand: (uid=%{Stripped-User-Name:-%{User-Name}}) ->
(uid=alicebob)
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in dc=companyname,dc=com, with filter
(uid=alicebob)
rlm_ldap: ldap_release_conn: Release Id: 0
[preprocess]    expand:
(|(&(objectClass=GroupOfNames)(member=%{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{Ldap-UserDn})))
->
(|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=)))
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in dc=companyname,dc=com, with filter
(&(radiusGroupName=wireless)(|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=))))
rlm_ldap: object not found or got ambiguous search result
rlm_ldap: ldap_release_conn: Release Id: 0
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in
uid=alicebob,ou=companystaff,dc=companyname,dc=com, with filter
(objectclass=*)
rlm_ldap::ldap_groupcmp: User found in group wireless
rlm_ldap: ldap_release_conn: Release Id: 0
++[preprocess] returns ok
[auth_log]      expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/freeradius/radacct/10.0.0.2/auth-detail-20090428
[auth_log]
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/10.0.0.2/auth-detail-20090428
[auth_log]      expand: %t -> Tue Apr 28 16:10:52 2009
++[auth_log] returns ok
++[mschap] returns noop
[suffix] No '@' in User-Name = "alicebob", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 8 length 38
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- 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] Received EAP-TLV response.
[peap]  Had sent TLV failure.  User was rejected earlier in this session.
[eap] Handler failed in EAP/peap
[eap] Failed in EAP select
++[eap] returns invalid
Failed to authenticate the user.
Login incorrect: [alicebob] (from client CISCO-accessPoint-Manager-2
port 1 cli 00-13-02-25-CF-40)
Using Post-Auth-Type Reject
+- entering group REJECT {...}
[attr_filter.access_reject]     expand: %{User-Name} -> alicebob
 attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] returns updated
Delaying reject of request 48 for 1 seconds
Going to the next request
Waking up in 0.9 seconds.
Sending delayed reject for request 48
Sending Access-Reject of id 14 to 10.0.0.2 port 32769
        EAP-Message = 0x04080004
        Message-Authenticator = 0x00000000000000000000000000000000
Waking up in 3.6 seconds.