Project

General

Profile

Bug #26265

JoiN AD Domain

Added by Carlo 5369 almost 3 years ago. Updated almost 3 years ago.

Status:
Closed: Behaves correctly
Priority:
No priority
Assignee:
Timur Bakeyev
Category:
OS
Target version:
Seen in:
Severity:
New
Reason for Closing:
Reason for Blocked:
Needs QA:
Yes
Needs Doc:
Yes
Needs Merging:
Yes
Needs Automation:
No
Support Suite Ticket:
n/a
Hardware Configuration:
ChangeLog Required:
No

Description

Hi following this topic http://doc.freenas.org/11/directoryservice.html#if-the-system-will-not-join-the-domain
I post my error:

root@freenasRA:~ # sqlite3 /data/freenas-v1.db "update directoryservice_activedirectory set ad_enable=1;"
root@freenasRA:~ # echo $?
0
root@freenasRA:~ # service ix-kerberos start
ERROR: <built-in method set_option of LDAP object at 0x80ff2d940> returned a result with an error set
Traceback (most recent call last):
File "/usr/local/libexec/nas/generate_krb5_conf.py", line 546, in <module>
main()
File "/usr/local/libexec/nas/generate_krb5_conf.py", line 477, in main
timeout=fs().directoryservice.kerberos.timeout.start))
File "/usr/local/lib/python3.6/site-packages/middlewared/client/client.py", line 236, in call
raise ClientException(c.error, c.trace)
middlewared.client.client.ClientException: <built-in method set_option of LDAP object at 0x816c1f1e8> returned a result with an error set
root@freenasRA:~ # service ix-nsswitch start
root@freenasRA:~ # service ix-kinit start
ERROR: <built-in method set_option of LDAP object at 0x80ff2d918> returned a result with an error set
root@freenasRA:~ # service ix-kinit status
ERROR: <built-in method set_option of LDAP object at 0x80ff1f878> returned a result with an error set
root@freenasRA:~ # echo $?
1
root@freenasRA:~ # klist
klist: No ticket file: /tmp/krb5cc_0
root@freenasRA:~ #
root@freenasRA:~ # service ix-sssd start
root@freenasRA:~ # service sssd start
Cannot 'start' sssd. Set sssd_enable to YES in /etc/rc.conf or use 'onestart' instead of 'start'.
root@freenasRA:~ #
root@freenasRA:~ # python /usr/local/www/freenasUI/middleware/notifier.py start cifs
False
root@freenasRA:~ # service ix-activedirectory start
ERROR: <built-in method set_option of LDAP object at 0x80ff2d918> returned a result with an error set
[: -lt: argument expected
[: -lt: argument expected
ERROR: <built-in method set_option of LDAP object at 0x80ff2d968> returned a result with an error set
ERROR: <built-in method set_option of LDAP object at 0x80ff2d918> returned a result with an error set
winbindd not running? (check /var/run/samba/winbindd.pid).
smbd not running? (check /var/run/samba/smbd.pid).
nmbd not running? (check /var/run/samba/nmbd.pid).
root@freenasRA:~ # service ix-activedirectory status
root@freenasRA:~ # echo $?
1
root@freenasRA:~ # python /usr/local/www/freenasUI/middleware/notifier.py restart cifs
False
root@freenasRA:~ # service ix-pam start
root@freenasRA:~ # service ix-cache start &
[1] 65412
root@freenasRA:~ #

History

#1 Updated by Dru Lavigne almost 3 years ago

  • Status changed from Unscreened to 15

Carlo: please attach a debug (System -> Advanced -> Save Debug).

#2 Updated by Carlo 5369 almost 3 years ago

  • File debug-freenasRA-20171019140938.tgz added

Hi,
attached you will find the requested files.
Carlo

#3 Updated by Dru Lavigne almost 3 years ago

  • Private changed from No to Yes

#4 Updated by Dru Lavigne almost 3 years ago

  • Status changed from 15 to Unscreened
  • Assignee changed from Release Council to Timur Bakeyev

Timur: any ideas on what is causing the traceback?

#5 Updated by Dru Lavigne almost 3 years ago

  • Tracker changed from Feature to Bug
  • Target version deleted (11.0-U4)
  • Seen in set to 11.0-U4
  • ChangeLog Required set to No

#6 Updated by Dru Lavigne almost 3 years ago

  • Target version set to 11.2-BETA1

#7 Updated by Timur Bakeyev almost 3 years ago

  • Status changed from Unscreened to 15

Hi, Carlo!

From the logs I see few potential problems:

nameserver 10.34.0.50
nameserver 10.34.0.1

[2017/10/19 06:38:35] (DEBUG) common.freenasldap.get_SRV_records():1151 - FreeNAS_ActiveDirectory_Base.get_SRV_records: looking up SRV records for _ldap._tcp.dc._msdcs.ravennaprocura.mcr
[2017/10/19 06:38:40] (DEBUG) common.freenasldap.get_SRV_records():1170 - FreeNAS_ActiveDirectory_Base.get_SRV_records: no SRV records for _ldap._tcp.dc._ms
dcs.ravennaprocura.mcr found: The DNS operation timed out after 5.046120882034302 seconds
[2017/10/19 06:38:40] (DEBUG) common.freenasldap.log_traceback():12 - Traceback (most recent call last):
[2017/10/19 06:38:40] (DEBUG) common.freenasldap.log_traceback():12 -   File "/usr/local/www/freenasUI/common/freenasldap.py", line 1160, in get_SRV_records
[2017/10/19 06:38:40] (DEBUG) common.freenasldap.log_traceback():12 -     answers = r.query(host, 'SRV')
[2017/10/19 06:38:40] (DEBUG) common.freenasldap.log_traceback():12 -   File "/usr/local/lib/python3.6/site-packages/dns/resolver.py", line 986, in query
[2017/10/19 06:38:40] (DEBUG) common.freenasldap.log_traceback():12 -     timeout = self._compute_timeout(start)
[2017/10/19 06:38:40] (DEBUG) common.freenasldap.log_traceback():12 -   File "/usr/local/lib/python3.6/site-packages/dns/resolver.py", line 805, in _compute_timeout
[2017/10/19 06:38:40] (DEBUG) common.freenasldap.log_traceback():12 -     raise Timeout(timeout=duration)
[2017/10/19 06:38:40] (DEBUG) common.freenasldap.log_traceback():12 - dns.exception.Timeout: The DNS operation timed out after 5.046120882034302 seconds

At least in some cases one of the provided NS servers isn't responding to the SRV queries properly. Please, verify, what is wrong with it.

[2017/10/19 08:25:24] (DEBUG) common.freenasldap.open():277 - FreeNAS_LDAP_Directory.open: enter
[2017/10/19 08:25:24] (DEBUG) common.freenasldap.open():284 - FreeNAS_LDAP_Directory.open: uri = ldaps://mcr0a023.ravennaprocura.mcr:636
[2017/10/19 08:25:24] (DEBUG) common.freenasldap.open():287 - FreeNAS_LDAP_Directory.open: initialized
[2017/10/19 08:25:24] (WARNING) application.call_method():177 - Exception while calling notifier.directoryservice(*['AD'])
ValueError: option error

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/middlewared/main.py", line 163, in call_method
    result = self.middleware.call_method(self, message)
  File "/usr/local/lib/python3.6/site-packages/middlewared/main.py", line 580, in call_method
    return self._call(message['method'], methodobj, params, app=app)
  File "/usr/local/lib/python3.6/site-packages/middlewared/main.py", line 568, in _call
    return methodobj(*args)
  File "/usr/local/lib/python3.6/site-packages/middlewared/plugins/notifier.py", line 124, in directoryservice
    ds = FreeNAS_ActiveDirectory(flags=FLAGS_DBINIT)
  File "/usr/local/www/freenasUI/common/freenasldap.py", line 2443, in __init__
    super(FreeNAS_ActiveDirectory, self).__init__(**kwargs)
  File "/usr/local/www/freenasUI/common/freenasldap.py", line 1555, in __init__
    self.set_servers()
  File "/usr/local/www/freenasUI/common/freenasldap.py", line 1711, in set_servers
    self.dchandle.open()
  File "/usr/local/www/freenasUI/common/freenasldap.py", line 308, in open
    ldap.OPT_X_TLS_DEMAND
  File "/usr/local/lib/python3.6/site-packages/ldap/ldapobject.py", line 823, in set_option
    return self._ldap_call(self._l.set_option,option,invalue)
  File "/usr/local/lib/python3.6/site-packages/ldap/ldapobject.py", line 263, in _ldap_call
    result = func(*args,**kwargs)
SystemError: <built-in method set_option of LDAP object at 0x816c41e68> returned a result with an error set

LDAP connection to AD server tries to establish TLS encrypted channel, but fails on setting this option. Try for the beginning to disable Encryption Mode: by setting it to off and try to re-establish the connection. You can see additional clues in the /var/log/middlewared.log file.

Windows AD in general allows to establish in-encrypted LDAP connections, unless explicitly configured not to. In that case you need to upload corresponding SSL certificate to the FreeNAS server, please consult the documentation how to do it.

#8 Updated by Dru Lavigne almost 3 years ago

  • Status changed from 15 to Closed: Behaves correctly
  • Target version changed from 11.2-BETA1 to N/A
  • Private changed from Yes to No

#9 Updated by Dru Lavigne almost 3 years ago

  • File deleted (debug-freenasRA-20171019140938.tgz)

Also available in: Atom PDF