Problem with LDAP against Active Directory

[domjullier at rhone.ch]

Hi folks,
I want authenticate users from a WLAN with freeradius. The
Users are stored in the Active Directory of a Windows 2003
Server.

With some Tutorials from the Internet I have configured
freeradius to make that.

Unfortunately the Authentication function not succesfully.

Thats the output from FreeRadius during the Authentication:

rad_recv: Access-Request packet from host
192.168.210.15:4596, id=13, length=100
        NAS-Port-Type = Ethernet
        Service-Type = Login-User
        User-Name = "ldap"
        User-Password = "ldap"
        Called-Station-Id = "00:01:02:ad:64:f7"
        Calling-Station-Id = "00:c0:49:54:b5:43"
        NAS-Port = 1
Mon Apr  3 11:12:08 2006 : Debug:   Processing the
authorize section of radiusd.conf
Mon Apr  3 11:12:08 2006 : Debug: modcall: entering group
authorize for request 2
Mon Apr  3 11:12:08 2006 : Debug:   modsingle[authorize]:
calling preprocess (rlm_preprocess) for request 2
Mon Apr  3 11:12:08 2006 : Debug:   modsingle[authorize]:
returned from preprocess (rlm_preprocess) for request 2
Mon Apr  3 11:12:08 2006 : Debug:   modcall[authorize]:
module "preprocess" returns ok for request 2
Mon Apr  3 11:12:08 2006 : Debug:   modsingle[authorize]:
calling chap (rlm_chap) for request 2
Mon Apr  3 11:12:08 2006 : Debug:   modsingle[authorize]:
returned from chap (rlm_chap) for request 2
Mon Apr  3 11:12:08 2006 : Debug:   modcall[authorize]:
module "chap" returns noop for request 2
Mon Apr  3 11:12:08 2006 : Debug:   modsingle[authorize]:
calling mschap (rlm_mschap) for request 2
Mon Apr  3 11:12:08 2006 : Debug:   modsingle[authorize]:
returned from mschap (rlm_mschap) for request 2
Mon Apr  3 11:12:08 2006 : Debug:   modcall[authorize]:
module "mschap" returns noop for request 2
Mon Apr  3 11:12:08 2006 : Debug:   modsingle[authorize]:
calling suffix (rlm_realm) for request 2
Mon Apr  3 11:12:08 2006 : Debug:     rlm_realm: No '@' in
User-Name = "ldap", looking up realm NULL
Mon Apr  3 11:12:08 2006 : Debug:     rlm_realm: No such
realm "NULL"
Mon Apr  3 11:12:08 2006 : Debug:   modsingle[authorize]:
returned from suffix (rlm_realm) for request 2
Mon Apr  3 11:12:08 2006 : Debug:   modcall[authorize]:
module "suffix" returns noop for request 2
Mon Apr  3 11:12:08 2006 : Debug:   modsingle[authorize]:
calling eap (rlm_eap) for request 2
Mon Apr  3 11:12:08 2006 : Debug:   rlm_eap: No
EAP-Message, not doing EAP
Mon Apr  3 11:12:08 2006 : Debug:   modsingle[authorize]:
returned from eap (rlm_eap) for request 2
Mon Apr  3 11:12:08 2006 : Debug:   modcall[authorize]:
module "eap" returns noop for request 2
Mon Apr  3 11:12:08 2006 : Debug:   modsingle[authorize]:
calling files (rlm_files) for request 2
Mon Apr  3 11:12:08 2006 : Debug:   modsingle[authorize]:
returned from files (rlm_files) for request 2
Mon Apr  3 11:12:08 2006 : Debug:   modcall[authorize]:
module "files" returns notfound for request 2
Mon Apr  3 11:12:08 2006 : Debug:   modsingle[authorize]:
calling ldap (rlm_ldap) for request 2
Mon Apr  3 11:12:08 2006 : Debug: rlm_ldap: - authorize
Mon Apr  3 11:12:08 2006 : Debug: rlm_ldap: performing user
authorization for ldap
Mon Apr  3 11:12:08 2006 : Debug: radius_xlat:
 '(uid=ldap)'
Mon Apr  3 11:12:08 2006 : Debug: radius_xlat:  'ou=Sion,
o=ad.ch'
Mon Apr  3 11:12:08 2006 : Debug: rlm_ldap: ldap_get_conn:
Checking Id: 0
Mon Apr  3 11:12:08 2006 : Debug: rlm_ldap: ldap_get_conn:
Got Id: 0
Mon Apr  3 11:12:08 2006 : Debug: rlm_ldap: attempting LDAP
reconnection
Mon Apr  3 11:12:08 2006 : Debug: rlm_ldap: closing
existing LDAP connection
Mon Apr  3 11:12:08 2006 : Debug: rlm_ldap: (re)connect to
ad.ch:389, authentication 0
Mon Apr  3 11:12:08 2006 : Debug: rlm_ldap: bind as / to
ad.ch:389
Mon Apr  3 11:12:18 2006 : Debug: rlm_ldap: waiting for
bind result ...
Mon Apr  3 11:12:18 2006 : Debug: rlm_ldap: Bind was
successful
Mon Apr  3 11:12:18 2006 : Debug: rlm_ldap: performing
search in ou=Sion, o=ad.ch, with filter (uid=ldap)
Mon Apr  3 11:12:18 2006 : Error: rlm_ldap: ldap_search()
failed: Operations error
Mon Apr  3 11:12:18 2006 : Debug: rlm_ldap: search failed
Mon Apr  3 11:12:18 2006 : Debug: rlm_ldap:
ldap_release_conn: Release Id: 0
Mon Apr  3 11:12:18 2006 : Debug:   modsingle[authorize]:
returned from ldap (rlm_ldap) for request 2
Mon Apr  3 11:12:18 2006 : Debug:   modcall[authorize]:
module "ldap" returns fail for request 2
Mon Apr  3 11:12:18 2006 : Debug: modcall: group authorize
returns fail for request 2
Mon Apr  3 11:12:18 2006 : Debug: Finished request 2
Mon Apr  3 11:12:18 2006 : Debug: Going to the next request
Mon Apr  3 11:12:18 2006 : Debug: --- Walking the entire
request list ---
Mon Apr  3 11:12:18 2006 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host
192.168.210.15:4596, id=13, length=100
Mon Apr  3 11:12:18 2006 : Debug: Discarding duplicate
request from client testnet:4596 - ID: 13
Mon Apr  3 11:12:18 2006 : Debug: --- Walking the entire
request list ---
Mon Apr  3 11:12:18 2006 : Debug: Cleaning up request 2 ID
13 with timestamp 4430e6e8
Mon Apr  3 11:12:18 2006 : Debug: Nothing to do.  Sleeping
until we see a request.
rad_recv: Access-Request packet from host
192.168.210.15:4596, id=13, length=100
        NAS-Port-Type = Ethernet
        Service-Type = Login-User
        User-Name = "ldap"
        User-Password = "ldap"
        Called-Station-Id = "00:01:02:ad:64:f7"
        Calling-Station-Id = "00:c0:49:54:b5:43"
        NAS-Port = 1
Mon Apr  3 11:12:18 2006 : Debug:   Processing the
authorize section of radiusd.conf
Mon Apr  3 11:12:18 2006 : Debug: modcall: entering group
authorize for request 3
Mon Apr  3 11:12:18 2006 : Debug:   modsingle[authorize]:
calling preprocess (rlm_preprocess) for request 3
Mon Apr  3 11:12:18 2006 : Debug:   modsingle[authorize]:
returned from preprocess (rlm_preprocess) for request 3
Mon Apr  3 11:12:18 2006 : Debug:   modcall[authorize]:
module "preprocess" returns ok for request 3
Mon Apr  3 11:12:18 2006 : Debug:   modsingle[authorize]:
calling chap (rlm_chap) for request 3
Mon Apr  3 11:12:18 2006 : Debug:   modsingle[authorize]:
returned from chap (rlm_chap) for request 3
Mon Apr  3 11:12:18 2006 : Debug:   modcall[authorize]:
module "chap" returns noop for request 3
Mon Apr  3 11:12:18 2006 : Debug:   modsingle[authorize]:
calling mschap (rlm_mschap) for request 3
Mon Apr  3 11:12:18 2006 : Debug:   modsingle[authorize]:
returned from mschap (rlm_mschap) for request 3
Mon Apr  3 11:12:18 2006 : Debug:   modcall[authorize]:
module "mschap" returns noop for request 3
Mon Apr  3 11:12:18 2006 : Debug:   modsingle[authorize]:
calling suffix (rlm_realm) for request 3
Mon Apr  3 11:12:18 2006 : Debug:     rlm_realm: No '@' in
User-Name = "ldap", looking up realm NULL
Mon Apr  3 11:12:18 2006 : Debug:     rlm_realm: No such
realm "NULL"
Mon Apr  3 11:12:18 2006 : Debug:   modsingle[authorize]:
returned from suffix (rlm_realm) for request 3
Mon Apr  3 11:12:18 2006 : Debug:   modcall[authorize]:
module "suffix" returns noop for request 3
Mon Apr  3 11:12:18 2006 : Debug:   modsingle[authorize]:
calling eap (rlm_eap) for request 3
Mon Apr  3 11:12:18 2006 : Debug:   rlm_eap: No
EAP-Message, not doing EAP
Mon Apr  3 11:12:18 2006 : Debug:   modsingle[authorize]:
returned from eap (rlm_eap) for request 3
Mon Apr  3 11:12:18 2006 : Debug:   modcall[authorize]:
module "eap" returns noop for request 3
Mon Apr  3 11:12:18 2006 : Debug:   modsingle[authorize]:
calling files (rlm_files) for request 3
Mon Apr  3 11:12:18 2006 : Debug:   modsingle[authorize]:
returned from files (rlm_files) for request 3
Mon Apr  3 11:12:18 2006 : Debug:   modcall[authorize]:
module "files" returns notfound for request 3
Mon Apr  3 11:12:18 2006 : Debug:   modsingle[authorize]:
calling ldap (rlm_ldap) for request 3
Mon Apr  3 11:12:18 2006 : Debug: rlm_ldap: - authorize
Mon Apr  3 11:12:18 2006 : Debug: rlm_ldap: performing user
authorization for ldap
Mon Apr  3 11:12:18 2006 : Debug: radius_xlat:
 '(uid=ldap)'
Mon Apr  3 11:12:18 2006 : Debug: radius_xlat:  'ou=Sion,
o=ad.ch'
Mon Apr  3 11:12:18 2006 : Debug: rlm_ldap: ldap_get_conn:
Checking Id: 0
Mon Apr  3 11:12:18 2006 : Debug: rlm_ldap: ldap_get_conn:
Got Id: 0
Mon Apr  3 11:12:18 2006 : Debug: rlm_ldap: attempting LDAP
reconnection
Mon Apr  3 11:12:18 2006 : Debug: rlm_ldap: closing
existing LDAP connection
Mon Apr  3 11:12:18 2006 : Debug: rlm_ldap: (re)connect to
ad.ch:389, authentication 0
Mon Apr  3 11:12:18 2006 : Debug: rlm_ldap: bind as / to
ad.ch:389
Mon Apr  3 11:12:28 2006 : Debug: rlm_ldap: waiting for
bind result ...
Mon Apr  3 11:12:28 2006 : Debug: rlm_ldap: Bind was
successful
Mon Apr  3 11:12:28 2006 : Debug: rlm_ldap: performing
search in ou=Sion, o=ad.ch, with filter (uid=ldap)
Mon Apr  3 11:12:28 2006 : Error: rlm_ldap: ldap_search()
failed: Operations error
Mon Apr  3 11:12:28 2006 : Debug: rlm_ldap: search failed
Mon Apr  3 11:12:28 2006 : Debug: rlm_ldap:
ldap_release_conn: Release Id: 0
Mon Apr  3 11:12:28 2006 : Debug:   modsingle[authorize]:
returned from ldap (rlm_ldap) for request 3
Mon Apr  3 11:12:28 2006 : Debug:   modcall[authorize]:
module "ldap" returns fail for request 3
Mon Apr  3 11:12:28 2006 : Debug: modcall: group authorize
returns fail for request 3
Mon Apr  3 11:12:28 2006 : Debug: Finished request 3
Mon Apr  3 11:12:28 2006 : Debug: Going to the next request
Mon Apr  3 11:12:28 2006 : Debug: --- Walking the entire
request list ---
Mon Apr  3 11:12:28 2006 : Debug: Waking up in 6 seconds...
Mon Apr  3 11:12:34 2006 : Debug: --- Walking the entire
request list ---
Mon Apr  3 11:12:34 2006 : Debug: Cleaning up request 3 ID
13 with timestamp 4430e6f2
Mon Apr  3 11:12:34 2006 : Debug: Nothing to do.  Sleeping
until we see a request.

Where can I fix the misstake which produce this error?

greets

dominique