FreeNAS 11.3U4.1 & 11.3U5 nslcd errors when contacting to JumpCloud LDAP Server

jcdfay

Cadet
Joined
Oct 15, 2020
Messages
4
Hey Team,

I've got several versions of FreeNAS running currently. Testing out a few things with FreeNAS & LDAP Authentication using JumpCloud's LDAP. Running into errors only with versions 11.3.

I'm running versions 11.2U8 (works perfectly) and 11.3U4.1 and 11.3U5 (having same issues on both).

Issue:
LDAP is configured to point to JumpCloud's LDAP following the KB: https://support.jumpcloud.com/suppo...pclouds-ldap-as-a-service-2019-08-21-10-36-47 (used same config within 11.2 with no issues. 11.3 doesn't allow for directly selected CAs like it did in 11.2, as it adds CAs to the truenas_cacerts.pem for you indirectly)

When selecting LDAP options for Encryption (NO, YES, & START_TLS) I continue to get the following errors in /var/log/messages:

Oct 15 13:51:14 freenas nslcd[6986]: [e65e86] <passwd="bob.smith"> ldap_result() failed: Can't contact LDAP server
Oct 15 13:51:14 freenas nslcd[6986]: [2d312f] <group/member="bob.smith"> ldap_result() failed: Can't contact LDAP server

GoDaddy CA cert which has been imported to the FreeNAS CA's menu by copy and pasting cert into text field (this is then saved to /etc/ssl/truenas_cacerts.pem)

In my config the Certificate field is left blank due to wanting to use the CA that I've uploaded from GoDaddy (via KB info).

When testing authentication just over 389 with no START_TLS or SSL, it still errors out with the same result in /var/log/messages even though I've tested authentication from the Windows PC accessing the SMB share with bob.smith's LDAP credentials, and it works successfully.

When using either No Encryption, Yes (SSL), or START_TLS, authentication and access appear to work fine for the end user, but /var/log/messages looks to be erroring out with the same connection message continually.

More Info:

getent groups shows all my LDAP Groups and sharing pools and shares is no issue at all. Works as expected.
FreeNAS 11.2 isn't showing any auth errors or connection errors with the LDAP server.

Config (/usr/local/etc/nslcd.conf)
SSL Enabled
uri ldaps://ldap.jumpcloud.com:636
base o=<ORGID>,dc=jumpcloud,dc=com
ssl on
tls_cacert /etc/ssl/truenas_cacerts.pem
tls_reqcert demand


START_TLS Enabled
uri ldap://ldap.jumpcloud.com:389
base o=<ORGID>,dc=jumpcloud,dc=com
ssl start_tls
tls_cacert /etc/ssl/truenas_cacerts.pem
tls_reqcert demand


No Encryption Enabled
uri ldap://ldap.jumpcloud.com:389
base o=<ORGID>,dc=jumpcloud,dc=com


End User Experience:
I can however authenticate to the SMB share from bob.smith's Windows PC via his LDAP credentials and create, access, write files.

Main Question:
  1. Are these messages are benign/false-positive?
    1. If they're not false-positive, how can we up the verbosity of nslcd to see why it reports there are errors?


      Thanks again for the help and any ideas around this.
 

anodos

Sambassador
iXsystems
Joined
Mar 6, 2014
Messages
9,545
The log message is generated wen ldap_result(3) fails with an LDAP_ERR such as you see above "Can't contact LDAP server". It might be caused by an intermittent issue with the remote service. nss-pam-ldapd is able to recover pretty quickly (probably through another one of its worker threads) and you don't notice a service interruption.

11.2 used SSSD for LDAP (which is currently unmaintained in FreeBSD).
11.3+ uses nss-pam-ldapd for the LDAP service

Different applications log error conditions differently. The syslog-ng config should probably be altered to move it to a separate file by default (maybe a change for 12).
 

jcdfay

Cadet
Joined
Oct 15, 2020
Messages
4
Thanks anodos,

I took a look a bit deeper, got nslcd debug logging going and was working with a colleague of mine on it as well. We made a singular change and it worked without getting another error message of:
freenas nslcd[6986]: [2d312f] <group/member="bob.smith"> ldap_result() failed: Can't contact LDAP server

All we did was comment out the scope field and it did not have the issue post.

nslcd.conf file:

root@freenas[/usr/local/etc]# less nslcd.conf
#
# NSLCD.CONF(5) The configuration file for LDAP nameservice daemon
# $FreeBSD$
#

uri ldaps://ldap.jumpcloud.com:636
base o=<ORG_ID>,dc=jumpcloud,dc=com
ssl on
tls_cacert /etc/ssl/truenas_cacerts.pem
tls_reqcert demand
binddn uid=<LDAP_BIND_DN USER>,ou=Users,o=<ORG_ID>,dc=jumpcloud,dc=com
bindpw *******************
# scope sub
timelimit 10
bind_timelimit 10
map passwd loginShell /bin/sh
log /var/log/nslcd.log debug

When restarting the server/service it overwrote the config file thus uncommenting the scope field causing the errors again.

Is there a template file or reference file somewhere to have scope be removed from the config file or at least commented out and where i can also add in the debug logging and log file location within FreeNAS 11.3+ ?

Thanks again for all the help!
 

anodos

Sambassador
iXsystems
Joined
Mar 6, 2014
Messages
9,545
Thanks anodos,

I took a look a bit deeper, got nslcd debug logging going and was working with a colleague of mine on it as well. We made a singular change and it worked without getting another error message of:
freenas nslcd[6986]: [2d312f] <group/member="bob.smith"> ldap_result() failed: Can't contact LDAP server

All we did was comment out the scope field and it did not have the issue post.

nslcd.conf file:

root@freenas[/usr/local/etc]# less nslcd.conf
#
# NSLCD.CONF(5) The configuration file for LDAP nameservice daemon
# $FreeBSD$
#

uri ldaps://ldap.jumpcloud.com:636
base o=<ORG_ID>,dc=jumpcloud,dc=com
ssl on
tls_cacert /etc/ssl/truenas_cacerts.pem
tls_reqcert demand
binddn uid=<LDAP_BIND_DN USER>,ou=Users,o=<ORG_ID>,dc=jumpcloud,dc=com
bindpw *******************
# scope sub
timelimit 10
bind_timelimit 10
map passwd loginShell /bin/sh
log /var/log/nslcd.log debug

When restarting the server/service it overwrote the config file thus uncommenting the scope field causing the errors again.

Is there a template file or reference file somewhere to have scope be removed from the config file or at least commented out and where i can also add in the debug logging and log file location within FreeNAS 11.3+ ?

Thanks again for all the help!
Any auxiliary parameters under LDAP directory service should be appended to the config file.
 

anodos

Sambassador
iXsystems
Joined
Mar 6, 2014
Messages
9,545
Code:
./nslcd/myldap.h:#define LDAP_SCOPE_DEFAULT LDAP_SCOPE_SUBTREE

static void handle_scope(const char *filename, int lnr,
                         const char *keyword, char *line,
                         struct ldap_config *cfg)
{
  char token[32];
  int *var;
  var = scope_get_var(get_map(&line));
  check_argumentcount(filename, lnr, keyword,
                      get_token(&line, token, sizeof(token)) != NULL);
  get_eol(filename, lnr, keyword, &line);
  if (var == NULL)
    var = &cfg->scope;
  if ((strcasecmp(token, "sub") == 0) || (strcasecmp(token, "subtree") == 0))
    *var = LDAP_SCOPE_SUBTREE;
  else if ((strcasecmp(token, "one") == 0) || (strcasecmp(token, "onelevel") == 0))
    *var = LDAP_SCOPE_ONELEVEL;
  else if (strcasecmp(token, "base") == 0)
    *var = LDAP_SCOPE_BASE;
#ifdef LDAP_SCOPE_CHILDREN
  else if (strcasecmp(token, "children") == 0)
    *var = LDAP_SCOPE_CHILDREN;
#endif /* LDAP_SCOPE_CHILDREN */
  else
  {
    log_log(LOG_ERR, "%s:%d: not a scope argument: '%s'",
            filename, lnr, token);
    exit(EXIT_FAILURE);
  }
}


So it seems like commenting out shouldn't actually change the interpreted value. :/
 

jcdfay

Cadet
Joined
Oct 15, 2020
Messages
4
After testing it again several times both with comment out and comment on, eventually hit the same "Can't contact LDAP server" error even though authentication went through fine. I'll submit the thread nslcd log below:

I get some failures like below:

Code:
nslcd: [48089a] <passwd="bob.smith"> ldap_result() failed: Can't contact LDAP server
nslcd: [48089a] <passwd="bob.smith"> DEBUG: set_socket_timeout(5,0)
nslcd: [48089a] <passwd="bob.smith"> DEBUG: ldap_abandon()
nslcd: [48089a] <passwd="bob.smith"> DEBUG: ldap_unbind()
nslcd: [48089a] <passwd="bob.smith"> DEBUG: myldap_get_entry(): retry search
nslcd: [48089a] <passwd="bob.smith"> DEBUG: ldap_initialize(ldap://ldap.jumpcloud.com:389)
nslcd: [48089a] <passwd="bob.smith"> DEBUG: ldap_set_rebind_proc()
nslcd: [48089a] <passwd="bob.smith"> DEBUG: ldap_set_option(LDAP_OPT_PROTOCOL_VERSION,3)
nslcd: [48089a] <passwd="bob.smith"> DEBUG: ldap_set_option(LDAP_OPT_DEREF,0)
nslcd: [48089a] <passwd="bob.smith"> DEBUG: ldap_set_option(LDAP_OPT_TIMELIMIT,10)
nslcd: [48089a] <passwd="bob.smith"> DEBUG: ldap_set_option(LDAP_OPT_TIMEOUT,10)
nslcd: [48089a] <passwd="bob.smith"> DEBUG: ldap_set_option(LDAP_OPT_NETWORK_TIMEOUT,10)
nslcd: [48089a] <passwd="bob.smith"> DEBUG: ldap_set_option(LDAP_OPT_REFERRALS,LDAP_OPT_ON)
nslcd: [48089a] <passwd="bob.smith"> DEBUG: ldap_set_option(LDAP_OPT_RESTART,LDAP_OPT_ON)
nslcd: [48089a] <passwd="bob.smith"> DEBUG: ldap_start_tls_s()
nslcd: [48089a] <passwd="bob.smith"> DEBUG: set_socket_timeout(10,500000)
nslcd: [48089a] <passwd="bob.smith"> DEBUG: ldap_simple_bind_s("uid=<LDAP_BINDDN>,ou=Users,o=<ORGID>,dc=jumpcloud,dc=com","***") (uri="ldap://ldap.jumpcloud.com:389")
nslcd: [48089a] <passwd="bob.smith"> DEBUG: ldap_result(): uid=bob.smith,ou=Users,o=<ORGID>,dc=jumpcloud,dc=com
nslcd: [48089a] <passwd="bob.smith"> (re)loading /etc/nsswitch.conf
nslcd: [48089a] <passwd="bob.smith"> DEBUG: ldap_result(): end of results (1 total)
nslcd: DEBUG: accept() failed (ignored): Resource temporarily unavailable


Then other times it looks to go through with no issues at all:

Code:
nslcd: [00834d] DEBUG: connection from pid=18446744073709551615 uid=0 gid=0
nslcd: [00834d] <passwd="bob.smith"> DEBUG: myldap_search(base="o=<ORGID>,dc=jumpcloud,dc=com", filter="(&(objectClass=posixAccount)(uid=bob.smith))")
nslcd: [00834d] <passwd="bob.smith"> DEBUG: ldap_initialize(ldap://ldap.jumpcloud.com:389)
nslcd: [00834d] <passwd="bob.smith"> DEBUG: ldap_set_rebind_proc()
nslcd: [00834d] <passwd="bob.smith"> DEBUG: ldap_set_option(LDAP_OPT_PROTOCOL_VERSION,3)
nslcd: [00834d] <passwd="bob.smith"> DEBUG: ldap_set_option(LDAP_OPT_DEREF,0)
nslcd: [00834d] <passwd="bob.smith"> DEBUG: ldap_set_option(LDAP_OPT_TIMELIMIT,10)
nslcd: [00834d] <passwd="bob.smith"> DEBUG: ldap_set_option(LDAP_OPT_TIMEOUT,10)
nslcd: [00834d] <passwd="bob.smith"> DEBUG: ldap_set_option(LDAP_OPT_NETWORK_TIMEOUT,10)
nslcd: [00834d] <passwd="bob.smith"> DEBUG: ldap_set_option(LDAP_OPT_REFERRALS,LDAP_OPT_ON)
nslcd: [00834d] <passwd="bob.smith"> DEBUG: ldap_set_option(LDAP_OPT_RESTART,LDAP_OPT_ON)
nslcd: [00834d] <passwd="bob.smith"> DEBUG: ldap_start_tls_s()
nslcd: [00834d] <passwd="bob.smith"> DEBUG: set_socket_timeout(10,500000)
nslcd: [00834d] <passwd="bob.smith"> DEBUG: ldap_simple_bind_s("uid=<LDAP_BINDDN>,ou=Users,o=<ORGID>,dc=jumpcloud,dc=com","***") (uri="ldap://ldap.jumpcloud.com:389")
nslcd: [00834d] <passwd="bob.smith"> DEBUG: ldap_result(): uid=bob.smith,ou=Users,o=<ORGID>,dc=jumpcloud,dc=com
nslcd: [00834d] <passwd="bob.smith"> (re)loading /etc/nsswitch.conf
nslcd: [00834d] <passwd="bob.smith"> DEBUG: ldap_result(): end of results (1 total)
nslcd: [ac75e1] DEBUG: connection from pid=18446744073709551615 uid=0 gid=0
nslcd: [ac75e1] <passwd="bob.smith"> DEBUG: myldap_search(base="o=<ORGID>,dc=jumpcloud,dc=com", filter="(&(objectClass=posixAccount)(uid=bob.smith))")
nslcd: [ac75e1] <passwd="bob.smith"> DEBUG: ldap_initialize(ldap://ldap.jumpcloud.com:389)
nslcd: [ac75e1] <passwd="bob.smith"> DEBUG: ldap_set_rebind_proc()
nslcd: [ac75e1] <passwd="bob.smith"> DEBUG: ldap_set_option(LDAP_OPT_PROTOCOL_VERSION,3)
nslcd: [ac75e1] <passwd="bob.smith"> DEBUG: ldap_set_option(LDAP_OPT_DEREF,0)
nslcd: [ac75e1] <passwd="bob.smith"> DEBUG: ldap_set_option(LDAP_OPT_TIMELIMIT,10)
nslcd: [ac75e1] <passwd="bob.smith"> DEBUG: ldap_set_option(LDAP_OPT_TIMEOUT,10)
nslcd: [ac75e1] <passwd="bob.smith"> DEBUG: ldap_set_option(LDAP_OPT_NETWORK_TIMEOUT,10)
nslcd: [ac75e1] <passwd="bob.smith"> DEBUG: ldap_set_option(LDAP_OPT_REFERRALS,LDAP_OPT_ON)
nslcd: [ac75e1] <passwd="bob.smith"> DEBUG: ldap_set_option(LDAP_OPT_RESTART,LDAP_OPT_ON)
nslcd: [ac75e1] <passwd="bob.smith"> DEBUG: ldap_start_tls_s()
nslcd: [ac75e1] <passwd="bob.smith"> DEBUG: set_socket_timeout(10,500000)
nslcd: [ac75e1] <passwd="bob.smith"> DEBUG: ldap_simple_bind_s("uid=<LDAP_BINDDN>,ou=Users,o=<ORGID>,dc=jumpcloud,dc=com","***") (uri="ldap://ldap.jumpcloud.com:389")
nslcd: [ac75e1] <passwd="bob.smith"> DEBUG: ldap_result(): uid=bob.smith,ou=Users,o=<ORGID>,dc=jumpcloud,dc=com
nslcd: [ac75e1] <passwd="bob.smith"> DEBUG: ldap_result(): end of results (1 total)


It does still authenticate with no issues regardless whether it errors or not, as bob.smith can gain access to the share. I tried changing the scope to the different sets to no avail.
 

jcdfay

Cadet
Joined
Oct 15, 2020
Messages
4
Is anyone else able to repro these issues as well?
I'm seeing two other iXSystems threads with the same issue as well as they're running into something very similar:

 

kyaky

Cadet
Joined
Feb 25, 2021
Messages
2
I can confirm this issue still existed in TrueNAS-12.0-STABLE
simple bind has issue

nslcd: DEBUG: could not open /proc/self/oom_score_adj to adjust the OOM score: No such file or directory
nslcd: DEBUG: unlink() of /var/run/nslcd/nslcd.ctl failed (ignored): No such file or directory
nslcd: accepting connections
nslcd: [00834d] DEBUG: connection from uid=0 gid=0
nslcd: [00834d] <passwd(all)> DEBUG: myldap_search(base="OU=Users,OU=xxx,OU=xxx,OU=xxx,DC=xxx,DC=xxx,DC=xxx,DC=xxx", filter="(objectClass=posixAccount)")
nslcd: [00834d] <passwd(all)> DEBUG: ldap_initialize(ldaps://xxx.xxx.xxx.xxx:636)
nslcd: [00834d] <passwd(all)> DEBUG: ldap_set_rebind_proc()
nslcd: [00834d] <passwd(all)> DEBUG: ldap_set_option(LDAP_OPT_PROTOCOL_VERSION,3)
nslcd: [00834d] <passwd(all)> DEBUG: ldap_set_option(LDAP_OPT_DEREF,0)
nslcd: [00834d] <passwd(all)> DEBUG: ldap_set_option(LDAP_OPT_TIMELIMIT,10)
nslcd: [00834d] <passwd(all)> DEBUG: ldap_set_option(LDAP_OPT_TIMEOUT,10)
nslcd: [00834d] <passwd(all)> DEBUG: ldap_set_option(LDAP_OPT_NETWORK_TIMEOUT,10)
nslcd: [00834d] <passwd(all)> DEBUG: ldap_set_option(LDAP_OPT_REFERRALS,LDAP_OPT_ON)
nslcd: [00834d] <passwd(all)> DEBUG: ldap_set_option(LDAP_OPT_RESTART,LDAP_OPT_ON)
nslcd: [00834d] <passwd(all)> DEBUG: ldap_set_option(LDAP_OPT_X_TLS,LDAP_OPT_X_TLS_HARD)
nslcd: [00834d] <passwd(all)> DEBUG: ldap_simple_bind_s("CN=xxx,OU=xxx,OU=xxx,OU=xxx,OU=xxx,DC=xxx,DC=xxx,DC=xxx,DC=xxx","***") (uri="ldaps://xxx.xxx.xxx.xxx:636
)
nslcd: [00834d] <passwd(all)> DEBUG: set_socket_timeout(10,500000)
nslcd: [00834d] <passwd(all)> DEBUG: ldap_result(): end of results (0 total)
 
Top