LDAP Query: Not Found

Scott Pickles scottpickles at yahoo.com
Tue Jul 28 18:25:04 CEST 2015


How can I further troubleshoot what might be the cause for my query against LDAP to return no results?  I have verified the following from debugging and testing:
[ ... SNIP ... ]
# Loaded module rlm_ldap
  # Instantiating module "ldap" from file /etc/raddb/mods-enabled/ldap
  ldap {
        server = "dc01.myDomain.com"
        port = 3268
        password = <<< secret >>>
        identity = "CN=Free RADIUS,CN=Users,DC=myDomain,DC=com"
   user {
        filter = "(uid=%{%{Stripped-User-Name}:-%{User-Name}})"
        scope = "sub"
        base_dn = "DC=myDomain,DC=com"
        access_positive = yes
   }
   group {
        filter = "(objectClass=posixGroup)"
        scope = "sub"
        base_dn = "DC=myDomain,DC=com"
        name_attribute = "cn"
        membership_attribute = "memberOf"
        membership_filter = "(|(member=%{control:Ldap-UserDn})(memberUid=%{%{Stripped-User-Name}:-%{User-Name}}))"
        cacheable_name = no
        cacheable_dn = no
   }
   client {
        filter = "(objectClass=frClient)"
        scope = "sub"
        base_dn = "DC=myDomain,DC=com"
    attribute {
        identifier = "radiusClientIdentifier"
        shortname = "cn"
        secret = "radiusClientSecret"
    }
   }
   profile {
        filter = "(&)"
   }
   options {
        ldap_debug = 40
        chase_referrals = yes
        rebind = yes
        net_timeout = 1
        res_timeout = 20
        srv_timelimit = 20
        idle = 60
        probes = 3
        interval = 3
   }
   tls {
        start_tls = no
   }
  }
rlm_ldap: Falling back to build time libldap version info.  Query for LDAP_OPT_API_INFO returned: -1
rlm_ldap: libldap vendor: OpenLDAP version: 20439
   accounting {
        reference = "%{tolower:type.%{Acct-Status-Type}}"
   }
   post-auth {
        reference = "."
   }
rlm_ldap (ldap): Initialising connection pool
   pool {
        start = 5
        min = 4
        max = 32
        spare = 3
        uses = 0
        lifetime = 0
        cleanup_interval = 30
        idle_timeout = 60
        retry_delay = 1
        spread = no
   }
rlm_ldap (ldap): Opening additional connection (0)
rlm_ldap (ldap): Connecting to dc01.myDomain.com:3268
rlm_ldap (ldap): Waiting for bind result...
>>rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): Opening additional connection (1)
rlm_ldap (ldap): Connecting to dc01.myDomain.com:3268
rlm_ldap (ldap): Waiting for bind result...
>>rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): Opening additional connection (2)
rlm_ldap (ldap): Connecting to dc01.myDomain.com:3268
rlm_ldap (ldap): Waiting for bind result...
>>rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): Opening additional connection (3)
rlm_ldap (ldap): Connecting to dc01.myDomain.com:3268
rlm_ldap (ldap): Waiting for bind result...
>>rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): Opening additional connection (4)
rlm_ldap (ldap): Connecting to dc01.myDomain.com:3268
rlm_ldap (ldap): Waiting for bind result...
>>rlm_ldap (ldap): Bind successful
 } # modules
[ ... SNIP ... ]
So it appears to be binding to LDAP ok.  I am binding on port 3268 to reference the global catalog and search sub-domains.
[ ... SNIP ... ]
Ready to process requests
Received Access-Request Id 32 from 172.18.1.2:1025 to 172.18.2.100:1812 length 66
        User-Name = 'spickles'
        User-Password = '****'
        NAS-IP-Address = 172.18.1.2
        NAS-Port = 32
        NAS-Port-Type = Virtual
(1) Received Access-Request packet from host 172.18.1.2 port 1025, id=32, length=66
(1)     User-Name = 'spickles'
(1)     User-Password = '****'
(1)     NAS-IP-Address = 172.18.1.2
(1)     NAS-Port = 32
(1)     NAS-Port-Type = Virtual
(1) # Executing section authorize from file /etc/raddb/sites-enabled/default
(1)   authorize {
(1)   [preprocess] = ok
(1)   rewrite_calling_station_id rewrite_calling_station_id {
(1)     if (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i) 
(1) ERROR: Failed retrieving values required to evaluate condition
(1)    else else {
(1)     [noop] = noop
(1)    } # else else = noop
(1)   } # rewrite_calling_station_id rewrite_calling_station_id = noop
(1)  eap : No EAP-Message, not doing EAP
(1)   [eap] = noop
(1)   [files] = noop
rlm_ldap (ldap): Reserved connection (4)
(1)  ldap : EXPAND (uid=%{%{Stripped-User-Name}:-%{User-Name}})
(1)  ldap :    --> (uid=spickles)
(1)  ldap : EXPAND DC=myDomain,DC=COM
(1)  ldap :    --> DC=myDomain,DC=COM
(1)  ldap : Performing search in 'DC=myDomain,DC=COM' with filter '(uid=spickles)', scope 'sub'
(1)  ldap : Waiting for search result...
>> (1)  ldap : Search returned no results
rlm_ldap (ldap): Released connection (4)
rlm_ldap (ldap): 0 of 1 connections in use.  Need more spares
rlm_ldap (ldap): Opening additional connection (5)
rlm_ldap (ldap): Connecting to rochdc01.myDomain.com:3268
rlm_ldap (ldap): Waiting for bind result...
rlm_ldap (ldap): Bind successful
>>(1)   [ldap] = notfound
(1)  } #  authorize = ok
(1) ERROR: No Auth-Type found: rejecting the user via Post-Auth-Type = Reject
(1) Failed to authenticate the user
(1) Login incorrect (Failed retrieving values required to evaluate condition): [spickles/****] (from client <<client_short_name>> port 32)
(1) Using Post-Auth-Type Reject
(1) # Executing group from file /etc/raddb/sites-enabled/default
(1)  Post-Auth-Type REJECT {
(1)  attr_filter.access_reject : EXPAND %{User-Name}
(1)  attr_filter.access_reject :    --> spickles
(1)  attr_filter.access_reject : Matched entry DEFAULT at line 11
(1)   [attr_filter.access_reject] = updated
(1)  eap : Request didn't contain an EAP-Message, not inserting EAP-Failure
(1)   [eap] = noop
(1)   remove_reply_message_if_eap remove_reply_message_if_eap {
(1)     if (&reply:EAP-Message && &reply:Reply-Message) 
(1)     if (&reply:EAP-Message && &reply:Reply-Message)  -> FALSE
(1)    else else {
(1)     [noop] = noop
(1)    } # else else = noop
(1)   } # remove_reply_message_if_eap remove_reply_message_if_eap = noop
(1)  } # Post-Auth-Type REJECT = updated
(1) Delaying response for 1 seconds
Waking up in 0.6 seconds.
Waking up in 0.3 seconds.
(1) Sending delayed response
(1) Sending Access-Reject packet to host 172.18.1.2 port 1025, id=32, length=0
Sending Access-Reject Id 32 from 172.18.2.100:1812 to 172.18.1.2:1025
Waking up in 3.9 seconds.
(1) Cleaning up request packet ID 32 with timestamp +189
Ready to process requests
[ ... SNIP ... ]
Not sure why it didn't find my user.  My user is in the standard container (i.e. CN=Users) so I would think that sub would search there and find it?  Perhaps that is my problem and either my base is incorrect or my scope is not correct?  However, this seems to be correct according to the wiki (modules/Rlm_ldap).  A final test with 'ldapsearch' yields similar results with no further information:
[ ... SNIP ... ]
[]# ldapsearch -x -b "DC=myDomain,DC=com" -D "CN=Free RADIUS,CN=Users,DC=myDomain,DC=com" -h myDomain.com -w "<<password>>" "(&(CN=VPN-Internal,OU=VPN,OU=Groups,DC=myDomain,DC=com))"
# extended LDIF
#
# LDAPv3
# base <DC=myDomain,DC=com> with scope subtree
# filter: (&(CN=VPN-Internal,OU=VPN,OU=Groups,DC=myDomain,DC=com))
# requesting: ALL
#

# search reference
ref: ldap://DomainDnsZones.myDomain.com/DC=DomainDnsZones,DC=myDomain,
 DC=com

# search result
search: 2
>>result: 0 Success

# numResponses: 2
# numReferences: 1
[ ... SNIP ... ]
The only other thing I can think of is that the user that I'm binding to AD with to read information doesn't have the right permissions?  But I would also think that the bind wouldn't be successful in the first place for the module if that were the case?  I don't know what direction to take this in next to get more information.  I would check the logs but since I'm running the server in debug mode the logs would just be duplicates of what I already have, correct?




More information about the Freeradius-Users mailing list