Hello list,

in my further tests with FreeRADIUS v3 (rpmbuild from v3.0.x branch) I have a problem with the ldap module and start_tls.

This is definitely working:

- Ldap connect with ldap utils (ldapsearch -ZZ and so on) via port 389 with starttls

- Ldap connect with FreeRADIUS 2.1.12 via port 389 (start_tls = yes and require_cert = "demand")

This is not working:

- FR 3 ldap module isn’t able to connect to ldap server via port 389 + start_tls=yes

- FR debug error:

# Loaded module rlm_ldap

# Instantiating module "ldap" from file /etc/raddb/mods-enabled/ldap

ldap {

server = "fqdn" (matches CN in ldap server certificate)

port = 389

password = "xxx"

identity = "xxx"

valuepair_attribute = "radiusVSA"

read_clients = yes

user {

filter = "(&(uid=%{%{Stripped-User-Name}:-%{User-Name}})(objectClass=radiusProfile))"

scope = "sub"

base_dn = "xxx"

access_attribute = "radiusAccountStatus"

access_positive = yes

}

group {

filter = "(objectClass=groupOfNames)"

scope = "sub"

base_dn = "xxx"

name_attribute = "cn"

membership_attribute = "memberOf"

membership_filter = "(member=%{control:Ldap-UserDn})"

cacheable_name = no

cacheable_dn = yes

}

client {

filter = "(objectClass=radiusClient)"

scope = "sub"

base_dn = "xxx"

attribute {

identifier = "radiusClientIdentifier"

shortname = "radiusClientShortname"

nas_type = "radiusClientType"

secret = "radiusClientSecret"

virtual_server = "radiusClientVirtualServer"

require_message_authenticator = "radiusClientRequireMa"

}

profile {

filter = "(objectclass=radiusObjectProfile)"

attribute = "radiusGroupName"

default = "xxx"

}

options {

ldap_debug = 597

chase_referrals = yes

rebind = yes

net_timeout = 1

res_timeout = 20

srv_timelimit = 20

idle = 60

probes = 3

interval = 3

}

tls {

ca_file = "/etc/raddb/certs/rootca_cert.pem"

start_tls = yes

require_cert = "demand" (also tested with never, same result)

}

accounting {

reference = "%{tolower:type.%{Acct-Status-Type}}"

}

post-auth {

reference = "."

}

rlm_ldap (ldap): Initialising connection pool

pool {

start = 5

min = 4

max = 10

spare = 3

uses = 0

lifetime = 0

cleanup_delay = 5

idle_timeout = 60

spread = no

}

rlm_ldap (ldap): Opening additional connection (0)

rlm_ldap (ldap): Connecting to fqdn:389

rlm_ldap (ldap): Could not start TLS: Connect error

rlm_ldap (ldap): Opening connection failed (0)

rlm_ldap (ldap): Removing connection pool

/etc/raddb/mods-enabled/ldap[8]: Instantiation failed for module "ldap"

- openldap debug log:

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on 1 descriptor

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on:

Nov 28 11:21:00 radiusv3test slapd[7737]:

Nov 28 11:21:00 radiusv3test slapd[7737]: slap_listener_activate(7):

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=7 busy

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=8 active_threads=0 tvp=zero

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=9 active_threads=0 tvp=zero

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=10 active_threads=0 tvp=zero

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=11 active_threads=0 tvp=zero

Nov 28 11:21:00 radiusv3test slapd[7737]: >>> slap_listener(ldap:///)

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: listen=7, new connection on 16

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on 1 descriptor

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on:

Nov 28 11:21:00 radiusv3test slapd[7737]:

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=7 active_threads=0 tvp=zero

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=8 active_threads=0 tvp=zero

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=9 active_threads=0 tvp=zero

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=10 active_threads=0 tvp=zero

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=11 active_threads=0 tvp=zero

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: added 16r (active) listener=(nil)

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on 2 descriptors

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on:

Nov 28 11:21:00 radiusv3test slapd[7737]: 16r

Nov 28 11:21:00 radiusv3test slapd[7737]:

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: read active on 16

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=7 active_threads=0 tvp=zero

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=8 active_threads=0 tvp=zero

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=9 active_threads=0 tvp=zero

Nov 28 11:21:00 radiusv3test slapd[7737]: connection_get(16)

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=10 active_threads=0 tvp=zero

Nov 28 11:21:00 radiusv3test slapd[7737]: connection_get(16): got connid=1003

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=11 active_threads=0 tvp=zero

Nov 28 11:21:00 radiusv3test slapd[7737]: connection_read(16): checking for input on id=1003

Nov 28 11:21:00 radiusv3test slapd[7737]: op tag 0x77, time 1385634060

Nov 28 11:21:00 radiusv3test slapd[7737]: conn=1003 op=0 do_extended

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on 1 descriptor

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on:

Nov 28 11:21:00 radiusv3test slapd[7737]: do_extended: oid=1.3.6.1.4.1.1466.20037

Nov 28 11:21:00 radiusv3test slapd[7737]:

Nov 28 11:21:00 radiusv3test slapd[7737]: send_ldap_extended: err=0 oid= len=0

Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=7 active_threads=0 tvp=zero

Nov 28 11:21:00 radiusv3test slapd[7737]: send_ldap_response: msgid=1 tag=120 err=0