FreeRADIUS / freeradius-server

FreeRADIUS - A multi-protocol policy server.
http://freeradius.org
GNU General Public License v2.0
2.11k stars 1.08k forks source link

3.0.25: ldap module instantiation failed when using start_tls #4375

Closed antoniotorresm closed 2 years ago

antoniotorresm commented 2 years ago

What type of defect/bug is this?

Unexpected behaviour (obvious or verified by project member)

How can the issue be reproduced?

Additional info:

Log output from the FreeRADIUS daemon

FreeRADIUS Version 3.0.25
Copyright (C) 1999-2021 The FreeRADIUS server project and contributors
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
PARTICULAR PURPOSE
You may redistribute copies of FreeRADIUS under the terms of the
GNU General Public License
For more information about these matters, see the file named COPYRIGHT
Starting - reading configuration files ...
including dictionary file /usr/share/freeradius/dictionary
including dictionary file /usr/share/freeradius/dictionary.dhcp
including dictionary file /usr/share/freeradius/dictionary.vqp
including dictionary file /etc/raddb/dictionary
including configuration file /etc/raddb/radiusd.conf
including configuration file /etc/raddb/proxy.conf
including configuration file /etc/raddb/clients.conf
including files in directory /etc/raddb/mods-enabled/
including configuration file /etc/raddb/mods-enabled/always
including configuration file /etc/raddb/mods-enabled/cache_eap
including configuration file /etc/raddb/mods-enabled/date
including configuration file /etc/raddb/mods-enabled/detail.log
including configuration file /etc/raddb/mods-enabled/dynamic_clients
including configuration file /etc/raddb/mods-enabled/echo
including configuration file /etc/raddb/mods-enabled/expiration
including configuration file /etc/raddb/mods-enabled/linelog
including configuration file /etc/raddb/mods-enabled/mschap
including configuration file /etc/raddb/mods-enabled/pap
including configuration file /etc/raddb/mods-enabled/preprocess
including configuration file /etc/raddb/mods-enabled/realm
including configuration file /etc/raddb/mods-enabled/soh
including configuration file /etc/raddb/mods-enabled/sradutmp
including configuration file /etc/raddb/mods-enabled/unix
including configuration file /etc/raddb/mods-enabled/utf8
including configuration file /etc/raddb/mods-enabled/ldap
including configuration file /etc/raddb/mods-enabled/attr_filter
including configuration file /etc/raddb/mods-enabled/chap
including configuration file /etc/raddb/mods-enabled/detail
including configuration file /etc/raddb/mods-enabled/digest
including configuration file /etc/raddb/mods-enabled/eap
including configuration file /etc/raddb/mods-enabled/exec
including configuration file /etc/raddb/mods-enabled/expr
including configuration file /etc/raddb/mods-enabled/files
including configuration file /etc/raddb/mods-enabled/logintime
including configuration file /etc/raddb/mods-enabled/ntlm_auth
including configuration file /etc/raddb/mods-enabled/passwd
including configuration file /etc/raddb/mods-enabled/radutmp
including configuration file /etc/raddb/mods-enabled/replicate
including configuration file /etc/raddb/mods-enabled/totp
including configuration file /etc/raddb/mods-enabled/unpack
including files in directory /etc/raddb/policy.d/
including configuration file /etc/raddb/policy.d/accounting
including configuration file /etc/raddb/policy.d/canonicalization
including configuration file /etc/raddb/policy.d/control
including configuration file /etc/raddb/policy.d/cui
including configuration file /etc/raddb/policy.d/debug
including configuration file /etc/raddb/policy.d/dhcp
including configuration file /etc/raddb/policy.d/eap
including configuration file /etc/raddb/policy.d/filter
including configuration file /etc/raddb/policy.d/operator-name
including configuration file /etc/raddb/policy.d/rfc7542
including files in directory /etc/raddb/sites-enabled/
including configuration file /etc/raddb/sites-enabled/default
including configuration file /etc/raddb/sites-enabled/inner-tunnel
main {
 security {
    user = "radiusd"
    group = "radiusd"
    allow_core_dumps = no
 }
    name = "radiusd"
    prefix = "/usr"
    localstatedir = "/var"
    logdir = "/var/log/radius"
    run_dir = "/var/run/radiusd"
}
main {
    name = "radiusd"
    prefix = "/usr"
    localstatedir = "/var"
    sbindir = "/usr/sbin"
    logdir = "/var/log/radius"
    run_dir = "/var/run/radiusd"
    libdir = "/usr/lib64/freeradius"
    radacctdir = "/var/log/radius/radacct"
    hostname_lookups = no
    max_request_time = 30
    cleanup_delay = 5
    max_requests = 16384
    postauth_client_lost = no
    pidfile = "/var/run/radiusd/radiusd.pid"
    checkrad = "/usr/sbin/checkrad"
    debug_level = 0
    proxy_requests = yes
 log {
    stripped_names = no
    auth = no
    auth_badpass = no
    auth_goodpass = no
    colourise = yes
    msg_denied = "You are already logged in - access denied"
 }
 resources {
 }
 security {
    max_attributes = 200
    reject_delay = 1.000000
    status_server = yes
 }
}
radiusd: #### Loading Realms and Home Servers ####
 proxy server {
    retry_delay = 5
    retry_count = 3
    default_fallback = no
    dead_time = 120
    wake_all_if_all_dead = no
 }
 home_server localhost {
    ipaddr = 127.0.0.1
    port = 1812
    type = "auth"
    secret = <<< secret >>>
    response_window = 20.000000
    response_timeouts = 1
    max_outstanding = 65536
    zombie_period = 40
    status_check = "status-server"
    ping_interval = 30
    check_interval = 30
    check_timeout = 4
    num_answers_to_alive = 3
    revive_interval = 120
  limit {
    max_connections = 16
    max_requests = 0
    lifetime = 0
    idle_timeout = 0
  }
  coa {
    irt = 2
    mrt = 16
    mrc = 5
    mrd = 30
  }
 }
 home_server_pool my_auth_failover {
    type = fail-over
    home_server = localhost
 }
 realm example.com {
    auth_pool = my_auth_failover
 }
 realm LOCAL {
 }
radiusd: #### Loading Clients ####
 client localhost {
    ipaddr = 127.0.0.1
    require_message_authenticator = no
    secret = <<< secret >>>
    nas_type = "other"
    proto = "*"
  limit {
    max_connections = 16
    lifetime = 0
    idle_timeout = 30
  }
 }
 client localhost_ipv6 {
    ipv6addr = ::1
    require_message_authenticator = no
    secret = <<< secret >>>
  limit {
    max_connections = 16
    lifetime = 0
    idle_timeout = 30
  }
 }
Debugger not attached
 # Creating Auth-Type = mschap
 # Creating Auth-Type = digest
 # Creating Auth-Type = eap
 # Creating Auth-Type = LDAP
 # Creating Auth-Type = PAP
 # Creating Auth-Type = CHAP
 # Creating Auth-Type = MS-CHAP
 # Creating Autz-Type = New-TLS-Connection
radiusd: #### Instantiating modules ####
 modules {
  # Loaded module rlm_always
  # Loading module "reject" from file /etc/raddb/mods-enabled/always
  always reject {
    rcode = "reject"
    simulcount = 0
    mpp = no
  }
  # Loading module "fail" from file /etc/raddb/mods-enabled/always
  always fail {
    rcode = "fail"
    simulcount = 0
    mpp = no
  }
  # Loading module "ok" from file /etc/raddb/mods-enabled/always
  always ok {
    rcode = "ok"
    simulcount = 0
    mpp = no
  }
  # Loading module "handled" from file /etc/raddb/mods-enabled/always
  always handled {
    rcode = "handled"
    simulcount = 0
    mpp = no
  }
  # Loading module "invalid" from file /etc/raddb/mods-enabled/always
  always invalid {
    rcode = "invalid"
    simulcount = 0
    mpp = no
  }
  # Loading module "userlock" from file /etc/raddb/mods-enabled/always
  always userlock {
    rcode = "userlock"
    simulcount = 0
    mpp = no
  }
  # Loading module "notfound" from file /etc/raddb/mods-enabled/always
  always notfound {
    rcode = "notfound"
    simulcount = 0
    mpp = no
  }
  # Loading module "noop" from file /etc/raddb/mods-enabled/always
  always noop {
    rcode = "noop"
    simulcount = 0
    mpp = no
  }
  # Loading module "updated" from file /etc/raddb/mods-enabled/always
  always updated {
    rcode = "updated"
    simulcount = 0
    mpp = no
  }
  # Loaded module rlm_cache
  # Loading module "cache_eap" from file /etc/raddb/mods-enabled/cache_eap
  cache cache_eap {
    driver = "rlm_cache_rbtree"
    key = "%{%{control:State}:-%{%{reply:State}:-%{State}}}"
    ttl = 15
    max_entries = 0
    epoch = 0
    add_stats = no
  }
  # Loaded module rlm_date
  # Loading module "date" from file /etc/raddb/mods-enabled/date
  date {
    format = "%b %e %Y %H:%M:%S %Z"
    utc = no
  }
  # Loading module "wispr2date" from file /etc/raddb/mods-enabled/date
  date wispr2date {
    format = "%Y-%m-%dT%H:%M:%S"
    utc = no
  }
  # Loaded module rlm_detail
  # Loading module "auth_log" from file /etc/raddb/mods-enabled/detail.log
  detail auth_log {
    filename = "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d"
    header = "%t"
    permissions = 384
    locking = no
    escape_filenames = no
    log_packet_header = no
  }
  # Loading module "reply_log" from file /etc/raddb/mods-enabled/detail.log
  detail reply_log {
    filename = "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d"
    header = "%t"
    permissions = 384
    locking = no
    escape_filenames = no
    log_packet_header = no
  }
  # Loading module "pre_proxy_log" from file /etc/raddb/mods-enabled/detail.log
  detail pre_proxy_log {
    filename = "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d"
    header = "%t"
    permissions = 384
    locking = no
    escape_filenames = no
    log_packet_header = no
  }
  # Loading module "post_proxy_log" from file /etc/raddb/mods-enabled/detail.log
  detail post_proxy_log {
    filename = "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d"
    header = "%t"
    permissions = 384
    locking = no
    escape_filenames = no
    log_packet_header = no
  }
  # Loaded module rlm_dynamic_clients
  # Loading module "dynamic_clients" from file /etc/raddb/mods-enabled/dynamic_clients
  # Loaded module rlm_exec
  # Loading module "echo" from file /etc/raddb/mods-enabled/echo
  exec echo {
    wait = yes
    program = "/bin/echo %{User-Name}"
    input_pairs = "request"
    output_pairs = "reply"
    shell_escape = yes
  }
  # Loaded module rlm_expiration
  # Loading module "expiration" from file /etc/raddb/mods-enabled/expiration
  # Loaded module rlm_linelog
  # Loading module "linelog" from file /etc/raddb/mods-enabled/linelog
  linelog {
    filename = "/var/log/radius/linelog"
    escape_filenames = no
    syslog_severity = "info"
    permissions = 384
    format = "This is a log message for %{User-Name}"
    reference = "messages.%{%{reply:Packet-Type}:-default}"
  }
  # Loading module "log_accounting" from file /etc/raddb/mods-enabled/linelog
  linelog log_accounting {
    filename = "/var/log/radius/linelog-accounting"
    escape_filenames = no
    syslog_severity = "info"
    permissions = 384
    format = ""
    reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}"
  }
  # Loaded module rlm_mschap
  # Loading module "mschap" from file /etc/raddb/mods-enabled/mschap
  mschap {
    use_mppe = yes
    require_encryption = no
    require_strong = no
    with_ntdomain_hack = yes
   passchange {
   }
    allow_retry = yes
    winbind_retry_with_normalised_username = no
  }
  # Loaded module rlm_pap
  # Loading module "pap" from file /etc/raddb/mods-enabled/pap
  pap {
    normalise = yes
  }
  # Loaded module rlm_preprocess
  # Loading module "preprocess" from file /etc/raddb/mods-enabled/preprocess
  preprocess {
    huntgroups = "/etc/raddb/mods-config/preprocess/huntgroups"
    hints = "/etc/raddb/mods-config/preprocess/hints"
    with_ascend_hack = no
    ascend_channels_per_line = 23
    with_ntdomain_hack = no
    with_specialix_jetstream_hack = no
    with_cisco_vsa_hack = no
    with_alvarion_vsa_hack = no
  }
  # Loaded module rlm_realm
  # Loading module "IPASS" from file /etc/raddb/mods-enabled/realm
  realm IPASS {
    format = "prefix"
    delimiter = "/"
    ignore_default = no
    ignore_null = no
  }
  # Loading module "suffix" from file /etc/raddb/mods-enabled/realm
  realm suffix {
    format = "suffix"
    delimiter = "@"
    ignore_default = no
    ignore_null = no
  }
  # Loading module "bangpath" from file /etc/raddb/mods-enabled/realm
  realm bangpath {
    format = "prefix"
    delimiter = "!"
    ignore_default = no
    ignore_null = no
  }
  # Loading module "realmpercent" from file /etc/raddb/mods-enabled/realm
  realm realmpercent {
    format = "suffix"
    delimiter = "%"
    ignore_default = no
    ignore_null = no
  }
  # Loading module "ntdomain" from file /etc/raddb/mods-enabled/realm
  realm ntdomain {
    format = "prefix"
    delimiter = "\\"
    ignore_default = no
    ignore_null = no
  }
  # Loaded module rlm_soh
  # Loading module "soh" from file /etc/raddb/mods-enabled/soh
  soh {
    dhcp = yes
  }
  # Loaded module rlm_radutmp
  # Loading module "sradutmp" from file /etc/raddb/mods-enabled/sradutmp
  radutmp sradutmp {
    filename = "/var/log/radius/sradutmp"
    username = "%{User-Name}"
    case_sensitive = yes
    check_with_nas = yes
    permissions = 420
    caller_id = no
  }
  # Loaded module rlm_unix
  # Loading module "unix" from file /etc/raddb/mods-enabled/unix
  unix {
    radwtmp = "/var/log/radius/radwtmp"
  }
Creating attribute Unix-Group
  # Loaded module rlm_utf8
  # Loading module "utf8" from file /etc/raddb/mods-enabled/utf8
  # Loaded module rlm_ldap
  # Loading module "ldap" from file /etc/raddb/mods-enabled/ldap
  ldap {
    server = "fedora"
    port = 389
   sasl {
   }
    user_dn = "LDAP-UserDn"
   user {
    scope = "sub"
    access_positive = yes
    sasl {
    }
   }
   group {
    filter = "(objectClass=posixGroup)"
    scope = "sub"
    name_attribute = "cn"
    membership_attribute = "memberOf"
    cacheable_name = no
    cacheable_dn = no
    allow_dangling_group_ref = no
   }
   client {
    filter = "(objectClass=radiusClient)"
    scope = "sub"
    base_dn = "dc=my-domain,dc=com"
   }
   profile {
   }
   options {
    ldap_debug = 2049
    chase_referrals = yes
    rebind = yes
    net_timeout = 1
    res_timeout = 10
    srv_timelimit = 3
    idle = 60
    probes = 3
    interval = 3
   }
   tls {
    start_tls = yes
    require_cert = "never"
   }
  }
Creating attribute LDAP-Group
  # Loaded module rlm_attr_filter
  # Loading module "attr_filter.post-proxy" from file /etc/raddb/mods-enabled/attr_filter
  attr_filter attr_filter.post-proxy {
    filename = "/etc/raddb/mods-config/attr_filter/post-proxy"
    key = "%{Realm}"
    relaxed = no
  }
  # Loading module "attr_filter.pre-proxy" from file /etc/raddb/mods-enabled/attr_filter
  attr_filter attr_filter.pre-proxy {
    filename = "/etc/raddb/mods-config/attr_filter/pre-proxy"
    key = "%{Realm}"
    relaxed = no
  }
  # Loading module "attr_filter.access_reject" from file /etc/raddb/mods-enabled/attr_filter
  attr_filter attr_filter.access_reject {
    filename = "/etc/raddb/mods-config/attr_filter/access_reject"
    key = "%{User-Name}"
    relaxed = no
  }
  # Loading module "attr_filter.access_challenge" from file /etc/raddb/mods-enabled/attr_filter
  attr_filter attr_filter.access_challenge {
    filename = "/etc/raddb/mods-config/attr_filter/access_challenge"
    key = "%{User-Name}"
    relaxed = no
  }
  # Loading module "attr_filter.accounting_response" from file /etc/raddb/mods-enabled/attr_filter
  attr_filter attr_filter.accounting_response {
    filename = "/etc/raddb/mods-config/attr_filter/accounting_response"
    key = "%{User-Name}"
    relaxed = no
  }
  # Loading module "attr_filter.coa" from file /etc/raddb/mods-enabled/attr_filter
  attr_filter attr_filter.coa {
    filename = "/etc/raddb/mods-config/attr_filter/coa"
    key = "%{User-Name}"
    relaxed = no
  }
  # Loaded module rlm_chap
  # Loading module "chap" from file /etc/raddb/mods-enabled/chap
  # Loading module "detail" from file /etc/raddb/mods-enabled/detail
  detail {
    filename = "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d"
    header = "%t"
    permissions = 384
    locking = no
    escape_filenames = no
    log_packet_header = no
  }
  # Loaded module rlm_digest
  # Loading module "digest" from file /etc/raddb/mods-enabled/digest
  # Loaded module rlm_eap
  # Loading module "eap" from file /etc/raddb/mods-enabled/eap
  eap {
    default_eap_type = "md5"
    timer_expire = 60
    ignore_unknown_eap_types = no
    cisco_accounting_username_bug = no
    max_sessions = 16384
  }
  # Loading module "exec" from file /etc/raddb/mods-enabled/exec
  exec {
    wait = no
    input_pairs = "request"
    shell_escape = yes
    timeout = 10
  }
  # Loaded module rlm_expr
  # Loading module "expr" from file /etc/raddb/mods-enabled/expr
  expr {
    safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ"
  }
  # Loaded module rlm_files
  # Loading module "files" from file /etc/raddb/mods-enabled/files
  files {
    filename = "/etc/raddb/mods-config/files/authorize"
    acctusersfile = "/etc/raddb/mods-config/files/accounting"
    preproxy_usersfile = "/etc/raddb/mods-config/files/pre-proxy"
  }
  # Loaded module rlm_logintime
  # Loading module "logintime" from file /etc/raddb/mods-enabled/logintime
  logintime {
    minimum_timeout = 60
  }
  # Loading module "ntlm_auth" from file /etc/raddb/mods-enabled/ntlm_auth
  exec ntlm_auth {
    wait = yes
    program = "/path/to/ntlm_auth --request-nt-key --domain=MYDOMAIN --username=%{mschap:User-Name} --password=%{User-Password}"
    shell_escape = yes
  }
  # Loaded module rlm_passwd
  # Loading module "etc_passwd" from file /etc/raddb/mods-enabled/passwd
  passwd etc_passwd {
    filename = "/etc/passwd"
    format = "*User-Name:Crypt-Password:"
    delimiter = ":"
    ignore_nislike = no
    ignore_empty = yes
    allow_multiple_keys = no
    hash_size = 100
  }
  # Loading module "radutmp" from file /etc/raddb/mods-enabled/radutmp
  radutmp {
    filename = "/var/log/radius/radutmp"
    username = "%{User-Name}"
    case_sensitive = yes
    check_with_nas = yes
    permissions = 384
    caller_id = yes
  }
  # Loaded module rlm_replicate
  # Loading module "replicate" from file /etc/raddb/mods-enabled/replicate
  # Loaded module rlm_totp
  # Loading module "totp" from file /etc/raddb/mods-enabled/totp
  # Loaded module rlm_unpack
  # Loading module "unpack" from file /etc/raddb/mods-enabled/unpack
  instantiate {
  }
  # Instantiating module "reject" from file /etc/raddb/mods-enabled/always
  # Instantiating module "fail" from file /etc/raddb/mods-enabled/always
  # Instantiating module "ok" from file /etc/raddb/mods-enabled/always
  # Instantiating module "handled" from file /etc/raddb/mods-enabled/always
  # Instantiating module "invalid" from file /etc/raddb/mods-enabled/always
  # Instantiating module "userlock" from file /etc/raddb/mods-enabled/always
  # Instantiating module "notfound" from file /etc/raddb/mods-enabled/always
  # Instantiating module "noop" from file /etc/raddb/mods-enabled/always
  # Instantiating module "updated" from file /etc/raddb/mods-enabled/always
  # Instantiating module "cache_eap" from file /etc/raddb/mods-enabled/cache_eap
rlm_cache (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linked
  # Instantiating module "auth_log" from file /etc/raddb/mods-enabled/detail.log
rlm_detail (auth_log): 'User-Password' suppressed, will not appear in detail output
  # Instantiating module "reply_log" from file /etc/raddb/mods-enabled/detail.log
  # Instantiating module "pre_proxy_log" from file /etc/raddb/mods-enabled/detail.log
  # Instantiating module "post_proxy_log" from file /etc/raddb/mods-enabled/detail.log
  # Instantiating module "expiration" from file /etc/raddb/mods-enabled/expiration
  # Instantiating module "linelog" from file /etc/raddb/mods-enabled/linelog
  # Instantiating module "log_accounting" from file /etc/raddb/mods-enabled/linelog
  # Instantiating module "mschap" from file /etc/raddb/mods-enabled/mschap
rlm_mschap (mschap): using internal authentication
  # Instantiating module "pap" from file /etc/raddb/mods-enabled/pap
  # Instantiating module "preprocess" from file /etc/raddb/mods-enabled/preprocess
reading pairlist file /etc/raddb/mods-config/preprocess/huntgroups
reading pairlist file /etc/raddb/mods-config/preprocess/hints
  # Instantiating module "IPASS" from file /etc/raddb/mods-enabled/realm
  # Instantiating module "suffix" from file /etc/raddb/mods-enabled/realm
  # Instantiating module "bangpath" from file /etc/raddb/mods-enabled/realm
  # Instantiating module "realmpercent" from file /etc/raddb/mods-enabled/realm
  # Instantiating module "ntdomain" from file /etc/raddb/mods-enabled/realm
  # Instantiating module "ldap" from file /etc/raddb/mods-enabled/ldap
rlm_ldap: libldap vendor: OpenLDAP, version: 20459
   accounting {
    reference = "%{tolower:type.%{Acct-Status-Type}}"
   }
   post-auth {
    reference = "."
   }
rlm_ldap (ldap): Initialising connection pool
   pool {
    start = 5
    min = 3
    max = 32
    spare = 10
    uses = 0
    lifetime = 0
    cleanup_interval = 30
    idle_timeout = 60
    retry_delay = 30
    spread = no
   }
rlm_ldap (ldap): Opening additional connection (0), 1 of 32 pending slots used
rlm_ldap (ldap): Connecting to ldap://fedora:389
ldap_create
ldap_url_parse_ext(ldap://fedora:389)
ldap_extended_operation_s
ldap_extended_operation
ldap_send_initial_request
ldap_new_connection 1 1 0
ldap_int_open_connection
ldap_connect_to_host: TCP fedora:389
ldap_new_socket: 3
ldap_prepare_socket: 3
ldap_connect_to_host: Trying fe80::5054:ff:fe82:f1fb 389
ldap_pvt_connect: fd: 3 tm: 1 async: 0
ldap_ndelay_on: 3
attempting to connect: 
connect errno: 115
ldap_int_poll: fd: 3 tm: 1
ldap_is_sock_ready: 3
ldap_ndelay_off: 3
ldap_pvt_connect: 0
ldap_open_defconn: successful
ldap_send_server_request
ldap_result ld 0x55c6752a66f0 msgid 1
wait4msg ld 0x55c6752a66f0 msgid 1 (infinite timeout)
wait4msg continue ld 0x55c6752a66f0 msgid 1 all 1
** ld 0x55c6752a66f0 Connections:
* host: fedora  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Tue Jan 25 21:52:39 2022

** ld 0x55c6752a66f0 Outstanding Requests:
 * msgid 1,  origid 1, status InProgress
   outstanding referrals 0, parent count 0
  ld 0x55c6752a66f0 request count 1 (abandoned 0)
** ld 0x55c6752a66f0 Response Queue:
   Empty
  ld 0x55c6752a66f0 response count 0
ldap_chkResponseList ld 0x55c6752a66f0 msgid 1 all 1
ldap_chkResponseList returns ld 0x55c6752a66f0 NULL
ldap_int_select
read1msg: ld 0x55c6752a66f0 msgid 1 all 1
read1msg: ld 0x55c6752a66f0 msgid 1 message type extended-result
read1msg: ld 0x55c6752a66f0 0 new referrals
read1msg:  mark request completed, ld 0x55c6752a66f0 msgid 1
request done: ld 0x55c6752a66f0 msgid 1
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 1, msgid 1)
ldap_parse_extended_result
ldap_parse_result
ldap_msgfree
TLS trace: SSL_connect:before SSL initialization
TLS trace: SSL_connect:SSLv3/TLS write client hello
TLS trace: SSL_connect:error in SSLv3/TLS write client hello
ldap_bind
ldap_simple_bind
ldap_sasl_bind
ldap_send_initial_request
ldap_send_server_request
TLS trace: SSL_connect:error in SSLv3/TLS write client hello
rlm_ldap (ldap): Waiting for bind result...
ldap_err2string
rlm_ldap (ldap): Bind with (anonymous) to ldap://fedora:389 failed: Server is busy
ldap_free_request (origid 2, msgid 2)
ldap_free_connection 1 1
ldap_send_unbind
TLS trace: SSL_connect:error in SSLv3/TLS write client hello
ldap_free_connection: actually freed
rlm_ldap (ldap): Opening connection failed (0)
rlm_ldap (ldap): Removing connection pool
/etc/raddb/mods-enabled/ldap[8]: Instantiation failed for module "ldap"

Relevant log output from client utilities

No response

Backtrace from LLDB or GDB

No response

alandekok commented 2 years ago

This is fixed in the v3.0.x branch, and will be included in 3.0.26 when it is released.

Until then, just change the LDAP connection pool to use start = 0

antoniotorresm commented 2 years ago

Thanks for your quick reply, @alandekok. I've tried building from source and testing but unfortunately the issue persists. There was the commit 21d95b268b4cf56e75064898d83123825d673818 that partially addressed this but got reverted a few weeks later in d14f77ef797d537f309e73f2333bc1eaef8080ba.

mcnewton commented 2 years ago

Yes that patch caused deadlocks elsewhere IIRC. Does it work with start = 0? That should arguably be the default in 99% of situations anyway, as otherwise when your LDAP server is down FreeRADIUS will entirely refuse to start up.

antoniotorresm commented 2 years ago

Setting start = 0 will allow FreeRADIUS to start, but the failure still shows when querying through radtest. The LDAP server is running and TLS auth is working through ldapsearch.

The debug output points to an error during SSL connect:

TLS trace: SSL_connect:before SSL initialization
TLS trace: SSL_connect:SSLv3/TLS write client hello
TLS trace: SSL_connect:error in SSLv3/TLS write client hello
antoniotorresm commented 2 years ago

Setting LDAP_OPT_NETWORK_TIMEOUT to -1 (which is the OpenLDAP default) when using start_tls = yes will fix this, since it makes libldap use a blocking socket during the TLS start procedure. Doing this in combination with start = 0 guarantees FreeRADIUS to start even if the LDAP server is non-responsive.