[TrueNAS 12.0-U2] - Impossible to join AD domain?

sqr00t2

Cadet
Joined
Feb 10, 2021
Messages
4
Hi all,

I've just recently started to use TrueNAS as my OS of choice after decommissioning an old ds214.

I deployed U1 last week and joined our AD domain whitout a hassle. After updating to U2 today, the directory service
entered a failed state and since then it has been impossible to rejoin the domain. What I've tried so far:

- Leaving & Rejoining domain
- Join domain with Domain Admin Account
- Join domain with kerberos principal
- Repeated all steps from above after a system reset

I just can't figure out, what's wrong. After trying to join I see the following Warning in middleware.log:
Code:
[2021/02/10 16:21:02] (DEBUG) ActiveDirectoryService.get_n_working_servers():169 - Request for [2] of server type [DOMAINCONTROLLER] returned: [{'host': 'dc1.corp.domain.com', 'port': 389}, {'host': 'dc2.corp.domain.com', 'port': 389}]
[2021/02/10 16:21:02] (WARNING) ActiveDirectoryService.conn_check():845 - Failed to get DC info from winbindd:
[2021/02/10 16:21:02] (WARNING) ActiveDirectoryService._extend_creds():201 - Failed to initialize secrets for domain [CORP.DOMAIN.COM]. attempting to use credentials from config file.

and the GUI throws a traceback:

Code:
Error: Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/middlewared/plugins/activedirectory.py", line 849, in conn_check
    ret = ActiveDirectory_Conn(conf=data, logger=self.logger).conn_check(dc)
  File "/usr/local/lib/python3.8/site-packages/middlewared/plugins/activedirectory.py", line 227, in conn_check
    netlogon.netlogon(
samba.NTSTATUSError: (3221225485, 'An invalid parameter was passed to a service or function.')

Are there other steps I could take to pinpoint the issue?
Thanks in advance!

cheers, sqr00t2
 

anodos

Sambassador
iXsystems
Joined
Mar 6, 2014
Messages
9,545
Hi all,

I've just recently started to use TrueNAS as my OS of choice after decommissioning an old ds214.

I deployed U1 last week and joined our AD domain whitout a hassle. After updating to U2 today, the directory service
entered a failed state and since then it has been impossible to rejoin the domain. What I've tried so far:

- Leaving & Rejoining domain
- Join domain with Domain Admin Account
- Join domain with kerberos principal
- Repeated all steps from above after a system reset

I just can't figure out, what's wrong. After trying to join I see the following Warning in middleware.log:
Code:
[2021/02/10 16:21:02] (DEBUG) ActiveDirectoryService.get_n_working_servers():169 - Request for [2] of server type [DOMAINCONTROLLER] returned: [{'host': 'dc1.corp.domain.com', 'port': 389}, {'host': 'dc2.corp.domain.com', 'port': 389}]
[2021/02/10 16:21:02] (WARNING) ActiveDirectoryService.conn_check():845 - Failed to get DC info from winbindd:
[2021/02/10 16:21:02] (WARNING) ActiveDirectoryService._extend_creds():201 - Failed to initialize secrets for domain [CORP.DOMAIN.COM]. attempting to use credentials from config file.

and the GUI throws a traceback:

Code:
Error: Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/middlewared/plugins/activedirectory.py", line 849, in conn_check
    ret = ActiveDirectory_Conn(conf=data, logger=self.logger).conn_check(dc)
  File "/usr/local/lib/python3.8/site-packages/middlewared/plugins/activedirectory.py", line 227, in conn_check
    netlogon.netlogon(
samba.NTSTATUSError: (3221225485, 'An invalid parameter was passed to a service or function.')

Are there other steps I could take to pinpoint the issue?
Thanks in advance!

cheers, sqr00t2
Hmm... can you send me a debug? System->Advanced->Save Debug
 

sqr00t2

Cadet
Joined
Feb 10, 2021
Messages
4
Hi,
since I don't want to disclose sensitive information, here is the stripped/anonymized output of the ad dump:
Code:
+--------------------------------------------------------------------------------+
+                      Active Directory Status @1612978553                       +
+--------------------------------------------------------------------------------+
Active Directory is DISABLED
debug finished in 0 seconds for Active Directory Status


+--------------------------------------------------------------------------------+
+                    Active Directory Run Status @1612978553                     +
+--------------------------------------------------------------------------------+
nmbd is not running.
smbd is running as pid 1552.
winbindd is running as pid 1565.
+--------------------------------------------------------------------------------+
+                                   @1612978554                                  +
+--------------------------------------------------------------------------------+
+--------------------------------------------------------------------------------+
+                         SMB Service Status @1612978554                         +
+--------------------------------------------------------------------------------+
SMB will start on boot.
debug finished in 0 seconds for SMB Service Status


+--------------------------------------------------------------------------------+
+                     Active Directory Settings @1612978554                      +
+--------------------------------------------------------------------------------+
{
  "id": 1,
  "domainname": "CORP.DOMAIN.COM",
  "bindname": "nafiler-spn",
  "verbose_logging": true,
  "allow_trusted_doms": true,
  "use_default_domain": true,
  "allow_dns_updates": false,
  "disable_freenas_cache": false,
  "restrict_pam": true,
  "site": "",
  "timeout": 60,
  "dns_timeout": 10,
  "nss_info": "RFC2307",
  "enable": false,
  "kerberos_principal": "",
  "createcomputer": "",
  "kerberos_realm": null,
  "netbiosname": "NAFILER",
  "netbiosalias": []
}
debug finished in 0 seconds for Active Directory Settings


+--------------------------------------------------------------------------------+
+                           /etc/krb5.conf @1612978554                           +
+--------------------------------------------------------------------------------+

debug finished in 0 seconds for /etc/krb5.conf


+--------------------------------------------------------------------------------+
+                         /etc/nsswitch.conf @1612978554                         +
+--------------------------------------------------------------------------------+


group: files
hosts: files dns
networks: files
passwd: files
shells: files
services: files
protocols: files
rpc: files
sudoers: files
debug finished in 0 seconds for /etc/nsswitch.conf


+--------------------------------------------------------------------------------+
+                      /usr/local/etc/smb4.conf @1612978554                      +
+--------------------------------------------------------------------------------+


[global]
        dns proxy = No
        aio max threads = 2
        max log size = 5120
        load printers = No
        printing = bsd
        disable spoolss = Yes
        dos filemode = Yes
        kernel change notify = No
        directory name cache size = 0
        nsupdate command = /usr/local/bin/samba-nsupdate -g
        unix charset = UTF-8
        log level = 2 auth_json_audit:3@/var/log/samba4/auth_audit.log
        obey pam restrictions = False
        enable web service discovery = True
        logging = syslog@2 file
        server min protocol = SMB2_02
        unix extensions = No
        restrict anonymous = 2
        server string = TrueNAS Server
        bind interfaces only = Yes
        netbios name = NAFILER
        netbios aliases =
        server role = standalone
        workgroup = DOMAIN
        idmap config *: backend = tdb
        idmap config *: range = 90000001-100000000
        registry shares = yes
        include = registry
debug finished in 0 seconds for /usr/local/etc/smb4.conf


+--------------------------------------------------------------------------------+
+                   /usr/local/etc/smb4_share.conf @1612978554                   +
+--------------------------------------------------------------------------------+
debug finished in 0 seconds for /usr/local/etc/smb4_share.conf


+--------------------------------------------------------------------------------+
+                     Kerberos Tickets - 'klist' @1612978554                     +
+--------------------------------------------------------------------------------+
Credentials cache: FILE:/tmp/krb5cc_0
        Principal: nafiler-spn@CORP.DOMAIN.COM
        
  Issued                Expires               Principal
Feb 10 18:35:16 2021  Feb 11 04:35:15 2021  krbtgt/CORP.DOMAIN.COM@CORP.DOMAIN.COM
debug finished in 0 seconds for Kerberos Tickets - 'klist'


+--------------------------------------------------------------------------------+
+                   Kerberos Principals - 'ktutil' @1612978554                   +
+--------------------------------------------------------------------------------+
ktutil: krb5_kt_start_seq_get FILE:/etc/krb5.keytab: keytab /etc/krb5.keytab open failed: No such file or directory
debug finished in 0 seconds for Kerberos Principals - 'ktutil'


+--------------------------------------------------------------------------------+
+            Active Directory Trust Secret - 'wbinfo -t' @1612978554             +
+--------------------------------------------------------------------------------+
wbcCheckTrustCredentials(DOMAIN): error code was NT_STATUS_NO_SUCH_DOMAIN (0xc00000df)
failed to call wbcCheckTrustCredentials: WBC_ERR_AUTH_ERROR
Could not check secret
checking the trust secret for domain DOMAIN via RPC calls failed
debug finished in 0 seconds for Active Directory Trust Secret - 'wbinfo -t'


+--------------------------------------------------------------------------------+
+         Active Directory NETLOGON connection - 'wbinfo -P' @1612978554         +
+--------------------------------------------------------------------------------+
failed to call wbcPingDc: WBC_ERR_DOMAIN_NOT_FOUND
checking the NETLOGON for domain[DOMAIN] dc connection to "" failed
debug finished in 0 seconds for Active Directory NETLOGON connection - 'wbinfo -P'


+--------------------------------------------------------------------------------+
+           Active Directory trusted domains - 'wbinfo -m' @1612978554           +
+--------------------------------------------------------------------------------+
Domain Name     DNS Domain                                                       Trust Type  Transitive  In   Out 
BUILTIN                                                                          Local
NAFILER                                                                          Local
debug finished in 0 seconds for Active Directory trusted domains - 'wbinfo -m'


+--------------------------------------------------------------------------------+
+       Active Directory all domains - 'wbinfo --all-domains' @1612978554        +
+--------------------------------------------------------------------------------+
BUILTIN
NAFILER
debug finished in 0 seconds for Active Directory all domains - 'wbinfo --all-domains'


+--------------------------------------------------------------------------------+
+        Active Directory own domain - 'wbinfo --own-domain' @1612978554         +
+--------------------------------------------------------------------------------+
DOMAIN
debug finished in 0 seconds for Active Directory own domain - 'wbinfo --own-domain'


+--------------------------------------------------------------------------------+
+     Active Directory online status - 'wbinfo --online-status' @1612978554      +
+--------------------------------------------------------------------------------+
BUILTIN : active connection
NAFILER : active connection
debug finished in 0 seconds for Active Directory online status - 'wbinfo --online-status'


+--------------------------------------------------------------------------------+
+  Active Directory domain info - 'wbinfo --domain-info=DOMAIN' @1612978554   +
+--------------------------------------------------------------------------------+
failed to call wbcDomainInfo: WBC_ERR_DOMAIN_NOT_FOUND
Could not get domain info
debug finished in 0 seconds for Active Directory domain info - 'wbinfo --domain-info=DOMAIN'


+--------------------------------------------------------------------------------+
+Active Directory DC name - 'wbinfo --dsgetdcname="CORP.DOMAIN.COM"' @1612978554+
+--------------------------------------------------------------------------------+
Could not find dc for "CORP.DOMAIN.COM"
debug finished in 0 seconds for Active Directory DC name - 'wbinfo --dsgetdcname="CORP.DOMAIN.COM"'


+--------------------------------------------------------------------------------+
+      Active Directory DC info - 'wbinfo --dc-info=DOMAIN' @1612978554       +
+--------------------------------------------------------------------------------+
Could not find dc info DOMAIN
debug finished in 0 seconds for Active Directory DC info - 'wbinfo --dc-info=DOMAIN'


+--------------------------------------------------------------------------------+
+                Active Directory Users - 'wbinfo -u' @1612978554                +
+--------------------------------------------------------------------------------+
Error looking up domain users
+--------------------------------------------------------------------------------+
+               Active Directory Groups - 'wbinfo -g' @1612978554                +
+--------------------------------------------------------------------------------+
failed to call wbcListGroups: WBC_ERR_DOMAIN_NOT_FOUND
Error looking up domain groups
debug finished in 0 seconds for Active Directory Groups - 'wbinfo -g'


+--------------------------------------------------------------------------------+
+                     Active Directory SPN list @1612978554                      +
+--------------------------------------------------------------------------------+
[EFAULT] Failed to generate SPN list: [ads_connect: No logon servers are currently available to service the logon request.
ads_connect: No logon servers are currently available to service the logon request.]
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/middlewared/main.py", line 137, in call_method
    result = await self.middleware._call(message['method'], serviceobj, methodobj, params, app=self,
  File "/usr/local/lib/python3.8/site-packages/middlewared/main.py", line 1195, in _call
    return await methodobj(*prepared_call.args)
  File "/usr/local/lib/python3.8/site-packages/middlewared/schema.py", line 973, in nf
    return await f(*args, **kwargs)
  File "/usr/local/lib/python3.8/site-packages/middlewared/plugins/activedirectory.py", line 1036, in get_spn_list
    raise CallError(
middlewared.service_exception.CallError: [EFAULT] Failed to generate SPN list: [ads_connect: No logon servers are currently available to service the logon request.
ads_connect: No logon servers are currently available to service the logon request.]

debug finished in 2 seconds for Active Directory SPN list


+--------------------------------------------------------------------------------+
+                           idmap settings @1612978556                           +
+--------------------------------------------------------------------------------+
[
  {
    "id": 1,
    "name": "DS_TYPE_ACTIVEDIRECTORY",
    "dns_domain_name": null,
    "range_low": 100000001,
    "range_high": 200000000,
    "idmap_backend": "RID",
    "options": {},
    "certificate": null
  },
  {
    "id": 2,
    "name": "DS_TYPE_LDAP",
    "dns_domain_name": null,
    "range_low": 10000,
    "range_high": 90000000,
    "idmap_backend": "LDAP",
    "options": {
      "ldap_base_dn": "",
      "ldap_user_dn": "",
      "ldap_url": "",
      "ssl": "OFF"
    },
    "certificate": null
  },
  {
    "id": 5,
    "name": "DS_TYPE_DEFAULT_DOMAIN",
    "dns_domain_name": null,
    "range_low": 90000001,
    "range_high": 100000000,
    "idmap_backend": "TDB",
    "options": {},
    "certificate": null
  }
]
debug finished in 0 seconds for idmap settings

Does this help for a first shot?
 

anodos

Sambassador
iXsystems
Joined
Mar 6, 2014
Messages
9,545
Looks like it's stuck halfway-configured. Can you at least send me contents of /var/log/middlewared.log? It might be worth explicitly leaving the domain (advanced option) and then rejoining. This will wipe some caches and our stored secret that seems to be no longer effective.
 

TheUsD

Contributor
Joined
May 17, 2013
Messages
116
Just piggy backing off this thread and sorry not trying to hijack but I am also getting the same issue but the cause was different.
I disjoined the domain to rename my device. After that I couldn't join back. Won't post for credentials, just gives me the error below. This was on 12.0-U1 and still continues on 12.0-U2

Code:
Error: Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/middlewared/plugins/activedirectory.py", line 760, in validate_credentials
    self.middleware.call_sync('kerberos.do_kinit', data)
  File "/usr/local/lib/python3.8/site-packages/middlewared/main.py", line 1254, in call_sync
    return self.run_coroutine(methodobj(*prepared_call.args))
  File "/usr/local/lib/python3.8/site-packages/middlewared/main.py", line 1294, in run_coroutine
    return fut.result()
  File "/usr/local/lib/python3.8/concurrent/futures/_base.py", line 432, in result
    return self.__get_result()
  File "/usr/local/lib/python3.8/concurrent/futures/_base.py", line 388, in __get_result
    raise self._exception
  File "/usr/local/lib/python3.8/site-packages/middlewared/plugins/kerberos.py", line 269, in do_kinit
    raise CallError(f"kinit for domain [{data['domainname']}] "
middlewared.service_exception.CallError: [EFAULT] kinit for domain [DOMAIN.COM] with principal [OldDeviceName$@DOMAIN.COM] failed: kinit: krb5_get_init_creds: Client (OldDeviceName$@DOMAIN.com) unknown
 

sqr00t2

Cadet
Joined
Feb 10, 2021
Messages
4
Looks like it's stuck halfway-configured. Can you at least send me contents of /var/log/middlewared.log? It might be worth explicitly leaving the domain (advanced option) and then rejoining. This will wipe some caches and our stored secret that seems to be no longer effective.
Sure, this is middleware log just after a reboot and a domain join attempt:
Code:
[2021/02/11 07:30:05] (INFO) middlewared.__init__():792 - Starting TrueNAS-12.0-U2 middleware
[2021/02/11 08:30:14] (DEBUG) middlewared.setup():1639 - Timezone set to Europe/Berlin
[2021/02/11 08:30:17] (WARNING) middlewared._loop_monitor_thread():1415 - Task seems blocked:
  File "<frozen importlib._bootstrap>", line 671, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 783, in exec_module
  File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed
  File "/usr/local/lib/python3.8/site-packages/pysnmp/carrier/asyncore/dgram/base.py", line 10, in <module>
    from pysnmp.carrier.asyncore.base import AbstractSocketTransport
  File "<frozen importlib._bootstrap>", line 991, in _find_and_load
  File "<frozen importlib._bootstrap>", line 975, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 671, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 779, in exec_module
  File "<frozen importlib._bootstrap_external>", line 874, in get_code
  File "<frozen importlib._bootstrap_external>", line 973, in get_data

[2021/02/11 08:30:19] (WARNING) middlewared._loop_monitor_thread():1415 - Task seems blocked:
  File "<frozen importlib._bootstrap>", line 671, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 783, in exec_module
  File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed
  File "/usr/local/lib/python3.8/site-packages/Cryptodome/Hash/SHA1.py", line 29, in <module>
    _raw_sha1_lib = load_pycryptodome_raw_lib("Cryptodome.Hash._SHA1",
  File "/usr/local/lib/python3.8/site-packages/Cryptodome/Util/_raw_api.py", line 296, in load_pycryptodome_raw_lib
    return load_lib(pycryptodome_filename(dir_comps, filename),
  File "/usr/local/lib/python3.8/site-packages/Cryptodome/Util/_raw_api.py", line 102, in load_lib
    lib = ffi.dlopen(name)
  File "/usr/local/lib/python3.8/site-packages/cffi/api.py", line 150, in dlopen
    lib, function_cache = _make_ffi_library(self, name, flags)
  File "/usr/local/lib/python3.8/site-packages/cffi/api.py", line 832, in _make_ffi_library
    backendlib = _load_backend_lib(backend, libname, flags)
  File "/usr/local/lib/python3.8/site-packages/cffi/api.py", line 818, in _load_backend_lib
    path = ctypes.util.find_library(name)
  File "/usr/local/lib/python3.8/ctypes/util.py", line 206, in find_library
    data = proc.stdout.read()

[2021/02/11 08:30:21] (WARNING) middlewared._loop_monitor_thread():1415 - Task seems blocked:
  File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed
  File "/usr/local/lib/python3.8/site-packages/Cryptodome/Cipher/AES.py", line 66, in <module>
    _raw_aes_lib = load_pycryptodome_raw_lib("Cryptodome.Cipher._raw_aes",
  File "/usr/local/lib/python3.8/site-packages/Cryptodome/Util/_raw_api.py", line 296, in load_pycryptodome_raw_lib
    return load_lib(pycryptodome_filename(dir_comps, filename),
  File "/usr/local/lib/python3.8/site-packages/Cryptodome/Util/_raw_api.py", line 102, in load_lib
    lib = ffi.dlopen(name)
  File "/usr/local/lib/python3.8/site-packages/cffi/api.py", line 150, in dlopen
    lib, function_cache = _make_ffi_library(self, name, flags)
  File "/usr/local/lib/python3.8/site-packages/cffi/api.py", line 832, in _make_ffi_library
    backendlib = _load_backend_lib(backend, libname, flags)
  File "/usr/local/lib/python3.8/site-packages/cffi/api.py", line 818, in _load_backend_lib
    path = ctypes.util.find_library(name)
  File "/usr/local/lib/python3.8/ctypes/util.py", line 199, in find_library
    proc = subprocess.Popen(('/sbin/ldconfig', '-r'),
  File "/usr/local/lib/python3.8/subprocess.py", line 854, in __init__
    self._execute_child(args, executable, preexec_fn, close_fds,
  File "/usr/local/lib/python3.8/subprocess.py", line 1658, in _execute_child
    part = os.read(errpipe_read, 50000)

[2021/02/11 08:30:25] (DEBUG) middlewared.setup():2835 - Certificate setup for System complete
[2021/02/11 08:30:30] (INFO) middlewared.devd_listen():58 - devd connection established
[2021/02/11 08:30:31] (DEBUG) middlewared.__plugins_setup():907 - All plugins loaded
[2021/02/11 08:30:31] (DEBUG) middlewared.__initialize():1499 - Accepting connections
[2021/02/11 08:30:32] (INFO) DiskService.sync_all():94 - Found disks: {'ada4': {'name': 'ada4', 'ident': 'FF73074A0F0800757474', 'lunid': None, 'serial': 'FF73074A0F0800757474'}, 'ada3': {'name': 'ada3', 'ident': 'WD-WCC4J3304069', 'lunid': '50014ee25f4d194e', 'serial': 'WD-WCC4J3304069'}, 'ada2': {'name': 'ada2', 'ident': 'WD-WCC4J3324157', 'lunid': '50014ee25f4d5063', 'serial': 'WD-WCC4J3324157'}, 'ada1': {'name': 'ada1', 'ident': 'WD-WCC4J3UPHZXP', 'lunid': '50014ee2b712a30f', 'serial': 'WD-WCC4J3UPHZXP'}, 'ada0': {'name': 'ada0', 'ident': 'WD-WCC4J5YEDYEJ', 'lunid': '50014ee20c678774', 'serial': 'WD-WCC4J5YEDYEJ'}}
[2021/02/11 08:30:38] (DEBUG) EtcService.generate():378 - No new changes for /etc/krb5.conf
[2021/02/11 08:30:39] (WARNING) builtins.add_bind_interfaces():116 - IP address [10.19.42.40] is no longer in use and should be removed from SMB configuration.
[2021/02/11 08:30:40] (DEBUG) EtcService.generate():378 - No new changes for /etc/pam.d/sshd
[2021/02/11 08:30:40] (DEBUG) EtcService.generate():329 - mako:local/users.oath file removed.
[2021/02/11 08:30:40] (DEBUG) EtcService.generate():329 - mako:local/openvpn/server/openvpn_server.conf file removed.
[2021/02/11 08:30:40] (DEBUG) EtcService.generate():329 - mako:local/openvpn/client/openvpn_client.conf file removed.
[2021/02/11 08:30:40] (DEBUG) EtcService.generate():329 - mako:wireguard/wg0.conf file removed.
[2021/02/11 08:30:44] (DEBUG) middlewared.dumpdev_configure():24 - Configured "/dev/ada3p1" device for crash dumps.
[2021/02/11 08:30:46] (WARNING) builtins.add_bind_interfaces():116 - IP address [10.19.42.40] is no longer in use and should be removed from SMB configuration.
[2021/02/11 08:30:46] (DEBUG) EtcService.generate():378 - No new changes for /etc/local/smb4.conf
[2021/02/11 08:30:46] (DEBUG) EtcService.generate():378 - No new changes for /etc/local/smbusername.map
[2021/02/11 08:30:47] (DEBUG) EtcService.generate():378 - No new changes for /etc/group
[2021/02/11 08:30:47] (DEBUG) EtcService.generate():378 - No new changes for /etc/security/pam_winbind.conf
[2021/02/11 08:30:48] (DEBUG) EtcService.generate():378 - No new changes for /etc/master.passwd
[2021/02/11 08:30:49] (DEBUG) EtcService.generate():378 - No new changes for /etc/local/proftpd.conf
[2021/02/11 08:30:49] (DEBUG) EtcService.generate():378 - No new changes for /etc/local/apache24/httpd.conf
[2021/02/11 08:30:50] (DEBUG) EtcService.generate():378 - No new changes for /etc/local/apache24/Includes/webdav.conf
[2021/02/11 08:30:50] (DEBUG) EtcService.generate():378 - No new changes for /etc/local/smb4_share.conf
[2021/02/11 08:30:50] (DEBUG) middlewared.interface_pre_sync_hook():1525 - No HA hardware detected, skipping interfaces setup.
[2021/02/11 08:30:50] (INFO) InterfaceService.lag_setup():13 - Setting up lagg0
[2021/02/11 08:30:50] (INFO) InterfaceService.lag_setup():35 - lagg0: changing protocol to 4
[2021/02/11 08:30:51] (DEBUG) InterfaceService.configure():159 - lagg0: adding 10.19.42.40/255.255.252.0
[2021/02/11 08:30:51] (INFO) InterfaceService.sync():1839 - Interfaces in database: lagg0
[2021/02/11 08:30:51] (DEBUG) EtcService.generate():378 - No new changes for /etc/dhclient.conf
[2021/02/11 08:30:53] (DEBUG) EtcService.generate():378 - No new changes for /etc/nsswitch.conf
[2021/02/11 08:30:53] (DEBUG) EtcService.generate():378 - No new changes for /etc/local/nslcd.conf
[2021/02/11 08:30:54] (DEBUG) EtcService.generate():378 - No new changes for /etc/krb5.conf
[2021/02/11 08:30:57] (DEBUG) EtcService.generate():378 - No new changes for /etc/krb5.conf
[2021/02/11 08:30:57] (DEBUG) EtcService.generate():378 - No new changes for /etc/krb5.conf
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task alert.flush_alerts to run every 3600 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task alert.process_alerts to run every 60 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task certificate.renew_certs to run every 86400 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task certificateauthority.crl_generation to run every 86400 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task kerberos.keytab.check_updated_keytab to run every 3600 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task kmip.sync_keys to run every 86400 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task mail.send_mail_queue to run every 600 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task plugin.periodic_plugin_update to run every 86400 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task plugin.retrieve_versions_for_repos to run every 86400 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task pool.dataset.sync_db_keys to run every 86400 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task smb.sharesec.check_share_info_tdb to run every 3600 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task truecommand.health_check to run every 1800 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task zettarepl.flush_state to run every 3600 seconds
[2021/02/11 08:30:58] (DEBUG) JailService.start_on_boot():1624 - Starting jails on boot: PENDING
[2021/02/11 08:30:59] (DEBUG) JailService.start_on_boot():1626 - Starting jails on boot: SUCCESS
[2021/02/11 08:30:59] (ERROR) iocage.callback():67 - Failed to update git repository: fatal: unable to access 'https://github.com/ix-plugin-hub/iocage-plugin-index.git/': Could not resolve host: github.com

[2021/02/11 08:30:59] (ERROR) iocage.callback():67 - Not cloning https://github.com/ix-plugin-hub/iocage-plugin-index.gitas git-pull failed due to network issues.
[2021/02/11 08:31:00] (DEBUG) urllib3.connectionpool._new_conn():221 - Starting new HTTP connection (1): pkg.freebsd.org:80
[2021/02/11 08:31:00] (DEBUG) urllib3.connectionpool._new_conn():221 - Starting new HTTP connection (1): pkg.cdn.trueos.org:80
[2021/02/11 08:31:00] (DEBUG) urllib3.connectionpool._new_conn():221 - Starting new HTTP connection (1): pkg.freebsd.org:80
[2021/02/11 08:31:00] (DEBUG) urllib3.connectionpool._new_conn():221 - Starting new HTTP connection (1): pkg.freebsd.org:80
[2021/02/11 08:31:00] (DEBUG) urllib3.connectionpool._new_conn():221 - Starting new HTTP connection (1): pkg.cdn.trueos.org:80
[2021/02/11 08:31:15] (ERROR) iocage.callback():67 - Failed to update git repository: fatal: unable to access 'https://github.com/freenas/iocage-ix-plugins.git/': Could not resolve host: github.com

[2021/02/11 08:31:15] (ERROR) iocage.callback():67 - Not cloning https://github.com/freenas/iocage-ix-plugins.gitas git-pull failed due to network issues.
[2021/02/11 08:31:15] (DEBUG) urllib3.connectionpool._new_conn():221 - Starting new HTTP connection (1): pkg.freebsd.org:80
[2021/02/11 08:31:15] (DEBUG) urllib3.connectionpool._new_conn():221 - Starting new HTTP connection (1): pkg.freebsd.org:80
[2021/02/11 08:31:15] (DEBUG) urllib3.connectionpool._new_conn():221 - Starting new HTTP connection (1): pkg.cdn.trueos.org:80
[2021/02/11 08:31:15] (DEBUG) urllib3.connectionpool._new_conn():221 - Starting new HTTP connection (1): download.truenas.com:80
[2021/02/11 08:31:15] (DEBUG) urllib3.connectionpool._make_request():428 - http://pkg.cdn.trueos.org:80 "GET /iocage/unstable/packagesite.txz HTTP/1.1" 200 302704
[2021/02/11 08:31:15] (DEBUG) urllib3.connectionpool._make_request():428 - http://pkg.freebsd.org:80 "GET /FreeBSD:12:amd64/latest/packagesite.txz HTTP/1.1" 200 6412488
[2021/02/11 08:31:15] (DEBUG) urllib3.connectionpool._make_request():428 - http://pkg.freebsd.org:80 "GET /FreeBSD:12:amd64/latest/packagesite.txz HTTP/1.1" 200 6412488
[2021/02/11 08:31:15] (DEBUG) urllib3.connectionpool._make_request():428 - http://download.truenas.com:80 "GET /plugins/asigra/stable/11.3-RELEASE/packagesite.txz HTTP/1.1" 200 16472
[2021/02/11 08:59:16] (DEBUG) urllib3.connectionpool._new_conn():955 - Starting new HTTPS connection (1): update-master.ixsystems.com:443
[2021/02/11 08:59:22] (WARNING) UpdateService.get_trains_data():102 - Failed to retrieve trains redirection
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/urllib3/connection.py", line 156, in _new_conn
    conn = connection.create_connection(
  File "/usr/local/lib/python3.8/site-packages/urllib3/util/connection.py", line 84, in create_connection
    raise err
  File "/usr/local/lib/python3.8/site-packages/urllib3/util/connection.py", line 74, in create_connection
    sock.connect(sa)
socket.timeout: timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/urllib3/connectionpool.py", line 665, in urlopen
    httplib_response = self._make_request(
  File "/usr/local/lib/python3.8/site-packages/urllib3/connectionpool.py", line 376, in _make_request
    self._validate_conn(conn)
  File "/usr/local/lib/python3.8/site-packages/urllib3/connectionpool.py", line 994, in _validate_conn
    conn.connect()
  File "/usr/local/lib/python3.8/site-packages/urllib3/connection.py", line 334, in connect
    conn = self._new_conn()
  File "/usr/local/lib/python3.8/site-packages/urllib3/connection.py", line 161, in _new_conn
    raise ConnectTimeoutError(
urllib3.exceptions.ConnectTimeoutError: (<urllib3.connection.VerifiedHTTPSConnection object at 0x81eba5cd0>, 'Connection to update-master.ixsystems.com timed out. (connect timeout=5)')

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/requests/adapters.py", line 439, in send
    resp = conn.urlopen(
  File "/usr/local/lib/python3.8/site-packages/urllib3/connectionpool.py", line 719, in urlopen
    retries = retries.increment(
  File "/usr/local/lib/python3.8/site-packages/urllib3/util/retry.py", line 436, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='update-master.ixsystems.com', port=443): Max retries exceeded with url: /TrueNAS/trains_redir.json (Caused by ConnectTimeoutError(<urllib3.connection.VerifiedHTTPSConnection object at 0x81eba5cd0>, 'Connection to update-master.ixsystems.com timed out. (connect timeout=5)'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/middlewared/plugins/update_/trains_freebsd.py", line 100, in get_trains_data
    redir_trains = self._get_redir_trains()
  File "/usr/local/lib/python3.8/site-packages/middlewared/plugins/update_/trains_freebsd.py", line 141, in _get_redir_trains
    r = requests.get(
  File "/usr/local/lib/python3.8/site-packages/requests/api.py", line 75, in get
    return request('get', url, params=params, **kwargs)
  File "/usr/local/lib/python3.8/site-packages/requests/api.py", line 60, in request
    return session.request(method=method, url=url, **kwargs)
  File "/usr/local/lib/python3.8/site-packages/requests/sessions.py", line 533, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/local/lib/python3.8/site-packages/requests/sessions.py", line 646, in send
    r = adapter.send(request, **kwargs)
  File "/usr/local/lib/python3.8/site-packages/requests/adapters.py", line 504, in send
    raise ConnectTimeout(e, request=request)
requests.exceptions.ConnectTimeout: HTTPSConnectionPool(host='update-master.ixsystems.com', port=443): Max retries exceeded with url: /TrueNAS/trains_redir.json (Caused by ConnectTimeoutError(<urllib3.connection.VerifiedHTTPSConnection object at 0x81eba5cd0>, 'Connection to update-master.ixsystems.com timed out. (connect timeout=5)'))
[2021/02/11 08:59:22] (DEBUG) freenasOS.Configuration.TryGetNetworkFile():606 - TryGetNetworkFile(['https://update.ixsystems.com/TrueNAS/trains.txt', 'https://update-master.ixsystems.com/TrueNAS/trains.txt'])
[2021/02/11 08:59:22] (DEBUG) urllib3.connectionpool._new_conn():955 - Starting new HTTPS connection (1): update.ixsystems.com:443
[2021/02/11 08:59:23] (DEBUG) urllib3.connectionpool._make_request():428 - https://update.ixsystems.com:443 "GET /TrueNAS/trains.txt HTTP/1.1" 301 169
[2021/02/11 08:59:23] (DEBUG) urllib3.connectionpool._new_conn():955 - Starting new HTTPS connection (1): update.freenas.org:443
[2021/02/11 08:59:23] (DEBUG) urllib3.connectionpool._make_request():428 - https://update.freenas.org:443 "GET /TrueNAS/trains.txt HTTP/1.1" 200 377
[2021/02/11 08:59:23] (DEBUG) freenasOS.Configuration.TryGetNetworkFile():745 - TryGetNetworkFile(['https://update.ixsystems.com/TrueNAS/trains.txt', 'https://update-master.ixsystems.com/TrueNAS/trains.txt']):  Read 377 bytes total
[2021/02/11 08:59:23] (DEBUG) freenasOS.Configuration.TryGetNetworkFile():606 - TryGetNetworkFile(['https://update-master.ixsystems.com/TrueNAS/TrueNAS-12.0-STABLE/LATEST'])
[2021/02/11 08:59:23] (DEBUG) urllib3.connectionpool._new_conn():955 - Starting new HTTPS connection (1): update-master.ixsystems.com:443
[2021/02/11 08:59:23] (DEBUG) urllib3.connectionpool._make_request():428 - https://update-master.ixsystems.com:443 "GET /TrueNAS/TrueNAS-12.0-STABLE/LATEST HTTP/1.1" 200 1602
[2021/02/11 08:59:23] (DEBUG) freenasOS.Configuration.TryGetNetworkFile():745 - TryGetNetworkFile(['https://update-master.ixsystems.com/TrueNAS/TrueNAS-12.0-STABLE/LATEST']):  Read 1602 bytes total
[2021/02/11 08:59:23] (DEBUG) freenasOS.Configuration.TryGetNetworkFile():606 - TryGetNetworkFile(['https://update-master.ixsystems.com/updates/ix_crl.pem'])
[2021/02/11 08:59:23] (DEBUG) urllib3.connectionpool._new_conn():955 - Starting new HTTPS connection (1): update-master.ixsystems.com:443
[2021/02/11 08:59:24] (DEBUG) urllib3.connectionpool._make_request():428 - https://update-master.ixsystems.com:443 "GET /updates/ix_crl.pem HTTP/1.1" 200 1028
[2021/02/11 08:59:24] (DEBUG) freenasOS.Configuration.CheckFreeSpace():77 - CheckFreeSpace(path=/tmp/tmp8khzpzq0.pem, pool=None, required=1028)
[2021/02/11 08:59:24] (DEBUG) freenasOS.Configuration.TryGetNetworkFile():745 - TryGetNetworkFile(['https://update-master.ixsystems.com/updates/ix_crl.pem']):  Read 1028 bytes total
[2021/02/11 08:59:24] (DEBUG) freenasOS.Configuration.TryGetNetworkFile():606 - TryGetNetworkFile(['https://update.ixsystems.com/TrueNAS/Validators/ValidateUpdate-mg3ef525.txt', 'https://update-master.ixsystems.com/TrueNAS/Validators/ValidateUpdate-mg3ef525.txt'])
[2021/02/11 08:59:24] (DEBUG) urllib3.connectionpool._new_conn():955 - Starting new HTTPS connection (1): update.ixsystems.com:443
[2021/02/11 08:59:25] (DEBUG) urllib3.connectionpool._make_request():428 - https://update.ixsystems.com:443 "GET /TrueNAS/Validators/ValidateUpdate-mg3ef525.txt HTTP/1.1" 301 169
[2021/02/11 08:59:25] (DEBUG) urllib3.connectionpool._new_conn():955 - Starting new HTTPS connection (1): update.freenas.org:443
[2021/02/11 08:59:25] (DEBUG) urllib3.connectionpool._make_request():428 - https://update.freenas.org:443 "GET /TrueNAS/Validators/ValidateUpdate-mg3ef525.txt HTTP/1.1" 200 185
[2021/02/11 08:59:25] (DEBUG) freenasOS.Configuration.CheckFreeSpace():77 - CheckFreeSpace(path=/tmp/tmp2ihmflkk, pool=None, required=185)
[2021/02/11 08:59:25] (DEBUG) freenasOS.Configuration.TryGetNetworkFile():745 - TryGetNetworkFile(['https://update.ixsystems.com/TrueNAS/Validators/ValidateUpdate-mg3ef525.txt', 'https://update-master.ixsystems.com/TrueNAS/Validators/ValidateUpdate-mg3ef525.txt']):  Read 185 bytes total
[2021/02/11 09:01:48] (DEBUG) ActiveDirectoryService.get_n_working_servers():169 - Request for [2] of server type [DOMAINCONTROLLER] returned: [{'host': 'dc2.corp.DOMAIN.com', 'port': 389}, {'host': 'dc1.corp.DOMAIN.com', 'port': 389}]
[2021/02/11 09:01:48] (WARNING) ActiveDirectoryService.conn_check():845 - Failed to get DC info from winbindd:
[2021/02/11 09:01:48] (WARNING) ActiveDirectoryService._extend_creds():201 - Failed to initialize secrets for domain [CORP.DOMAIN.COM]. attempting to use credentials from config file.

The option to leave the domain is not available, probably due to the failed join attempt. Is there a way to do it from the shell?

cheers
 

anodos

Sambassador
iXsystems
Joined
Mar 6, 2014
Messages
9,545
Sure, this is middleware log just after a reboot and a domain join attempt:
Code:
[2021/02/11 07:30:05] (INFO) middlewared.__init__():792 - Starting TrueNAS-12.0-U2 middleware
[2021/02/11 08:30:14] (DEBUG) middlewared.setup():1639 - Timezone set to Europe/Berlin
[2021/02/11 08:30:17] (WARNING) middlewared._loop_monitor_thread():1415 - Task seems blocked:
  File "<frozen importlib._bootstrap>", line 671, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 783, in exec_module
  File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed
  File "/usr/local/lib/python3.8/site-packages/pysnmp/carrier/asyncore/dgram/base.py", line 10, in <module>
    from pysnmp.carrier.asyncore.base import AbstractSocketTransport
  File "<frozen importlib._bootstrap>", line 991, in _find_and_load
  File "<frozen importlib._bootstrap>", line 975, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 671, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 779, in exec_module
  File "<frozen importlib._bootstrap_external>", line 874, in get_code
  File "<frozen importlib._bootstrap_external>", line 973, in get_data

[2021/02/11 08:30:19] (WARNING) middlewared._loop_monitor_thread():1415 - Task seems blocked:
  File "<frozen importlib._bootstrap>", line 671, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 783, in exec_module
  File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed
  File "/usr/local/lib/python3.8/site-packages/Cryptodome/Hash/SHA1.py", line 29, in <module>
    _raw_sha1_lib = load_pycryptodome_raw_lib("Cryptodome.Hash._SHA1",
  File "/usr/local/lib/python3.8/site-packages/Cryptodome/Util/_raw_api.py", line 296, in load_pycryptodome_raw_lib
    return load_lib(pycryptodome_filename(dir_comps, filename),
  File "/usr/local/lib/python3.8/site-packages/Cryptodome/Util/_raw_api.py", line 102, in load_lib
    lib = ffi.dlopen(name)
  File "/usr/local/lib/python3.8/site-packages/cffi/api.py", line 150, in dlopen
    lib, function_cache = _make_ffi_library(self, name, flags)
  File "/usr/local/lib/python3.8/site-packages/cffi/api.py", line 832, in _make_ffi_library
    backendlib = _load_backend_lib(backend, libname, flags)
  File "/usr/local/lib/python3.8/site-packages/cffi/api.py", line 818, in _load_backend_lib
    path = ctypes.util.find_library(name)
  File "/usr/local/lib/python3.8/ctypes/util.py", line 206, in find_library
    data = proc.stdout.read()

[2021/02/11 08:30:21] (WARNING) middlewared._loop_monitor_thread():1415 - Task seems blocked:
  File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed
  File "/usr/local/lib/python3.8/site-packages/Cryptodome/Cipher/AES.py", line 66, in <module>
    _raw_aes_lib = load_pycryptodome_raw_lib("Cryptodome.Cipher._raw_aes",
  File "/usr/local/lib/python3.8/site-packages/Cryptodome/Util/_raw_api.py", line 296, in load_pycryptodome_raw_lib
    return load_lib(pycryptodome_filename(dir_comps, filename),
  File "/usr/local/lib/python3.8/site-packages/Cryptodome/Util/_raw_api.py", line 102, in load_lib
    lib = ffi.dlopen(name)
  File "/usr/local/lib/python3.8/site-packages/cffi/api.py", line 150, in dlopen
    lib, function_cache = _make_ffi_library(self, name, flags)
  File "/usr/local/lib/python3.8/site-packages/cffi/api.py", line 832, in _make_ffi_library
    backendlib = _load_backend_lib(backend, libname, flags)
  File "/usr/local/lib/python3.8/site-packages/cffi/api.py", line 818, in _load_backend_lib
    path = ctypes.util.find_library(name)
  File "/usr/local/lib/python3.8/ctypes/util.py", line 199, in find_library
    proc = subprocess.Popen(('/sbin/ldconfig', '-r'),
  File "/usr/local/lib/python3.8/subprocess.py", line 854, in __init__
    self._execute_child(args, executable, preexec_fn, close_fds,
  File "/usr/local/lib/python3.8/subprocess.py", line 1658, in _execute_child
    part = os.read(errpipe_read, 50000)

[2021/02/11 08:30:25] (DEBUG) middlewared.setup():2835 - Certificate setup for System complete
[2021/02/11 08:30:30] (INFO) middlewared.devd_listen():58 - devd connection established
[2021/02/11 08:30:31] (DEBUG) middlewared.__plugins_setup():907 - All plugins loaded
[2021/02/11 08:30:31] (DEBUG) middlewared.__initialize():1499 - Accepting connections
[2021/02/11 08:30:32] (INFO) DiskService.sync_all():94 - Found disks: {'ada4': {'name': 'ada4', 'ident': 'FF73074A0F0800757474', 'lunid': None, 'serial': 'FF73074A0F0800757474'}, 'ada3': {'name': 'ada3', 'ident': 'WD-WCC4J3304069', 'lunid': '50014ee25f4d194e', 'serial': 'WD-WCC4J3304069'}, 'ada2': {'name': 'ada2', 'ident': 'WD-WCC4J3324157', 'lunid': '50014ee25f4d5063', 'serial': 'WD-WCC4J3324157'}, 'ada1': {'name': 'ada1', 'ident': 'WD-WCC4J3UPHZXP', 'lunid': '50014ee2b712a30f', 'serial': 'WD-WCC4J3UPHZXP'}, 'ada0': {'name': 'ada0', 'ident': 'WD-WCC4J5YEDYEJ', 'lunid': '50014ee20c678774', 'serial': 'WD-WCC4J5YEDYEJ'}}
[2021/02/11 08:30:38] (DEBUG) EtcService.generate():378 - No new changes for /etc/krb5.conf
[2021/02/11 08:30:39] (WARNING) builtins.add_bind_interfaces():116 - IP address [10.19.42.40] is no longer in use and should be removed from SMB configuration.
[2021/02/11 08:30:40] (DEBUG) EtcService.generate():378 - No new changes for /etc/pam.d/sshd
[2021/02/11 08:30:40] (DEBUG) EtcService.generate():329 - mako:local/users.oath file removed.
[2021/02/11 08:30:40] (DEBUG) EtcService.generate():329 - mako:local/openvpn/server/openvpn_server.conf file removed.
[2021/02/11 08:30:40] (DEBUG) EtcService.generate():329 - mako:local/openvpn/client/openvpn_client.conf file removed.
[2021/02/11 08:30:40] (DEBUG) EtcService.generate():329 - mako:wireguard/wg0.conf file removed.
[2021/02/11 08:30:44] (DEBUG) middlewared.dumpdev_configure():24 - Configured "/dev/ada3p1" device for crash dumps.
[2021/02/11 08:30:46] (WARNING) builtins.add_bind_interfaces():116 - IP address [10.19.42.40] is no longer in use and should be removed from SMB configuration.
[2021/02/11 08:30:46] (DEBUG) EtcService.generate():378 - No new changes for /etc/local/smb4.conf
[2021/02/11 08:30:46] (DEBUG) EtcService.generate():378 - No new changes for /etc/local/smbusername.map
[2021/02/11 08:30:47] (DEBUG) EtcService.generate():378 - No new changes for /etc/group
[2021/02/11 08:30:47] (DEBUG) EtcService.generate():378 - No new changes for /etc/security/pam_winbind.conf
[2021/02/11 08:30:48] (DEBUG) EtcService.generate():378 - No new changes for /etc/master.passwd
[2021/02/11 08:30:49] (DEBUG) EtcService.generate():378 - No new changes for /etc/local/proftpd.conf
[2021/02/11 08:30:49] (DEBUG) EtcService.generate():378 - No new changes for /etc/local/apache24/httpd.conf
[2021/02/11 08:30:50] (DEBUG) EtcService.generate():378 - No new changes for /etc/local/apache24/Includes/webdav.conf
[2021/02/11 08:30:50] (DEBUG) EtcService.generate():378 - No new changes for /etc/local/smb4_share.conf
[2021/02/11 08:30:50] (DEBUG) middlewared.interface_pre_sync_hook():1525 - No HA hardware detected, skipping interfaces setup.
[2021/02/11 08:30:50] (INFO) InterfaceService.lag_setup():13 - Setting up lagg0
[2021/02/11 08:30:50] (INFO) InterfaceService.lag_setup():35 - lagg0: changing protocol to 4
[2021/02/11 08:30:51] (DEBUG) InterfaceService.configure():159 - lagg0: adding 10.19.42.40/255.255.252.0
[2021/02/11 08:30:51] (INFO) InterfaceService.sync():1839 - Interfaces in database: lagg0
[2021/02/11 08:30:51] (DEBUG) EtcService.generate():378 - No new changes for /etc/dhclient.conf
[2021/02/11 08:30:53] (DEBUG) EtcService.generate():378 - No new changes for /etc/nsswitch.conf
[2021/02/11 08:30:53] (DEBUG) EtcService.generate():378 - No new changes for /etc/local/nslcd.conf
[2021/02/11 08:30:54] (DEBUG) EtcService.generate():378 - No new changes for /etc/krb5.conf
[2021/02/11 08:30:57] (DEBUG) EtcService.generate():378 - No new changes for /etc/krb5.conf
[2021/02/11 08:30:57] (DEBUG) EtcService.generate():378 - No new changes for /etc/krb5.conf
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task alert.flush_alerts to run every 3600 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task alert.process_alerts to run every 60 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task certificate.renew_certs to run every 86400 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task certificateauthority.crl_generation to run every 86400 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task kerberos.keytab.check_updated_keytab to run every 3600 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task kmip.sync_keys to run every 86400 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task mail.send_mail_queue to run every 600 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task plugin.periodic_plugin_update to run every 86400 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task plugin.retrieve_versions_for_repos to run every 86400 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task pool.dataset.sync_db_keys to run every 86400 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task smb.sharesec.check_share_info_tdb to run every 3600 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task truecommand.health_check to run every 1800 seconds
[2021/02/11 08:30:58] (DEBUG) middlewared._setup_periodic_tasks():920 - Setting up periodic task zettarepl.flush_state to run every 3600 seconds
[2021/02/11 08:30:58] (DEBUG) JailService.start_on_boot():1624 - Starting jails on boot: PENDING
[2021/02/11 08:30:59] (DEBUG) JailService.start_on_boot():1626 - Starting jails on boot: SUCCESS
[2021/02/11 08:30:59] (ERROR) iocage.callback():67 - Failed to update git repository: fatal: unable to access 'https://github.com/ix-plugin-hub/iocage-plugin-index.git/': Could not resolve host: github.com

[2021/02/11 08:30:59] (ERROR) iocage.callback():67 - Not cloning https://github.com/ix-plugin-hub/iocage-plugin-index.gitas git-pull failed due to network issues.
[2021/02/11 08:31:00] (DEBUG) urllib3.connectionpool._new_conn():221 - Starting new HTTP connection (1): pkg.freebsd.org:80
[2021/02/11 08:31:00] (DEBUG) urllib3.connectionpool._new_conn():221 - Starting new HTTP connection (1): pkg.cdn.trueos.org:80
[2021/02/11 08:31:00] (DEBUG) urllib3.connectionpool._new_conn():221 - Starting new HTTP connection (1): pkg.freebsd.org:80
[2021/02/11 08:31:00] (DEBUG) urllib3.connectionpool._new_conn():221 - Starting new HTTP connection (1): pkg.freebsd.org:80
[2021/02/11 08:31:00] (DEBUG) urllib3.connectionpool._new_conn():221 - Starting new HTTP connection (1): pkg.cdn.trueos.org:80
[2021/02/11 08:31:15] (ERROR) iocage.callback():67 - Failed to update git repository: fatal: unable to access 'https://github.com/freenas/iocage-ix-plugins.git/': Could not resolve host: github.com

[2021/02/11 08:31:15] (ERROR) iocage.callback():67 - Not cloning https://github.com/freenas/iocage-ix-plugins.gitas git-pull failed due to network issues.
[2021/02/11 08:31:15] (DEBUG) urllib3.connectionpool._new_conn():221 - Starting new HTTP connection (1): pkg.freebsd.org:80
[2021/02/11 08:31:15] (DEBUG) urllib3.connectionpool._new_conn():221 - Starting new HTTP connection (1): pkg.freebsd.org:80
[2021/02/11 08:31:15] (DEBUG) urllib3.connectionpool._new_conn():221 - Starting new HTTP connection (1): pkg.cdn.trueos.org:80
[2021/02/11 08:31:15] (DEBUG) urllib3.connectionpool._new_conn():221 - Starting new HTTP connection (1): download.truenas.com:80
[2021/02/11 08:31:15] (DEBUG) urllib3.connectionpool._make_request():428 - http://pkg.cdn.trueos.org:80 "GET /iocage/unstable/packagesite.txz HTTP/1.1" 200 302704
[2021/02/11 08:31:15] (DEBUG) urllib3.connectionpool._make_request():428 - http://pkg.freebsd.org:80 "GET /FreeBSD:12:amd64/latest/packagesite.txz HTTP/1.1" 200 6412488
[2021/02/11 08:31:15] (DEBUG) urllib3.connectionpool._make_request():428 - http://pkg.freebsd.org:80 "GET /FreeBSD:12:amd64/latest/packagesite.txz HTTP/1.1" 200 6412488
[2021/02/11 08:31:15] (DEBUG) urllib3.connectionpool._make_request():428 - http://download.truenas.com:80 "GET /plugins/asigra/stable/11.3-RELEASE/packagesite.txz HTTP/1.1" 200 16472
[2021/02/11 08:59:16] (DEBUG) urllib3.connectionpool._new_conn():955 - Starting new HTTPS connection (1): update-master.ixsystems.com:443
[2021/02/11 08:59:22] (WARNING) UpdateService.get_trains_data():102 - Failed to retrieve trains redirection
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/urllib3/connection.py", line 156, in _new_conn
    conn = connection.create_connection(
  File "/usr/local/lib/python3.8/site-packages/urllib3/util/connection.py", line 84, in create_connection
    raise err
  File "/usr/local/lib/python3.8/site-packages/urllib3/util/connection.py", line 74, in create_connection
    sock.connect(sa)
socket.timeout: timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/urllib3/connectionpool.py", line 665, in urlopen
    httplib_response = self._make_request(
  File "/usr/local/lib/python3.8/site-packages/urllib3/connectionpool.py", line 376, in _make_request
    self._validate_conn(conn)
  File "/usr/local/lib/python3.8/site-packages/urllib3/connectionpool.py", line 994, in _validate_conn
    conn.connect()
  File "/usr/local/lib/python3.8/site-packages/urllib3/connection.py", line 334, in connect
    conn = self._new_conn()
  File "/usr/local/lib/python3.8/site-packages/urllib3/connection.py", line 161, in _new_conn
    raise ConnectTimeoutError(
urllib3.exceptions.ConnectTimeoutError: (<urllib3.connection.VerifiedHTTPSConnection object at 0x81eba5cd0>, 'Connection to update-master.ixsystems.com timed out. (connect timeout=5)')

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/requests/adapters.py", line 439, in send
    resp = conn.urlopen(
  File "/usr/local/lib/python3.8/site-packages/urllib3/connectionpool.py", line 719, in urlopen
    retries = retries.increment(
  File "/usr/local/lib/python3.8/site-packages/urllib3/util/retry.py", line 436, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='update-master.ixsystems.com', port=443): Max retries exceeded with url: /TrueNAS/trains_redir.json (Caused by ConnectTimeoutError(<urllib3.connection.VerifiedHTTPSConnection object at 0x81eba5cd0>, 'Connection to update-master.ixsystems.com timed out. (connect timeout=5)'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/middlewared/plugins/update_/trains_freebsd.py", line 100, in get_trains_data
    redir_trains = self._get_redir_trains()
  File "/usr/local/lib/python3.8/site-packages/middlewared/plugins/update_/trains_freebsd.py", line 141, in _get_redir_trains
    r = requests.get(
  File "/usr/local/lib/python3.8/site-packages/requests/api.py", line 75, in get
    return request('get', url, params=params, **kwargs)
  File "/usr/local/lib/python3.8/site-packages/requests/api.py", line 60, in request
    return session.request(method=method, url=url, **kwargs)
  File "/usr/local/lib/python3.8/site-packages/requests/sessions.py", line 533, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/local/lib/python3.8/site-packages/requests/sessions.py", line 646, in send
    r = adapter.send(request, **kwargs)
  File "/usr/local/lib/python3.8/site-packages/requests/adapters.py", line 504, in send
    raise ConnectTimeout(e, request=request)
requests.exceptions.ConnectTimeout: HTTPSConnectionPool(host='update-master.ixsystems.com', port=443): Max retries exceeded with url: /TrueNAS/trains_redir.json (Caused by ConnectTimeoutError(<urllib3.connection.VerifiedHTTPSConnection object at 0x81eba5cd0>, 'Connection to update-master.ixsystems.com timed out. (connect timeout=5)'))
[2021/02/11 08:59:22] (DEBUG) freenasOS.Configuration.TryGetNetworkFile():606 - TryGetNetworkFile(['https://update.ixsystems.com/TrueNAS/trains.txt', 'https://update-master.ixsystems.com/TrueNAS/trains.txt'])
[2021/02/11 08:59:22] (DEBUG) urllib3.connectionpool._new_conn():955 - Starting new HTTPS connection (1): update.ixsystems.com:443
[2021/02/11 08:59:23] (DEBUG) urllib3.connectionpool._make_request():428 - https://update.ixsystems.com:443 "GET /TrueNAS/trains.txt HTTP/1.1" 301 169
[2021/02/11 08:59:23] (DEBUG) urllib3.connectionpool._new_conn():955 - Starting new HTTPS connection (1): update.freenas.org:443
[2021/02/11 08:59:23] (DEBUG) urllib3.connectionpool._make_request():428 - https://update.freenas.org:443 "GET /TrueNAS/trains.txt HTTP/1.1" 200 377
[2021/02/11 08:59:23] (DEBUG) freenasOS.Configuration.TryGetNetworkFile():745 - TryGetNetworkFile(['https://update.ixsystems.com/TrueNAS/trains.txt', 'https://update-master.ixsystems.com/TrueNAS/trains.txt']):  Read 377 bytes total
[2021/02/11 08:59:23] (DEBUG) freenasOS.Configuration.TryGetNetworkFile():606 - TryGetNetworkFile(['https://update-master.ixsystems.com/TrueNAS/TrueNAS-12.0-STABLE/LATEST'])
[2021/02/11 08:59:23] (DEBUG) urllib3.connectionpool._new_conn():955 - Starting new HTTPS connection (1): update-master.ixsystems.com:443
[2021/02/11 08:59:23] (DEBUG) urllib3.connectionpool._make_request():428 - https://update-master.ixsystems.com:443 "GET /TrueNAS/TrueNAS-12.0-STABLE/LATEST HTTP/1.1" 200 1602
[2021/02/11 08:59:23] (DEBUG) freenasOS.Configuration.TryGetNetworkFile():745 - TryGetNetworkFile(['https://update-master.ixsystems.com/TrueNAS/TrueNAS-12.0-STABLE/LATEST']):  Read 1602 bytes total
[2021/02/11 08:59:23] (DEBUG) freenasOS.Configuration.TryGetNetworkFile():606 - TryGetNetworkFile(['https://update-master.ixsystems.com/updates/ix_crl.pem'])
[2021/02/11 08:59:23] (DEBUG) urllib3.connectionpool._new_conn():955 - Starting new HTTPS connection (1): update-master.ixsystems.com:443
[2021/02/11 08:59:24] (DEBUG) urllib3.connectionpool._make_request():428 - https://update-master.ixsystems.com:443 "GET /updates/ix_crl.pem HTTP/1.1" 200 1028
[2021/02/11 08:59:24] (DEBUG) freenasOS.Configuration.CheckFreeSpace():77 - CheckFreeSpace(path=/tmp/tmp8khzpzq0.pem, pool=None, required=1028)
[2021/02/11 08:59:24] (DEBUG) freenasOS.Configuration.TryGetNetworkFile():745 - TryGetNetworkFile(['https://update-master.ixsystems.com/updates/ix_crl.pem']):  Read 1028 bytes total
[2021/02/11 08:59:24] (DEBUG) freenasOS.Configuration.TryGetNetworkFile():606 - TryGetNetworkFile(['https://update.ixsystems.com/TrueNAS/Validators/ValidateUpdate-mg3ef525.txt', 'https://update-master.ixsystems.com/TrueNAS/Validators/ValidateUpdate-mg3ef525.txt'])
[2021/02/11 08:59:24] (DEBUG) urllib3.connectionpool._new_conn():955 - Starting new HTTPS connection (1): update.ixsystems.com:443
[2021/02/11 08:59:25] (DEBUG) urllib3.connectionpool._make_request():428 - https://update.ixsystems.com:443 "GET /TrueNAS/Validators/ValidateUpdate-mg3ef525.txt HTTP/1.1" 301 169
[2021/02/11 08:59:25] (DEBUG) urllib3.connectionpool._new_conn():955 - Starting new HTTPS connection (1): update.freenas.org:443
[2021/02/11 08:59:25] (DEBUG) urllib3.connectionpool._make_request():428 - https://update.freenas.org:443 "GET /TrueNAS/Validators/ValidateUpdate-mg3ef525.txt HTTP/1.1" 200 185
[2021/02/11 08:59:25] (DEBUG) freenasOS.Configuration.CheckFreeSpace():77 - CheckFreeSpace(path=/tmp/tmp2ihmflkk, pool=None, required=185)
[2021/02/11 08:59:25] (DEBUG) freenasOS.Configuration.TryGetNetworkFile():745 - TryGetNetworkFile(['https://update.ixsystems.com/TrueNAS/Validators/ValidateUpdate-mg3ef525.txt', 'https://update-master.ixsystems.com/TrueNAS/Validators/ValidateUpdate-mg3ef525.txt']):  Read 185 bytes total
[2021/02/11 09:01:48] (DEBUG) ActiveDirectoryService.get_n_working_servers():169 - Request for [2] of server type [DOMAINCONTROLLER] returned: [{'host': 'dc2.corp.DOMAIN.com', 'port': 389}, {'host': 'dc1.corp.DOMAIN.com', 'port': 389}]
[2021/02/11 09:01:48] (WARNING) ActiveDirectoryService.conn_check():845 - Failed to get DC info from winbindd:
[2021/02/11 09:01:48] (WARNING) ActiveDirectoryService._extend_creds():201 - Failed to initialize secrets for domain [CORP.DOMAIN.COM]. attempting to use credentials from config file.

The option to leave the domain is not available, probably due to the failed join attempt. Is there a way to do it from the shell?

cheers
Might be some stale secrets. Disable AD from GUI, then let's try following commands in sequence:
Code:
net cache flush
mv /var/db/system/samba4/secrets.tdb /var/db/system/samba4/secrets.tdb.bak

Then re-enter your credentials in the GUI and try again.

I'm going to be out of town for the next couple of days with limited internet access and so I might not respond as promptly as otherwise.
 

Kellerkind

Cadet
Joined
Feb 12, 2021
Messages
1
Hi all, I have had a similar experience: Today I started with a fresh install of 12U2 und was unable to join it to our AD (errors were the same as sqr00ts is seeing). In the end I did download the 12U1 installer and did a reinstall, with U1 I was able to join the AD without a hitch on the first attempt (same settings as before with U2). U2 might have a bug?
BR - Kellerkind
 

Jedi940

Dabbler
Joined
Feb 25, 2020
Messages
20

sqr00t2

Cadet
Joined
Feb 10, 2021
Messages
4
Thanks Jedi for opening a bug report. I don't seem to have access to the bugtracker at Jira yet.
I had to rollback to U1 as well and the domain join worked as well like a breeze.
 
Joined
Jan 21, 2021
Messages
4
Might be some stale secrets. Disable AD from GUI, then let's try following commands in sequence:
Code:
net cache flush
mv /var/db/system/samba4/secrets.tdb /var/db/system/samba4/secrets.tdb.bak

Then re-enter your credentials in the GUI and try again.

I'm going to be out of town for the next couple of days with limited internet access and so I might not respond as promptly as otherwise.
I am having the same problem, recently update my system from 11.2 U8 (running like a charm for more than 2 years) to TrueNas 12.0 U1.1 and can´t join SBS2003 AD, update to TrueNas 12.0 U2 and still not able to join AD, I tried to follow the sugested commands but get an error, further investigation led me to secrets.tdb were in private samba subdirectory, is it ok or am I doing it in the wrong way? Also I tried a fresh install TrueNAs 12.0 U2, still not able to join AD.
Code:
net cache flush
mv /var/db/system/samba4/secrets.tdb /var/db/system/samba4/private/secrets.tdb.bak
 

keson

Dabbler
Joined
Jan 24, 2019
Messages
12
Hi everyone. I just today upgraded to 12.0-U2 from previous stable U1.1 version and I also decided to join the AD so that I could access the content with domain users. I faced exactly the same errors like above people mentioned...

[EFAULT] Netlogon connection to [dc02.xxxx.local] failed with error: An invalid parameter was passed to a service or function.

Reading the posts here I decided to boot my previous environment.
When the system came up, I tried to join the domain (I actually use the exact same settings I had on my primary freeness box, where it works for a year without any issue since version 11.x) again with the same settings...

And the AD join was a matter od a second...
The "Directory Services Monitor" immediately posed up and the status was Joining and now it is Healthy.

So I do confirm, there is a bug in 12.0 U2.

For now I stay away from the latest version. If someone needs my logs, I can provide them on request.
 

TheUsD

Contributor
Joined
May 17, 2013
Messages
116
While working on other issues with my new build, I decided to reload TrueNas and start with 12.0u2 (since 12.0u2 was said to resolved some issues with intel chips).

I have no doubt that if someone is on these forums they don't already possess the knowledge on how to join a device to AD. The intent of this is just to walk those who are having trouble with joining TrueNAS to AD with the steps that I had to go through for 12.0u2 to join AD successfully.

Background:
I have three NICS, each on their own subnet (obviously)
Onboard (used for interface) 192.168.20.0/24
SFP Card Port1: 192.168.19.2/30
SFP Card Port2: 192.168.19.10/30

1). Changed the name of my host: Network > Global Configuration: Hostname
2). Set the domain to my domain name.
3). Set the default gateway (the interface gateway is also the gateway my AD server uses)
4). Set DNS Name Server.
Rebooted.
5). LDAP bind (no LDAPS) using a Windows AD account which has delegated control for Read-Only. Ensured the bind was successful. Rebooted.
6). Joined AD using a second Windows AD account with Domain Admin priv.
When joining, I made sure to not go deep into anything crazy. I joined successfully.
Rebooted.
Everything in green are changes I made.

1613344005428.png

1613344029238.png

1613349247177.png

1613421940730.png
 
Last edited:
Joined
Jan 21, 2021
Messages
4
Hi TheUsD, what is the version of AD you joining in? Im my case SBS 2003 still not able to join.
I came from an update 11.2 U8 (joining to AD withou any issues for more than 1 year) to 11.3 U5 then U12.0 U1 and finally to U12 U2, seeking for a solutions to solve AD issues.
 

Jedi940

Dabbler
Joined
Feb 25, 2020
Messages
20
While working on other issues with my new build, I decided to reload TrueNas and start with 12.0u2 (since 12.0u2 was said to resolved some issues with intel chips).

I have no doubt that if someone is on these forums they don't already possess the knowledge on how to join a device to AD. The intent of this is just to walk those who are having trouble with joining TrueNAS to AD with the steps that I had to go through for 12.0u2 to join AD successfully.

Background:
I have three NICS, each on their own subnet (obviously)
Onboard (used for interface) 192.168.20.0/24
SFP Card Port1: 192.168.19.2/30
SFP Card Port2: 192.168.19.10/30

1). Changed the name of my host: Network > Global Configuration: Hostname
2). Set the domain to my domain name.
3). Set the default gateway (the interface gateway is also the gateway my AD server uses)
4). Set DNS Name Server.
Rebooted.
5). LDAP bind (no LDAPS) using a Windows AD account which has delegated control for Read-Only. Ensured the bind was successful. Rebooted.
6). Joined AD using a second Windows AD account with Domain Admin priv.
When joining, I made sure to not go deep into anything crazy. I joined successfully.
Rebooted.
Everything in green are changes I made.

To be clear, we are not using LDAP, we are trying to use the Active Directory function.
1613408503665.png
 

TheUsD

Contributor
Joined
May 17, 2013
Messages
116
To be clear, we are not using LDAP, we are trying to use the Active Directory function.

Hey Jedi,
As I mentioned in the post, these are all the steps I had to take to get it to join AD. I had to bind LDAP, too but more importantly, I had to go in that order.
You can always disconnect the LDAP bind after you join AD.

I noticed that I posted the same screen shot twice in the directions. I updated it with the AD Screen shot. Maybe that is what created confusion.
 

Valorem

Cadet
Joined
Mar 29, 2017
Messages
2
Same here, using 12.0-U2 I am unable to join Active Directory (based on Server 2019, if that matters)

Downgraded to 12.0-U1.1 and exact same settings work without fuss.

Just to confirm absolutely the same problem as @sqr00t2 .
Trying to join W2K8R2 AD.
 

Emile.Belcourt

Dabbler
Joined
Feb 16, 2021
Messages
23
Had the exact same issue, attempted TheUsD's process and didn't work for me with the same error.

I loaded 12.0-u1 and was able to join then updated to 12.0-u2 and all the reports are healthy but I am trying to now diagnose an issue where I can't assign AD users and groups into the ACLs. I didn't test on u1 (d'oh) before jumping ahead.
 
Top