Register for the iXsystems Community to get an ad-free experience and exclusive discounts in our eBay Store.

FreeNAS 11.3-U4.1 fails to join domain after update

Western Digital Drives - The Preferred Drives of FreeNAS and TrueNAS CORE

andrewjones216

Junior Member
Joined
Jun 7, 2016
Messages
15
Hi all,

I am unable to join our domain after upgrading our Freenas to the latest stable release (11.3-U4.1). The interface times out when trying to save the settings.
I've got another FreeNAS box on the same version with the same AD settings connected ok. The output below suggests it has some old info cached somewhere, maybe?

Domain has been obfuscated to 'our.domain'
Workgroup parameter has been obfuscated to 'workgroup'

I've tried:

Code:
root@CNAS05:~ # service winbindd onestart


winbindd already running?  (pid=5846).



root@CNAS05:~ # ping cwm-dc-01


PING cwm-dc-01.our.domain (xxx.xxx.11.51): 56 data bytes

64 bytes from xxx.xxx.11.51: icmp_seq=0 ttl=128 time=0.779 ms

64 bytes from xxx.xxx.11.51: icmp_seq=1 ttl=128 time=0.839 ms

64 bytes from xxx.xxx.11.51: icmp_seq=2 ttl=128 time=0.727 ms



root@CNAS05:~ # dig our.domain


; <<>> DiG 9.14.6 <<>> our.domain

;; global options: +cmd

;; Got answer:

;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 32686

;; flags: qr aa rd ra; QUERY: 1, ANSWER: 4, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:

; EDNS: version: 0, flags:; udp: 4000

;; QUESTION SECTION:

;our.domain.                  IN      A


;; ANSWER SECTION:

our.domain.           600     IN      A       xxx.xxx.10.53

our.domain.           600     IN      A       xxx.xxx.10.163

our.domain.           600     IN      A       xxx.xxx.11.52

our.domain.           600     IN      A       xxx.xxx.11.51


;; Query time: 1 msec

;; SERVER: xxx.xxx.11.51#53(xxx.xxx.11.51)

;; WHEN: Thu Aug 13 18:29:41 BST 2020

;; MSG SIZE  rcvd: 105




root@CNAS05:~ # host -t srv _ldap._tcp.our.domain


_ldap._tcp.our.domain has SRV record 0 100 389 CWM-DC-01.our.domain.

_ldap._tcp.our.domain has SRV record 0 100 389 cwm-dc-02.our.domain.

_ldap._tcp.our.domain has SRV record 0 100 389 cwm-dc-01.our.domain.

_ldap._tcp.our.domain has SRV record 0 100 389 cdc01.our.domain.

_ldap._tcp.our.domain has SRV record 0 100 389 CWM-DC-02.our.domain.


; <<>> DiG 9.14.6 <<>> pdc.our.domain

;; global options: +cmd

;; Got answer:

;; ->>HEADER<<- opcode: QUERY, status: NXDOMAIN, id: 32981

;; flags: qr aa rd ra; QUERY: 1, ANSWER: 0, AUTHORITY: 1, ADDITIONAL: 1

;; OPT PSEUDOSECTION:

; EDNS: version: 0, flags:; udp: 4000


;; QUESTION SECTION:

;pdc.our.domain.              IN      A


;; AUTHORITY SECTION:

our.domain.           3600    IN      SOA     cwm-dc-01.our.domain. hostmaster.our.domain. 182354 900 600 86400 3600

;; Query time: 1 msec

;; SERVER: xxx.xxx.11.51#53(xxx.xxx.11.51)

;; WHEN: Thu Aug 13 18:30:21 BST 2020

;; MSG SIZE  rcvd: 114


root@CNAS05:~ # net -k -d 5 ads testjoin

INFO: Current debug levels:

  all: 5

  tdb: 5

  printdrivers: 5

  lanman: 5

  smb: 5

  rpc_parse: 5

  rpc_srv: 5

  rpc_cli: 5

  passdb: 5

  sam: 5

  auth: 5

  winbind: 5

  vfs: 5

  idmap: 5

  quota: 5

  acls: 5

  locking: 5

  msdfs: 5

  dmapi: 5

  registry: 5

  scavenger: 5

  dns: 5

  ldb: 5

  tevent: 5

  auth_audit: 5

  auth_json_audit: 5

  kerberos: 5

  drs_repl: 5

  smb2: 5

  smb2_credits: 5

  dsdb_audit: 5

  dsdb_json_audit: 5

  dsdb_password_audit: 5

  dsdb_password_json_audit: 5

  dsdb_transaction_audit: 5

  dsdb_transaction_json_audit: 5

  dsdb_group_audit: 5

  dsdb_group_json_audit: 5

lp_load_ex: refreshing parameters

Initialising global parameters

INFO: Current debug levels:

  all: 5

  tdb: 5

  printdrivers: 5

  lanman: 5

  smb: 5

  rpc_parse: 5

  rpc_srv: 5

  rpc_cli: 5

  passdb: 5

  sam: 5

  auth: 5

  winbind: 5

  vfs: 5

  idmap: 5

  quota: 5

  acls: 5

  locking: 5

  msdfs: 5

  dmapi: 5

  registry: 5

  scavenger: 5

  dns: 5

  ldb: 5

  tevent: 5

  auth_audit: 5

  auth_json_audit: 5

  kerberos: 5

  drs_repl: 5

  smb2: 5

  smb2_credits: 5

  dsdb_audit: 5

  dsdb_json_audit: 5

  dsdb_password_audit: 5

  dsdb_password_json_audit: 5

  dsdb_transaction_audit: 5

  dsdb_transaction_json_audit: 5

  dsdb_group_audit: 5

  dsdb_group_json_audit: 5

Processing section "[global]"

doing parameter dns proxy = No

doing parameter aio max threads = 2

doing parameter max log size = 51200

doing parameter allocation roundup size = 0

doing parameter load printers = No

doing parameter printing = bsd

doing parameter disable spoolss = Yes

doing parameter dos filemode = Yes

doing parameter kernel change notify = No

doing parameter directory name cache size = 0

doing parameter nsupdate command = /usr/local/bin/samba-nsupdate -g

doing parameter unix charset = UTF-8

doing parameter log level = 3

doing parameter obey pam restrictions = False

doing parameter enable web service discovery = True

doing parameter logging = file

doing parameter server min protocol = SMB2_02

doing parameter unix extensions = No

doing parameter map to guest = Bad User

doing parameter server string = CNAS05 FreeNAS Storage Server

doing parameter bind interfaces only = Yes

doing parameter netbios name = CNAS05

doing parameter netbios aliases =

doing parameter server role = standalone

doing parameter workgroup = workgroup

doing parameter idmap config *: backend = tdb

doing parameter idmap config *: range = 90000001-100000000

doing parameter include = /usr/local/etc/smb4_share.conf

pm_process() returned Yes

Registering messaging pointer for type 2 - private_data=0x0

Registering messaging pointer for type 9 - private_data=0x0

Registered MSG_REQ_POOL_USAGE

Registering messaging pointer for type 11 - private_data=0x0

Registering messaging pointer for type 12 - private_data=0x0

Registered MSG_REQ_DMALLOC_MARK and LOG_CHANGED

Registering messaging pointer for type 1 - private_data=0x0

Registering messaging pointer for type 5 - private_data=0x0

Registering messaging pointer for type 51 - private_data=0x0

lp_load_ex: refreshing parameters

Freeing parametrics:

Initialising global parameters

INFO: Current debug levels:

  all: 5

  tdb: 5

  printdrivers: 5

  lanman: 5

  smb: 5

  rpc_parse: 5

  rpc_srv: 5

  rpc_cli: 5

  passdb: 5

  sam: 5

  auth: 5

  winbind: 5

  vfs: 5

  idmap: 5

  quota: 5

  acls: 5

  locking: 5

  msdfs: 5

  dmapi: 5

  registry: 5

  scavenger: 5

  dns: 5

  ldb: 5

  tevent: 5

  auth_audit: 5

  auth_json_audit: 5

  kerberos: 5

  drs_repl: 5

  smb2: 5

  smb2_credits: 5

  dsdb_audit: 5

  dsdb_json_audit: 5

  dsdb_password_audit: 5

  dsdb_password_json_audit: 5

  dsdb_transaction_audit: 5

  dsdb_transaction_json_audit: 5

  dsdb_group_audit: 5

  dsdb_group_json_audit: 5

Processing section "[global]"

doing parameter dns proxy = No

doing parameter aio max threads = 2

doing parameter max log size = 51200

doing parameter allocation roundup size = 0

doing parameter load printers = No

doing parameter printing = bsd

doing parameter disable spoolss = Yes

doing parameter dos filemode = Yes

doing parameter kernel change notify = No

doing parameter directory name cache size = 0

doing parameter nsupdate command = /usr/local/bin/samba-nsupdate -g

doing parameter unix charset = UTF-8

doing parameter log level = 3

doing parameter obey pam restrictions = False

doing parameter enable web service discovery = True

doing parameter logging = file

doing parameter server min protocol = SMB2_02

doing parameter unix extensions = No

doing parameter map to guest = Bad User

doing parameter server string = CNAS05 FreeNAS Storage Server

doing parameter bind interfaces only = Yes

doing parameter netbios name = CNAS05

doing parameter netbios aliases =

doing parameter server role = standalone

doing parameter workgroup = workgroup

doing parameter idmap config *: backend = tdb

doing parameter idmap config *: range = 90000001-100000000

doing parameter include = /usr/local/etc/smb4_share.conf

pm_process() returned Yes

Netbios name list:-

my_netbios_names[0]="CNAS05"

added interface ix0 ip=xxx.16.0.2 bcast=xxx.16.0.7 netmask=255.255.255.248

added interface igb0 ip=xxx.xxx.10.77 bcast=xxx.xxx.10.255 netmask=255.255.255.0

Opening cache file at /var/run/samba4/gencache.tdb

sitename_fetch: No stored sitename for realm ''

ads_dc_name: domain=workgroup

saf_fetch: failed to find server for "workgroup" domain

get_dc_list: preferred server list: ", *"

no entry for workgroup#1C found.

resolve_lmhosts: Attempting lmhosts lookup for name workgroup<0x1c>

startlmhosts: Can't open lmhosts file /usr/local/etc/lmhosts. Error was No such file or directory

resolve_wins: WINS server resolution selected and no WINS servers listed.

resolve_hosts: not appropriate for name type <0x1c>

name_resolve_bcast: Attempting broadcast lookup for name workgroup<0x1c>

get_dc_list: no servers found

ads_find_dc: name resolution for realm '' (domain 'workgroup') failed: NT_STATUS_NO_LOGON_SERVERS

saf_fetch: failed to find server for "workgroup" domain

get_dc_list: preferred server list: ", *"

no entry for workgroup#1C found.

resolve_lmhosts: Attempting lmhosts lookup for name workgroup<0x1c>

startlmhosts: Can't open lmhosts file /usr/local/etc/lmhosts. Error was No such file or directory

resolve_wins: WINS server resolution selected and no WINS servers listed.

resolve_hosts: not appropriate for name type <0x1c>

name_resolve_bcast: Attempting broadcast lookup for name workgroup<0x1c>

get_dc_list: no servers found

Could not look up dc's for domain workgroup

sitename_fetch: No stored sitename for realm ''

ads_dc_name: domain=workgroup

saf_fetch: failed to find server for "workgroup" domain

get_dc_list: preferred server list: ", *"

no entry for workgroup#1C found.

resolve_lmhosts: Attempting lmhosts lookup for name workgroup<0x1c>

startlmhosts: Can't open lmhosts file /usr/local/etc/lmhosts. Error was No such file or directory

resolve_wins: WINS server resolution selected and no WINS servers listed.

resolve_hosts: not appropriate for name type <0x1c>

name_resolve_bcast: Attempting broadcast lookup for name workgroup<0x1c>

get_dc_list: no servers found

ads_find_dc: name resolution for realm '' (domain 'workgroup') failed: NT_STATUS_NO_LOGON_SERVERS

saf_fetch: failed to find server for "workgroup" domain

get_dc_list: preferred server list: ", *"

no entry for workgroup#1C found.

resolve_lmhosts: Attempting lmhosts lookup for name workgroup<0x1c>

startlmhosts: Can't open lmhosts file /usr/local/etc/lmhosts. Error was No such file or directory

resolve_wins: WINS server resolution selected and no WINS servers listed.

resolve_hosts: not appropriate for name type <0x1c>

name_resolve_bcast: Attempting broadcast lookup for name workgroup<0x1c>

get_dc_list: no servers found

Could not look up dc's for domain workgroup

ads_connect: No logon servers are currently available to service the logon request.

Join to domain is not valid: No logon servers are currently available to service the logon request.

return code = -1


root@CNAS05:~ # wbinfo -t

checking the trust secret for domain CNM via RPC calls failed

wbcCheckTrustCredentials(CNM): error code was NT_STATUS_NO_SUCH_DOMAIN (0xc00000df)

failed to call wbcCheckTrustCredentials: WBC_ERR_AUTH_ERROR

Could not check secret


root@CNAS05:~ # wbinfo -m

BUILTIN

CNAS05



Web GUI shows this:
1597344744230.png

1597344755136.png


Any help would be much appreciated.


Thanks
Andrew
 

andrewjones216

Junior Member
Joined
Jun 7, 2016
Messages
15
Update:
When trying to save in the Web GUI, it takes it's time but eventually displays the error:

Failed to validate bind credentials: kinit for domain [our.domain] with password failed: kinit: krb5_get_init_creds: unable to reach any KDC in realm our.domain

Update 2:
Tried changing the SASL wrapping as per this bug report https://jira.ixsystems.com/browse/NAS-104916?jql=text ~ "Server 2019"

  • With SEAL selected: Failed to validate bind credentials: kinit for domain [our.domain] with password failed: kinit: krb5_get_init_creds: unable to reach any KDC in realm our.domain
  • With PLAIN selected: Failed to validate bind credentials: kinit for domain [our.domain] with password failed: kinit: krb5_get_init_creds: unable to reach any KDC in realm our.domain
Going to try any and all the bug fixes/ reports I have found on the jira platform later on today, any input would be appreciated.
 
Last edited:

andrewjones216

Junior Member
Joined
Jun 7, 2016
Messages
15
Update
Have tried some of the bug fixes from Jira:
https://jira.ixsystems.com/browse/NAS-107107?jql=project = NAS
https://github.com/freenas/freenas/pull/5396
  • Backed up config including keys
  • Recorded the output of "cat /etc/krb5.conf" and take copy via winscp - empty no point!
  • Recorded the output of "cat /etc/krb5.keytab" and take copy via winscp - file doesn't exist
  • Backed up secrets.tdb

- Delete any keytabs; No keytabs available to delete
- Delete any realms; No realms available to delete
- rename "/var/db/system/samba4/private/secrets.tdb" to "/var/db/system/samba4/private/secrets.tdb.bak.{int(ts)}"; renamed secrets.tdb from "/var/db/system/samba4/private/secrets.tdb" to "/var/db/system/samba4/private/secrets.tdb.bak"
- flush samba cache; flushed samba cache "net cache flush"
- restarted winbindd services "service winbindd restart"
- Try joining domain again; Tried to join domain: "Failed to validate bind credentials: kinit for domain [domain_name] with password failed: kinit: krb5_get_init_creds: unable to reach any KDC in realm domain_name"
- The process did create a new secrets.tdb file
- Ran debug and net -k d10 ads testjoin; failed.
- Checked DC time against CNAS05 time: DC time: 19:02 27/08/2020 CNAS05 time: Thu Aug 27 19:02:33 BST 2020

I have the debug and testjoin output but it's very much the same as above. Both appear to try and use the workgroup name to call the domain.

Any thoughts?
 

anodos

Sambassador
iXsystems
Joined
Mar 6, 2014
Messages
7,200
When you say "times out when saving", as in clicking "OK" hits a middleware timeout? The AD update performs a quick validation of credentials via `kinit` before handing off the actual domain join to a backgrounded job. If it times out at this point, then the problem is probably kerberos-related. Check lookups of your kerberos-related SRV records. If you enable verbose logging, you should see more output in /var/log/middlewared.log about the state of things. Preferred security settings are SSL: OFF, sasl_wrapping: SEAL.
 

andrewjones216

Junior Member
Joined
Jun 7, 2016
Messages
15
Hi anodos,

I’ve broken my reply to you up in to sections below;


When you say "times out when saving", as in clicking "OK" hits a middleware timeout? The AD update performs a quick validation of credentials via `kinit` before handing off the actual domain join to a backgrounded job. If it times out at this point, then the problem is probably kerberos-related.
---
When clicking 'Save' (see image below) the spinning circle ‘Please wait’ comes up for about 5 minutes before displaying the message "Failed to validate bind credentials: kinit for domain [our.domain] with password failed: kinit: krb5_get_init_creds: unable to reach any KDC in realm our.domain" below the password text box.
image1.png




Check lookups of your kerberos-related SRV records.
---
root@CNAS05:~ # ping cwm-dc-01
PING cwm-dc-01.our.domain (xxx.xxx.11.51): 56 data bytes
64 bytes from xxx. xxx.11.51: icmp_seq=0 ttl=128 time=0.759 ms
64 bytes from xxx. xxx.11.51: icmp_seq=1 ttl=128 time=0.775 ms
64 bytes from xxx. xxx.11.51: icmp_seq=2 ttl=128 time=0.582 ms

root@CNAS05:~ # ping cwm-dc-02
PING cwm-dc-02.out.domain (xxx.xxx.11.52): 56 data bytes
64 bytes from xxx. xxx.11.52: icmp_seq=0 ttl=128 time=0.558 ms
64 bytes from xxx. xxx.11.52: icmp_seq=1 ttl=128 time=0.437 ms
64 bytes from xxx. xxx.11.52: icmp_seq=2 ttl=128 time=0.458 ms


root@CNAS05:~ # dig our.domain
; <<>> DiG 9.14.6 <<>> our.domain
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 39980
;; flags: qr aa rd ra; QUERY: 1, ANSWER: 3, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 4000
;; QUESTION SECTION:
;our.domain. IN A

;; ANSWER SECTION:
our.domain. 600 IN A xxx.xxx.10.53
our.domain. 600 IN A xxx.xxx.11.51
our.domain. 600 IN A xxx.xxx.11.52

;; Query time: 1 msec
;; SERVER: xxx.xxx.11.51#53(xxx.xxx.11.51)
;; WHEN: Wed Sep 02 08:29:04 BST 2020
;; MSG SIZE rcvd: 89


root@CNAS05:~ # host -t srv _ldap._tcp.our.domain
_ldap._tcp.our.domain has SRV record 0 100 389 CWM-DC-02.our.domain.
_ldap._tcp.our.domain has SRV record 0 100 389 CWM-DC-01.our.domain.
_ldap._tcp.our.domain has SRV record 0 100 389 cwm-dc-02.our.domain.
_ldap._tcp.our.domain has SRV record 0 100 389 cwm-dc-01.our.domain.
_ldap._tcp.our.domain has SRV record 0 100 389 cdc01.our.domain.


root@CNAS05:~ # dig pdc.our.domain
; <<>> DiG 9.14.6 <<>> pdc.our.domain
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NXDOMAIN, id: 57463
;; flags: qr aa rd ra; QUERY: 1, ANSWER: 0, AUTHORITY: 1, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 4000
;; QUESTION SECTION:
;pdc.our.domain. IN A

;; AUTHORITY SECTION:
our.domain. 3600 IN SOA cwm-dc-01.our.domain. hostmaster.our.domain. 182805 900 600 86400 3600

;; Query time: 1 msec
;; SERVER: xxx.xxx.11.51#53(xxx.xxx.11.51)
;; WHEN: Wed Sep 02 08:31:03 BST 2020
;; MSG SIZE rcvd: 114



If you enable verbose logging, you should see more output in /var/log/middlewared.log about the state of things. Preferred security settings are SSL: OFF, sasl_wrapping: SEAL.

--- Verbose logging ticked, SSL OFF and sasl_wrapping set to SEAL (although I did try SIGN as well). Output from middlewared.log from the time I started below.
Code:
[2020/09/01 17:21:21] (DEBUG) urllib3.connectionpool._new_conn():959 - Starting new HTTPS connection (1): update-master.ixsystems.com:443
[2020/09/01 17:21:42] (WARNING) UpdateService.get_trains():297 - Failed to retrieve trains redirection
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/urllib3/connection.py", line 157, in _new_conn
    (self._dns_host, self.port), self.timeout, **extra_kw
  File "/usr/local/lib/python3.7/site-packages/urllib3/util/connection.py", line 84, in create_connection
    raise err
  File "/usr/local/lib/python3.7/site-packages/urllib3/util/connection.py", line 74, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 61] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 672, in urlopen
    chunked=chunked,
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 376, in _make_request
    self._validate_conn(conn)
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 994, in _validate_conn
    conn.connect()
  File "/usr/local/lib/python3.7/site-packages/urllib3/connection.py", line 334, in connect
    conn = self._new_conn()
  File "/usr/local/lib/python3.7/site-packages/urllib3/connection.py", line 169, in _new_conn
    self, "Failed to establish a new connection: %s" % e
urllib3.exceptions.NewConnectionError: <urllib3.connection.VerifiedHTTPSConnection object at 0x860b67b10>: Failed to establish a new connection: [Errno 61] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/requests/adapters.py", line 449, in send
    timeout=timeout
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 720, in urlopen
    method, url, error=e, _pool=self, _stacktrace=sys.exc_info()[2]
  File "/usr/local/lib/python3.7/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: /FreeNAS/trains_redir.json (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x860b67b10>: Failed to establish a new connection: [Errno 61] Connection refused'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 295, in get_trains
    redir_trains = self._get_redir_trains()
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 277, in _get_redir_trains
    timeout=5,
  File "/usr/local/lib/python3.7/site-packages/requests/api.py", line 75, in get
    return request('get', url, params=params, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/api.py", line 60, in request
    return session.request(method=method, url=url, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 533, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/local/lib/python3.7/site-packages/raven/breadcrumbs.py", line 341, in send
    resp = real_send(self, request, *args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 646, in send
    r = adapter.send(request, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/adapters.py", line 516, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPSConnectionPool(host='update-master.ixsystems.com', port=443): Max retries exceeded with url: /FreeNAS/trains_redir.json (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x860b67b10>: Failed to establish a new connection: [Errno 61] Connection refused'))
[2020/09/01 17:21:42] (DEBUG) freenasOS.Configuration.TryGetNetworkFile():606 - TryGetNetworkFile(['https://update.ixsystems.com/FreeNAS/trains.txt', 'https://update-master.ixsystems.com/FreeNAS/trains.txt'])
[2020/09/01 17:21:42] (DEBUG) urllib3.connectionpool._new_conn():959 - Starting new HTTPS connection (1): update.ixsystems.com:443
[2020/09/01 17:21:47] (ERROR) freenasOS.Configuration.TryGetNetworkFile():692 - Unable to connect to url https://update.ixsystems.com/FreeNAS/trains.txt: HTTPSConnectionPool(host='update.ixsystems.com', port=443): Max retries exceeded with url: /FreeNAS/trains.txt (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x83ed1df10>: Failed to establish a new connection: [Errno 61] Connection refused'))
[2020/09/01 17:21:47] (DEBUG) urllib3.connectionpool._new_conn():959 - Starting new HTTPS connection (1): update-master.ixsystems.com:443
[2020/09/01 17:21:57] (ERROR) freenasOS.Configuration.TryGetNetworkFile():692 - Unable to connect to url https://update-master.ixsystems.com/FreeNAS/trains.txt: HTTPSConnectionPool(host='update-master.ixsystems.com', port=443): Max retries exceeded with url: /FreeNAS/trains.txt (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x87c0eb8d0>: Failed to establish a new connection: [Errno 61] Connection refused'))
[2020/09/01 17:21:57] (ERROR) freenasOS.Configuration.TryGetNetworkFile():709 - Unable to load ['https://update.ixsystems.com/FreeNAS/trains.txt', 'https://update-master.ixsystems.com/FreeNAS/trains.txt']: Unable to connect to url https://update-master.ixsystems.com/FreeNAS/trains.txt
[2020/09/01 17:21:57] (WARNING) application.call_method():168 - Exception while calling update.check_available(*[])
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 130, in call_method
    io_thread=False)
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1098, in _call
    return await run_method(methodobj, *args)
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1022, in _run_in_conn_threadpool
    return await self.run_in_executor(self.__ws_threadpool, method, *args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1010, in run_in_executor
    return await loop.run_in_executor(pool, functools.partial(method, *args, **kwargs))
  File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/schema.py", line 965, in nf
    return f(*args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 422, in check_available
    trains = self.middleware.call_sync('update.get_trains')
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1157, in call_sync
    io_thread=True, job_on_progress_cb=job_on_progress_cb,
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1180, in run_coroutine
    return fut.result()
  File "/usr/local/lib/python3.7/concurrent/futures/_base.py", line 428, in result
    return self.__get_result()
  File "/usr/local/lib/python3.7/concurrent/futures/_base.py", line 384, in __get_result
    raise self._exception
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1098, in _call
    return await run_method(methodobj, *args)
  File "/usr/local/lib/python3.7/site-packages/middlewared/utils/run_in_thread.py", line 10, in run_in_thread
    return await self.loop.run_in_executor(self.run_in_thread_executor, functools.partial(method, *args, **kwargs))
  File "/usr/local/lib/python3.7/site-packages/middlewared/utils/io_thread_pool_executor.py", line 25, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/schema.py", line 965, in nf
    return f(*args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 302, in get_trains
    for name, descr in (conf.AvailableTrains() or {}).items():
  File "/usr/local/lib/freenasOS/Configuration.py", line 987, in AvailableTrains
    fileref = self.TryGetNetworkFile(file=TRAIN_FILE, reason="FetchTrains")
  File "/usr/local/lib/freenasOS/Configuration.py", line 710, in TryGetNetworkFile
    raise url_exc
freenasOS.Exceptions.UpdateNetworkConnectionException: Unable to connect to url https://update-master.ixsystems.com/FreeNAS/trains.txt
[2020/09/01 17:21:57] (DEBUG) application.__crash_reporting():173 - [Crash Reporting] is disabled using sentinel file.
[2020/09/01 17:36:52] (DEBUG) urllib3.connectionpool._new_conn():959 - Starting new HTTPS connection (1): update-master.ixsystems.com:443
[2020/09/01 17:37:03] (WARNING) UpdateService.get_trains():297 - Failed to retrieve trains redirection
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/urllib3/connection.py", line 157, in _new_conn
    (self._dns_host, self.port), self.timeout, **extra_kw
  File "/usr/local/lib/python3.7/site-packages/urllib3/util/connection.py", line 84, in create_connection
    raise err
  File "/usr/local/lib/python3.7/site-packages/urllib3/util/connection.py", line 74, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 61] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 672, in urlopen
    chunked=chunked,
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 376, in _make_request
    self._validate_conn(conn)
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 994, in _validate_conn
    conn.connect()
  File "/usr/local/lib/python3.7/site-packages/urllib3/connection.py", line 334, in connect
    conn = self._new_conn()
  File "/usr/local/lib/python3.7/site-packages/urllib3/connection.py", line 169, in _new_conn
    self, "Failed to establish a new connection: %s" % e
urllib3.exceptions.NewConnectionError: <urllib3.connection.VerifiedHTTPSConnection object at 0x87befa0d0>: Failed to establish a new connection: [Errno 61] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/requests/adapters.py", line 449, in send
    timeout=timeout
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 720, in urlopen
    method, url, error=e, _pool=self, _stacktrace=sys.exc_info()[2]
  File "/usr/local/lib/python3.7/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: /FreeNAS/trains_redir.json (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x87befa0d0>: Failed to establish a new connection: [Errno 61] Connection refused'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 295, in get_trains
    redir_trains = self._get_redir_trains()
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 277, in _get_redir_trains
    timeout=5,
  File "/usr/local/lib/python3.7/site-packages/requests/api.py", line 75, in get
    return request('get', url, params=params, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/api.py", line 60, in request
    return session.request(method=method, url=url, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 533, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/local/lib/python3.7/site-packages/raven/breadcrumbs.py", line 341, in send
    resp = real_send(self, request, *args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 646, in send
    r = adapter.send(request, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/adapters.py", line 516, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPSConnectionPool(host='update-master.ixsystems.com', port=443): Max retries exceeded with url: /FreeNAS/trains_redir.json (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x87befa0d0>: Failed to establish a new connection: [Errno 61] Connection refused'))
[2020/09/01 17:37:03] (DEBUG) freenasOS.Configuration.TryGetNetworkFile():606 - TryGetNetworkFile(['https://update.ixsystems.com/FreeNAS/trains.txt', 'https://update-master.ixsystems.com/FreeNAS/trains.txt'])
[2020/09/01 17:37:03] (DEBUG) urllib3.connectionpool._new_conn():959 - Starting new HTTPS connection (1): update.ixsystems.com:443
[2020/09/01 17:37:03] (ERROR) freenasOS.Configuration.TryGetNetworkFile():692 - Unable to connect to url https://update.ixsystems.com/FreeNAS/trains.txt: HTTPSConnectionPool(host='update.ixsystems.com', port=443): Max retries exceeded with url: /FreeNAS/trains.txt (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x87bffb9d0>: Failed to establish a new connection: [Errno 61] Connection refused'))
[2020/09/01 17:37:03] (DEBUG) urllib3.connectionpool._new_conn():959 - Starting new HTTPS connection (1): update-master.ixsystems.com:443
[2020/09/01 17:37:07] (ERROR) freenasOS.Configuration.TryGetNetworkFile():692 - Unable to connect to url https://update-master.ixsystems.com/FreeNAS/trains.txt: HTTPSConnectionPool(host='update-master.ixsystems.com', port=443): Max retries exceeded with url: /FreeNAS/trains.txt (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x87bffb410>: Failed to establish a new connection: [Errno 61] Connection refused'))
[2020/09/01 17:37:07] (ERROR) freenasOS.Configuration.TryGetNetworkFile():709 - Unable to load ['https://update.ixsystems.com/FreeNAS/trains.txt', 'https://update-master.ixsystems.com/FreeNAS/trains.txt']: Unable to connect to url https://update-master.ixsystems.com/FreeNAS/trains.txt
[2020/09/01 17:37:07] (WARNING) application.call_method():168 - Exception while calling update.check_available(*[])
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 130, in call_method
    io_thread=False)
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1098, in _call
    return await run_method(methodobj, *args)
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1022, in _run_in_conn_threadpool
    return await self.run_in_executor(self.__ws_threadpool, method, *args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1010, in run_in_executor
    return await loop.run_in_executor(pool, functools.partial(method, *args, **kwargs))
  File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/schema.py", line 965, in nf
    return f(*args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 422, in check_available
    trains = self.middleware.call_sync('update.get_trains')
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1157, in call_sync
    io_thread=True, job_on_progress_cb=job_on_progress_cb,
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1180, in run_coroutine
    return fut.result()
  File "/usr/local/lib/python3.7/concurrent/futures/_base.py", line 428, in result
    return self.__get_result()
  File "/usr/local/lib/python3.7/concurrent/futures/_base.py", line 384, in __get_result
    raise self._exception
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1098, in _call
    return await run_method(methodobj, *args)
  File "/usr/local/lib/python3.7/site-packages/middlewared/utils/run_in_thread.py", line 10, in run_in_thread
    return await self.loop.run_in_executor(self.run_in_thread_executor, functools.partial(method, *args, **kwargs))
  File "/usr/local/lib/python3.7/site-packages/middlewared/utils/io_thread_pool_executor.py", line 25, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/schema.py", line 965, in nf
    return f(*args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 302, in get_trains
    for name, descr in (conf.AvailableTrains() or {}).items():
  File "/usr/local/lib/freenasOS/Configuration.py", line 987, in AvailableTrains
    fileref = self.TryGetNetworkFile(file=TRAIN_FILE, reason="FetchTrains")
  File "/usr/local/lib/freenasOS/Configuration.py", line 710, in TryGetNetworkFile
    raise url_exc
freenasOS.Exceptions.UpdateNetworkConnectionException: Unable to connect to url https://update-master.ixsystems.com/FreeNAS/trains.txt
[2020/09/01 17:37:07] (DEBUG) application.__crash_reporting():173 - [Crash Reporting] is disabled using sentinel file.
[2020/09/01 18:02:45] (ERROR) iocage.callback():63 - Failed to update git repository: fatal: Unable to create '/mnt/AppData1/iocage/.plugins/github_com_freenas_iocage-ix-plugins_git/.git/index.lock': Read-only file system

[2020/09/01 18:02:45] (DEBUG) git.repo.base._clone():938 - Cmd(['git', 'clone', '-v', 'https://github.com/freenas/iocage-ix-plugins.git', '/mnt/AppData1/iocage/.plugins/github_com_freenas_iocage-ix-plugins_git'])'s unused stdout:
[2020/09/01 18:02:45] (ERROR) middlewared.job.run():361 - Job <bound method accepts.<locals>.wrap.<locals>.nf of <middlewared.plugins.jail.PluginService object at 0x82c860350>> failed
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/iocage_lib/ioc_plugin.py", line 1578, in _clone_repo
    for k in ['http_proxy', 'https_proxy'] if
  File "/usr/local/lib/python3.7/site-packages/iocage_lib/ioc_exec.py", line 268, in __init__
    self.output = list(silent)
  File "/usr/local/lib/python3.7/site-packages/iocage_lib/ioc_exec.py", line 260, in exec_jail
    list(stderr_queue)
iocage_lib.ioc_exceptions.CommandFailed: [b"fatal: Unable to create '/mnt/AppData1/iocage/.plugins/github_com_freenas_iocage-ix-plugins_git/.git/index.lock': Read-only file system\n", b'', b'', b'', b'', b'']

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/middlewared/job.py", line 349, in run
    await self.future
  File "/usr/local/lib/python3.7/site-packages/middlewared/job.py", line 387, in __run_body
    rv = await self.middleware.run_in_thread(self.method, *([self] + args))
  File "/usr/local/lib/python3.7/site-packages/middlewared/utils/run_in_thread.py", line 10, in run_in_thread
    return await self.loop.run_in_executor(self.run_in_thread_executor, functools.partial(method, *args, **kwargs))
  File "/usr/local/lib/python3.7/site-packages/middlewared/utils/io_thread_pool_executor.py", line 25, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/schema.py", line 965, in nf
    return f(*args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/jail.py", line 409, in available
    plugins_versions_data = IOCPlugin(branch=branch, git_repository=plugin_repository).fetch_plugin_versions()
  File "/usr/local/lib/python3.7/site-packages/iocage_lib/ioc_plugin.py", line 266, in fetch_plugin_versions
    self.pull_clone_git_repo()
  File "/usr/local/lib/python3.7/site-packages/iocage_lib/ioc_plugin.py", line 137, in pull_clone_git_repo
    depth, self.callback
  File "/usr/local/lib/python3.7/site-packages/iocage_lib/ioc_plugin.py", line 1631, in _clone_repo
    k: v for k, v in kwargs.items() if v
  File "/usr/local/lib/python3.7/site-packages/git/repo/base.py", line 988, in clone_from
    return cls._clone(git, url, to_path, GitCmdObjectDB, progress, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/git/repo/base.py", line 939, in _clone
    finalize_process(proc, stderr=stderr)
  File "/usr/local/lib/python3.7/site-packages/git/util.py", line 333, in finalize_process
    proc.wait(**kwargs)
  File "/usr/local/lib/python3.7/site-packages/git/cmd.py", line 415, in wait
    raise GitCommandError(self.args, status, errstr)
git.exc.GitCommandError: Cmd('git') failed due to: exit code(128)
  cmdline: git clone -v https://github.com/freenas/iocage-ix-plugins.git /mnt/AppData1/iocage/.plugins/github_com_freenas_iocage-ix-plugins_git
  stderr: 'fatal: destination path '/mnt/AppData1/iocage/.plugins/github_com_freenas_iocage-ix-plugins_git' already exists and is not an empty directory.
'
[2020/09/01 18:02:45] (ERROR) iocage.callback():63 - Failed to update git repository:
[2020/09/01 18:02:46] (DEBUG) git.repo.base._clone():938 - Cmd(['git', 'clone', '-v', 'https://github.com/ix-plugin-hub/iocage-plugin-index.git', '/mnt/AppData1/iocage/.plugins/github_com_ix-plugin-hub_iocage-plugin-index_git'])'s unused stdout:
[2020/09/01 18:02:46] (ERROR) middlewared.job.run():361 - Job <bound method accepts.<locals>.wrap.<locals>.nf of <middlewared.plugins.jail.PluginService object at 0x82c860350>> failed
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/iocage_lib/ioc_plugin.py", line 1578, in _clone_repo
    for k in ['http_proxy', 'https_proxy'] if
  File "/usr/local/lib/python3.7/site-packages/iocage_lib/ioc_exec.py", line 268, in __init__
    self.output = list(silent)
  File "/usr/local/lib/python3.7/site-packages/iocage_lib/ioc_exec.py", line 260, in exec_jail
    list(stderr_queue)
iocage_lib.ioc_exceptions.CommandFailed: [b'', b'', b'', b'', b'', b'', b'', b'', b'', b'', b'', b'', b'', b'', b'', b'', b'', b'', b'', b'', b'', b'', b'', b'', b'', b'', b'', b'', b'', b'']

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/middlewared/job.py", line 349, in run
    await self.future
  File "/usr/local/lib/python3.7/site-packages/middlewared/job.py", line 387, in __run_body
    rv = await self.middleware.run_in_thread(self.method, *([self] + args))
  File "/usr/local/lib/python3.7/site-packages/middlewared/utils/run_in_thread.py", line 10, in run_in_thread
    return await self.loop.run_in_executor(self.run_in_thread_executor, functools.partial(method, *args, **kwargs))
  File "/usr/local/lib/python3.7/site-packages/middlewared/utils/io_thread_pool_executor.py", line 25, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/schema.py", line 965, in nf
    return f(*args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/jail.py", line 409, in available
    plugins_versions_data = IOCPlugin(branch=branch, git_repository=plugin_repository).fetch_plugin_versions()
  File "/usr/local/lib/python3.7/site-packages/iocage_lib/ioc_plugin.py", line 266, in fetch_plugin_versions
    self.pull_clone_git_repo()
  File "/usr/local/lib/python3.7/site-packages/iocage_lib/ioc_plugin.py", line 137, in pull_clone_git_repo
    depth, self.callback
  File "/usr/local/lib/python3.7/site-packages/iocage_lib/ioc_plugin.py", line 1631, in _clone_repo
    k: v for k, v in kwargs.items() if v
  File "/usr/local/lib/python3.7/site-packages/git/repo/base.py", line 988, in clone_from
    return cls._clone(git, url, to_path, GitCmdObjectDB, progress, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/git/repo/base.py", line 939, in _clone
    finalize_process(proc, stderr=stderr)
  File "/usr/local/lib/python3.7/site-packages/git/util.py", line 333, in finalize_process
    proc.wait(**kwargs)
  File "/usr/local/lib/python3.7/site-packages/git/cmd.py", line 415, in wait
    raise GitCommandError(self.args, status, errstr)
git.exc.GitCommandError: Cmd('git') failed due to: exit code(128)
  cmdline: git clone -v https://github.com/ix-plugin-hub/iocage-plugin-index.git /mnt/AppData1/iocage/.plugins/github_com_ix-plugin-hub_iocage-plugin-index_git
  stderr: 'fatal: destination path '/mnt/AppData1/iocage/.plugins/github_com_ix-plugin-hub_iocage-plugin-index_git' already exists and is not an empty directory.
'
 
Last edited:

anodos

Sambassador
iXsystems
Joined
Mar 6, 2014
Messages
7,200
Once again we're unable to kinit because we can't find a KDC through DNS. Checking for LDAP SRV records won't help in this case (host -t srv _ldap._tcp.our.domain)

Code:
class SRV(enum.Enum):
    DOMAINCONTROLLER = '_ldap._tcp.dc._msdcs.'
    FORESTGLOBALCATALOG = '_ldap._tcp.gc._msdcs.'
    GLOBALCATALOG = '_gc._tcp.'
    KERBEROS = '_kerberos._tcp.'
    KERBEROSDOMAINCONTROLLER = '_kerberos._tcp.dc._msdcs.'
    KPASSWD = '_kpasswd._tcp.'
    LDAP = '_ldap._tcp.'
    PDC = '_ldap._tcp.pdc._msdcs.'


If you can look up a KDC through DNS successfully, then remove any kerberos realms you may have added in our GUI and start over with the AD form.
 

andrewjones216

Junior Member
Joined
Jun 7, 2016
Messages
15
Hi anodos,

Once again we're unable to kinit because we can't find a KDC through DNS. Checking for LDAP SRV records won't help in this case (host -t srv _ldap._tcp.our.domain)

root@CNAS05:~ # nslookup cwm-dc-01
Server: xxx.xxx.11.51
Address: xxx.xxx.11.51#53
Name: cwm-dc-01.our.domain
Address: xxx.xxx.11.51

root@CNAS05:~ # nslookup cwm-dc-02
Server: xxx.xxx.11.51
Address: xxx.xxx.11.51#53
Name: cwm-dc-02.our.domain
Address: xxx.xxx.11.52

root@CNAS05:~ # host -t srv _ldap._tcp.dc._msdcs.our.domain
_ldap._tcp.dc._msdcs.our.domain has SRV record 0 100 389 cwm-dc-02.our.domain.
_ldap._tcp.dc._msdcs.our.domain has SRV record 0 100 389 cdc01.our.domain.
_ldap._tcp.dc._msdcs.our.domain has SRV record 0 100 389 CWM-DC-02.our.domain.
_ldap._tcp.dc._msdcs.our.domain has SRV record 0 100 389 CWM-DC-01.our.domain.
_ldap._tcp.dc._msdcs.our.domain has SRV record 0 100 389 cwm-dc-01.our.domain.

root@CNAS05:~ # host -t srv _ldap._tcp.gc._msdcs.our.domain
_ldap._tcp.gc._msdcs.our.domain has SRV record 0 100 3268 CWM-DC-02.our.domain.
_ldap._tcp.gc._msdcs.our.domain has SRV record 0 100 3268 CWM-DC-01.our.domain.
_ldap._tcp.gc._msdcs.our.domain has SRV record 0 100 3268 cdc01.our.domain.
_ldap._tcp.gc._msdcs.our.domain has SRV record 0 100 3268 cwm-dc-02.our.domain.
_ldap._tcp.gc._msdcs.our.domain has SRV record 0 100 3268 cwm-dc-01.our.domain.

root@CNAS05:~ # host -t srv _gc._tcp.our.domain
_gc._tcp.our.domain has SRV record 0 100 3268 cwm-dc-02.our.domain.
_gc._tcp.our.domain has SRV record 0 100 3268 cwm-dc-01.our.domain.
_gc._tcp.our.domain has SRV record 0 100 3268 CWM-DC-01.our.domain.
_gc._tcp.our.domain has SRV record 0 100 3268 CWM-DC-02.our.domain.
_gc._tcp.our.domain has SRV record 0 100 3268 cdc01.our.domain.

root@CNAS05:~ # host -t srv _kerberos._tcp.our.domain
_kerberos._tcp.our.domain has SRV record 0 100 88 cdc01.our.domain.
_kerberos._tcp.our.domain has SRV record 0 100 88 CWM-DC-01.our.domain.
_kerberos._tcp.our.domain has SRV record 0 100 88 CWM-DC-02.our.domain.
_kerberos._tcp.our.domain has SRV record 0 100 88 cwm-dc-01.our.domain.
_kerberos._tcp.our.domain has SRV record 0 100 88 cwm-dc-02.our.domain.

root@CNAS05:~ # host -t srv _kerberos._tcp.dc._msdcs.our.domain
_kerberos._tcp.dc._msdcs.our.domain has SRV record 0 100 88 cwm-dc-02.our.domain.
_kerberos._tcp.dc._msdcs.our.domain has SRV record 0 100 88 CWM-DC-02.our.domain.
_kerberos._tcp.dc._msdcs.our.domain has SRV record 0 100 88 CWM-DC-01.our.domain.
_kerberos._tcp.dc._msdcs.our.domain has SRV record 0 100 88 cwm-dc-01.our.domain.
_kerberos._tcp.dc._msdcs.our.domain has SRV record 0 100 88 cdc01.our.domain.

root@CNAS05:~ # host -t srv _kpasswd._tcp.our.domain
_kpasswd._tcp.our.domain has SRV record 0 100 464 cwm-dc-02.our.domain.
_kpasswd._tcp.our.domain has SRV record 0 100 464 CWM-DC-02.our.domain.
_kpasswd._tcp.our.domain has SRV record 0 100 464 cwm-dc-01.our.domain.
_kpasswd._tcp.our.domain has SRV record 0 100 464 CWM-DC-01.our.domain.
_kpasswd._tcp.our.domain has SRV record 0 100 464 cdc01.our.domain.

root@CNAS05:~ # host -t srv _ldap._tcp.our.domain
_ldap._tcp.our.domain has SRV record 0 100 389 cwm-dc-02.our.domain.
_ldap._tcp.our.domain has SRV record 0 100 389 CWM-DC-01.our.domain.
_ldap._tcp.our.domain has SRV record 0 100 389 CWM-DC-02.our.domain.
_ldap._tcp.our.domain has SRV record 0 100 389 cdc01.our.domain.
_ldap._tcp.our.domain has SRV record 0 100 389 cwm-dc-01.our.domain.

root@CNAS05:~ # host -t srv _ldap._tcp.pdc._msdcs.our.domain
_ldap._tcp.pdc._msdcs.our.domain has SRV record 0 100 389 CWM-DC-02.our.domain.


If you can look up a KDC through DNS successfully, then remove any kerberos realms you may have added in our GUI and start over with the AD form.

Can successfully lookup KDC through DNS. No Kerberos Realm to delete in the GUI:

image2.png


Tried to add to the domain and failed with the same error as before.


Cheers
Andrew
 

andrewjones216

Junior Member
Joined
Jun 7, 2016
Messages
15
Hi all,

Any idea what's happening here? Could really do with resolving this one!


Cheers
Andrew
 

anodos

Sambassador
iXsystems
Joined
Mar 6, 2014
Messages
7,200
Is this Microsoft AD or Samba AD?
You could bypass the DNS lookup options in the base kerberos and see if that gets past your validation issues. You can achieve this by manually generating a realm entry for your realm (make sure you put in realm name in ALL CAPS -- kerberos is case-sensitive for realm name and convention is to use upper-case), then hard-code the fqdn for one or more of your DCs for each of the kerberos-related servers.

Then add appropriate auxiliary parameters to disable DNS lookups for kerberos info:
Code:
              dns_lookup_kdc = boolean
               Use DNS SRV records to lookup KDC services loca-
               tion.

              dns_lookup_realm = boolean
               Use DNS TXT records to lookup domain    to realm map-
               pings.

^^^ these are some supported libdefaults parameters for kerberos config. See manpage here: https://www.freebsd.org/cgi/man.cgi...FreeBSD+12.1-RELEASE&arch=default&format=html

These steps should not be required. Also, please revert any changes made to OS files to try to troubleshoot the issue.
 

andrewjones216

Junior Member
Joined
Jun 7, 2016
Messages
15
Hi anodos,

Is this Microsoft AD or Samba AD?
Microsoft AD (Server 2019 - 2016 AD)

Below are screenshots of the Kerberos Realm and Aux Parameters set, also the error generated by trying to connect to the domain.
What I don't understand is that we have another box with the same version of FreeNAS in the same subnet connected to AD fine.

1600766599963.png


1600766563341.png


1600766612462.png


1600766658213.png


I've also taken the middlewared.log from when I started entering these settings:

Code:
[2020/09/21 17:40:05] (DEBUG) urllib3.connectionpool._new_conn():959 - Starting new HTTPS connection (1): update-master.ixsystems.com:443
[2020/09/21 17:40:05] (WARNING) UpdateService.get_trains():297 - Failed to retrieve trains redirection
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/urllib3/connection.py", line 157, in _new_conn
    (self._dns_host, self.port), self.timeout, **extra_kw
  File "/usr/local/lib/python3.7/site-packages/urllib3/util/connection.py", line 84, in create_connection
    raise err
  File "/usr/local/lib/python3.7/site-packages/urllib3/util/connection.py", line 74, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 61] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 672, in urlopen
    chunked=chunked,
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 376, in _make_request
    self._validate_conn(conn)
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 994, in _validate_conn
    conn.connect()
  File "/usr/local/lib/python3.7/site-packages/urllib3/connection.py", line 334, in connect
    conn = self._new_conn()
  File "/usr/local/lib/python3.7/site-packages/urllib3/connection.py", line 169, in _new_conn
    self, "Failed to establish a new connection: %s" % e
urllib3.exceptions.NewConnectionError: <urllib3.connection.VerifiedHTTPSConnection object at 0x8b0b5e750>: Failed to establish a new connection: [Errno 61] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/requests/adapters.py", line 449, in send
    timeout=timeout
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 720, in urlopen
    method, url, error=e, _pool=self, _stacktrace=sys.exc_info()[2]
  File "/usr/local/lib/python3.7/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: /FreeNAS/trains_redir.json (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x8b0b5e750>: Failed to establish a new connection: [Errno 61] Connection refused'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 295, in get_trains
    redir_trains = self._get_redir_trains()
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 277, in _get_redir_trains
    timeout=5,
  File "/usr/local/lib/python3.7/site-packages/requests/api.py", line 75, in get
    return request('get', url, params=params, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/api.py", line 60, in request
    return session.request(method=method, url=url, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 533, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/local/lib/python3.7/site-packages/raven/breadcrumbs.py", line 341, in send
    resp = real_send(self, request, *args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 646, in send
    r = adapter.send(request, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/adapters.py", line 516, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPSConnectionPool(host='update-master.ixsystems.com', port=443): Max retries exceeded with url: /FreeNAS/trains_redir.json (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x8b0b5e750>: Failed to establish a new connection: [Errno 61] Connection refused'))
[2020/09/21 17:40:05] (DEBUG) freenasOS.Configuration.TryGetNetworkFile():606 - TryGetNetworkFile(['https://update.ixsystems.com/FreeNAS/trains.txt', 'https://update-master.ixsystems.com/FreeNAS/trains.txt'])
[2020/09/21 17:40:05] (DEBUG) urllib3.connectionpool._new_conn():959 - Starting new HTTPS connection (1): update.ixsystems.com:443
[2020/09/21 17:40:06] (ERROR) freenasOS.Configuration.TryGetNetworkFile():692 - Unable to connect to url https://update.ixsystems.com/FreeNAS/trains.txt: HTTPSConnectionPool(host='update.ixsystems.com', port=443): Max retries exceeded with url: /FreeNAS/trains.txt (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x8b1a43410>: Failed to establish a new connection: [Errno 61] Connection refused'))
[2020/09/21 17:40:06] (DEBUG) urllib3.connectionpool._new_conn():959 - Starting new HTTPS connection (1): update-master.ixsystems.com:443
[2020/09/21 17:40:06] (ERROR) freenasOS.Configuration.TryGetNetworkFile():692 - Unable to connect to url https://update-master.ixsystems.com/FreeNAS/trains.txt: HTTPSConnectionPool(host='update-master.ixsystems.com', port=443): Max retries exceeded with url: /FreeNAS/trains.txt (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x8b1a4bad0>: Failed to establish a new connection: [Errno 61] Connection refused'))
[2020/09/21 17:40:06] (ERROR) freenasOS.Configuration.TryGetNetworkFile():709 - Unable to load ['https://update.ixsystems.com/FreeNAS/trains.txt', 'https://update-master.ixsystems.com/FreeNAS/trains.txt']: Unable to connect to url https://update-master.ixsystems.com/FreeNAS/trains.txt
[2020/09/21 17:40:06] (WARNING) application.call_method():168 - Exception while calling update.check_available(*[])
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 130, in call_method
    io_thread=False)
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1098, in _call
    return await run_method(methodobj, *args)
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1022, in _run_in_conn_threadpool
    return await self.run_in_executor(self.__ws_threadpool, method, *args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1010, in run_in_executor
    return await loop.run_in_executor(pool, functools.partial(method, *args, **kwargs))
  File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/schema.py", line 965, in nf
    return f(*args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 422, in check_available
    trains = self.middleware.call_sync('update.get_trains')
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1157, in call_sync
    io_thread=True, job_on_progress_cb=job_on_progress_cb,
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1180, in run_coroutine
    return fut.result()
  File "/usr/local/lib/python3.7/concurrent/futures/_base.py", line 428, in result
    return self.__get_result()
  File "/usr/local/lib/python3.7/concurrent/futures/_base.py", line 384, in __get_result
    raise self._exception
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1098, in _call
    return await run_method(methodobj, *args)
  File "/usr/local/lib/python3.7/site-packages/middlewared/utils/run_in_thread.py", line 10, in run_in_thread
    return await self.loop.run_in_executor(self.run_in_thread_executor, functools.partial(method, *args, **kwargs))
  File "/usr/local/lib/python3.7/site-packages/middlewared/utils/io_thread_pool_executor.py", line 25, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/schema.py", line 965, in nf
    return f(*args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 302, in get_trains
    for name, descr in (conf.AvailableTrains() or {}).items():
  File "/usr/local/lib/freenasOS/Configuration.py", line 987, in AvailableTrains
    fileref = self.TryGetNetworkFile(file=TRAIN_FILE, reason="FetchTrains")
  File "/usr/local/lib/freenasOS/Configuration.py", line 710, in TryGetNetworkFile
    raise url_exc
freenasOS.Exceptions.UpdateNetworkConnectionException: Unable to connect to url https://update-master.ixsystems.com/FreeNAS/trains.txt
[2020/09/21 17:40:06] (DEBUG) application.__crash_reporting():173 - [Crash Reporting] is disabled using sentinel file.
[2020/09/21 17:42:19] (DEBUG) urllib3.connectionpool._new_conn():959 - Starting new HTTPS connection (1): update-master.ixsystems.com:443
[2020/09/21 17:42:19] (WARNING) UpdateService.get_trains():297 - Failed to retrieve trains redirection
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/urllib3/connection.py", line 157, in _new_conn
    (self._dns_host, self.port), self.timeout, **extra_kw
  File "/usr/local/lib/python3.7/site-packages/urllib3/util/connection.py", line 84, in create_connection
    raise err
  File "/usr/local/lib/python3.7/site-packages/urllib3/util/connection.py", line 74, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 61] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 672, in urlopen
    chunked=chunked,
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 376, in _make_request
    self._validate_conn(conn)
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 994, in _validate_conn
    conn.connect()
  File "/usr/local/lib/python3.7/site-packages/urllib3/connection.py", line 334, in connect
    conn = self._new_conn()
  File "/usr/local/lib/python3.7/site-packages/urllib3/connection.py", line 169, in _new_conn
    self, "Failed to establish a new connection: %s" % e
urllib3.exceptions.NewConnectionError: <urllib3.connection.VerifiedHTTPSConnection object at 0x8b1a9a410>: Failed to establish a new connection: [Errno 61] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/requests/adapters.py", line 449, in send
    timeout=timeout
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 720, in urlopen
    method, url, error=e, _pool=self, _stacktrace=sys.exc_info()[2]
  File "/usr/local/lib/python3.7/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: /FreeNAS/trains_redir.json (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x8b1a9a410>: Failed to establish a new connection: [Errno 61] Connection refused'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 295, in get_trains
    redir_trains = self._get_redir_trains()
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 277, in _get_redir_trains
    timeout=5,
  File "/usr/local/lib/python3.7/site-packages/requests/api.py", line 75, in get
    return request('get', url, params=params, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/api.py", line 60, in request
    return session.request(method=method, url=url, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 533, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/local/lib/python3.7/site-packages/raven/breadcrumbs.py", line 341, in send
    resp = real_send(self, request, *args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 646, in send
    r = adapter.send(request, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/adapters.py", line 516, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPSConnectionPool(host='update-master.ixsystems.com', port=443): Max retries exceeded with url: /FreeNAS/trains_redir.json (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x8b1a9a410>: Failed to establish a new connection: [Errno 61] Connection refused'))
[2020/09/21 17:42:19] (DEBUG) freenasOS.Configuration.TryGetNetworkFile():606 - TryGetNetworkFile(['https://update.ixsystems.com/FreeNAS/trains.txt', 'https://update-master.ixsystems.com/FreeNAS/trains.txt'])
[2020/09/21 17:42:19] (DEBUG) urllib3.connectionpool._new_conn():959 - Starting new HTTPS connection (1): update.ixsystems.com:443
[2020/09/21 17:42:19] (ERROR) freenasOS.Configuration.TryGetNetworkFile():692 - Unable to connect to url https://update.ixsystems.com/FreeNAS/trains.txt: HTTPSConnectionPool(host='update.ixsystems.com', port=443): Max retries exceeded with url: /FreeNAS/trains.txt (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x8b1a00d90>: Failed to establish a new connection: [Errno 61] Connection refused'))
[2020/09/21 17:42:19] (DEBUG) urllib3.connectionpool._new_conn():959 - Starting new HTTPS connection (1): update-master.ixsystems.com:443
[2020/09/21 17:42:19] (ERROR) freenasOS.Configuration.TryGetNetworkFile():692 - Unable to connect to url https://update-master.ixsystems.com/FreeNAS/trains.txt: HTTPSConnectionPool(host='update-master.ixsystems.com', port=443): Max retries exceeded with url: /FreeNAS/trains.txt (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x8b1a821d0>: Failed to establish a new connection: [Errno 61] Connection refused'))
[2020/09/21 17:42:19] (ERROR) freenasOS.Configuration.TryGetNetworkFile():709 - Unable to load ['https://update.ixsystems.com/FreeNAS/trains.txt', 'https://update-master.ixsystems.com/FreeNAS/trains.txt']: Unable to connect to url https://update-master.ixsystems.com/FreeNAS/trains.txt
[2020/09/21 17:42:19] (WARNING) application.call_method():168 - Exception while calling update.check_available(*[])
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 130, in call_method
    io_thread=False)
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1098, in _call
    return await run_method(methodobj, *args)
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1022, in _run_in_conn_threadpool
    return await self.run_in_executor(self.__ws_threadpool, method, *args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1010, in run_in_executor
    return await loop.run_in_executor(pool, functools.partial(method, *args, **kwargs))
  File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/schema.py", line 965, in nf
    return f(*args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 422, in check_available
    trains = self.middleware.call_sync('update.get_trains')
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1157, in call_sync
    io_thread=True, job_on_progress_cb=job_on_progress_cb,
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1180, in run_coroutine
    return fut.result()
  File "/usr/local/lib/python3.7/concurrent/futures/_base.py", line 428, in result
    return self.__get_result()
  File "/usr/local/lib/python3.7/concurrent/futures/_base.py", line 384, in __get_result
    raise self._exception
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1098, in _call
    return await run_method(methodobj, *args)
  File "/usr/local/lib/python3.7/site-packages/middlewared/utils/run_in_thread.py", line 10, in run_in_thread
    return await self.loop.run_in_executor(self.run_in_thread_executor, functools.partial(method, *args, **kwargs))
  File "/usr/local/lib/python3.7/site-packages/middlewared/utils/io_thread_pool_executor.py", line 25, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/schema.py", line 965, in nf
    return f(*args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 302, in get_trains
    for name, descr in (conf.AvailableTrains() or {}).items():
  File "/usr/local/lib/freenasOS/Configuration.py", line 987, in AvailableTrains
    fileref = self.TryGetNetworkFile(file=TRAIN_FILE, reason="FetchTrains")
  File "/usr/local/lib/freenasOS/Configuration.py", line 710, in TryGetNetworkFile
    raise url_exc
freenasOS.Exceptions.UpdateNetworkConnectionException: Unable to connect to url https://update-master.ixsystems.com/FreeNAS/trains.txt
[2020/09/21 17:42:19] (DEBUG) application.__crash_reporting():173 - [Crash Reporting] is disabled using sentinel file.
[2020/09/21 17:45:04] (DEBUG) ServiceService._simplecmd():286 - Calling: restart(cron)
[2020/09/21 17:45:04] (DEBUG) EtcService.generate():275 - No new changes for /etc/crontab
[2020/09/21 17:45:39] (DEBUG) urllib3.connectionpool._new_conn():959 - Starting new HTTPS connection (1): update-master.ixsystems.com:443
[2020/09/21 17:45:39] (WARNING) UpdateService.get_trains():297 - Failed to retrieve trains redirection
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/urllib3/connection.py", line 157, in _new_conn
    (self._dns_host, self.port), self.timeout, **extra_kw
  File "/usr/local/lib/python3.7/site-packages/urllib3/util/connection.py", line 84, in create_connection
    raise err
  File "/usr/local/lib/python3.7/site-packages/urllib3/util/connection.py", line 74, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 61] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 672, in urlopen
    chunked=chunked,
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 376, in _make_request
    self._validate_conn(conn)
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 994, in _validate_conn
    conn.connect()
  File "/usr/local/lib/python3.7/site-packages/urllib3/connection.py", line 334, in connect
    conn = self._new_conn()
  File "/usr/local/lib/python3.7/site-packages/urllib3/connection.py", line 169, in _new_conn
    self, "Failed to establish a new connection: %s" % e
urllib3.exceptions.NewConnectionError: <urllib3.connection.VerifiedHTTPSConnection object at 0x8b0bd0450>: Failed to establish a new connection: [Errno 61] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/requests/adapters.py", line 449, in send
    timeout=timeout
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 720, in urlopen
    method, url, error=e, _pool=self, _stacktrace=sys.exc_info()[2]
  File "/usr/local/lib/python3.7/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: /FreeNAS/trains_redir.json (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x8b0bd0450>: Failed to establish a new connection: [Errno 61] Connection refused'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 295, in get_trains
    redir_trains = self._get_redir_trains()
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 277, in _get_redir_trains
    timeout=5,
  File "/usr/local/lib/python3.7/site-packages/requests/api.py", line 75, in get
    return request('get', url, params=params, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/api.py", line 60, in request
    return session.request(method=method, url=url, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 533, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/local/lib/python3.7/site-packages/raven/breadcrumbs.py", line 341, in send
    resp = real_send(self, request, *args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 646, in send
    r = adapter.send(request, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/adapters.py", line 516, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPSConnectionPool(host='update-master.ixsystems.com', port=443): Max retries exceeded with url: /FreeNAS/trains_redir.json (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x8b0bd0450>: Failed to establish a new connection: [Errno 61] Connection refused'))
[2020/09/21 17:45:39] (DEBUG) freenasOS.Configuration.TryGetNetworkFile():606 - TryGetNetworkFile(['https://update.ixsystems.com/FreeNAS/trains.txt', 'https://update-master.ixsystems.com/FreeNAS/trains.txt'])
[2020/09/21 17:45:39] (DEBUG) urllib3.connectionpool._new_conn():959 - Starting new HTTPS connection (1): update.ixsystems.com:443
[2020/09/21 17:45:39] (ERROR) freenasOS.Configuration.TryGetNetworkFile():692 - Unable to connect to url https://update.ixsystems.com/FreeNAS/trains.txt: HTTPSConnectionPool(host='update.ixsystems.com', port=443): Max retries exceeded with url: /FreeNAS/trains.txt (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x8b0be6810>: Failed to establish a new connection: [Errno 61] Connection refused'))
[2020/09/21 17:45:39] (DEBUG) urllib3.connectionpool._new_conn():959 - Starting new HTTPS connection (1): update-master.ixsystems.com:443
[2020/09/21 17:45:39] (ERROR) freenasOS.Configuration.TryGetNetworkFile():692 - Unable to connect to url https://update-master.ixsystems.com/FreeNAS/trains.txt: HTTPSConnectionPool(host='update-master.ixsystems.com', port=443): Max retries exceeded with url: /FreeNAS/trains.txt (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x8b0be6a90>: Failed to establish a new connection: [Errno 61] Connection refused'))
[2020/09/21 17:45:39] (ERROR) freenasOS.Configuration.TryGetNetworkFile():709 - Unable to load ['https://update.ixsystems.com/FreeNAS/trains.txt', 'https://update-master.ixsystems.com/FreeNAS/trains.txt']: Unable to connect to url https://update-master.ixsystems.com/FreeNAS/trains.txt
[2020/09/21 17:45:39] (WARNING) application.call_method():168 - Exception while calling update.check_available(*[])
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 130, in call_method
    io_thread=False)
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1098, in _call
    return await run_method(methodobj, *args)
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1022, in _run_in_conn_threadpool
    return await self.run_in_executor(self.__ws_threadpool, method, *args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1010, in run_in_executor
    return await loop.run_in_executor(pool, functools.partial(method, *args, **kwargs))
  File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/schema.py", line 965, in nf
    return f(*args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 422, in check_available
    trains = self.middleware.call_sync('update.get_trains')
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1157, in call_sync
    io_thread=True, job_on_progress_cb=job_on_progress_cb,
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1180, in run_coroutine
    return fut.result()
  File "/usr/local/lib/python3.7/concurrent/futures/_base.py", line 428, in result
    return self.__get_result()
  File "/usr/local/lib/python3.7/concurrent/futures/_base.py", line 384, in __get_result
    raise self._exception
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1098, in _call
    return await run_method(methodobj, *args)
  File "/usr/local/lib/python3.7/site-packages/middlewared/utils/run_in_thread.py", line 10, in run_in_thread
    return await self.loop.run_in_executor(self.run_in_thread_executor, functools.partial(method, *args, **kwargs))
  File "/usr/local/lib/python3.7/site-packages/middlewared/utils/io_thread_pool_executor.py", line 25, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/schema.py", line 965, in nf
    return f(*args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 302, in get_trains
    for name, descr in (conf.AvailableTrains() or {}).items():
  File "/usr/local/lib/freenasOS/Configuration.py", line 987, in AvailableTrains
    fileref = self.TryGetNetworkFile(file=TRAIN_FILE, reason="FetchTrains")
  File "/usr/local/lib/freenasOS/Configuration.py", line 710, in TryGetNetworkFile
    raise url_exc
freenasOS.Exceptions.UpdateNetworkConnectionException: Unable to connect to url https://update-master.ixsystems.com/FreeNAS/trains.txt
[2020/09/21 17:45:39] (DEBUG) application.__crash_reporting():173 - [Crash Reporting] is disabled using sentinel file.
[2020/09/21 17:59:05] (DEBUG) EtcService.generate():275 - No new changes for /etc/krb5.conf


I also took a debug after trying to connect using the settings above, I've attached the ActiveDirectory one in the next post. It seems to be checking the workgroup for a trust secret (still) instead of the domain.
 

andrewjones216

Junior Member
Joined
Jun 7, 2016
Messages
15
ActiveDirectory debug:


Code:
+--------------------------------------------------------------------------------+
+                      Active Directory Status @1600707853                       +
+--------------------------------------------------------------------------------+
Active Directory is DISABLED
debug finished in 0 seconds for Active Directory Status


+--------------------------------------------------------------------------------+
+                    Active Directory Run Status @1600707853                     +
+--------------------------------------------------------------------------------+
nmbd is running as pid 23133.
smbd is running as pid 23114.
winbindd is running as pid 23125.
+--------------------------------------------------------------------------------+
+                                   @1600707853                                  +
+--------------------------------------------------------------------------------+
+--------------------------------------------------------------------------------+
+                         SMB Service Status @1600707853                         +
+--------------------------------------------------------------------------------+
SMB will start on boot.
debug finished in 0 seconds for SMB Service Status


+--------------------------------------------------------------------------------+
+                     Active Directory Settings @1600707853                      +
+--------------------------------------------------------------------------------+
{
  "id": 1,
  "domainname": "OUR.DOMAIN",
  "bindname": "username",
  "ssl": "OFF",
  "certificate": null,
  "validate_certificates": true,
  "verbose_logging": true,
  "allow_trusted_doms": false,
  "use_default_domain": true,
  "allow_dns_updates": false,
  "disable_freenas_cache": false,
  "site": "",
  "kerberos_realm": null,
  "kerberos_principal": "",
  "createcomputer": "",
  "timeout": 5000,
  "dns_timeout": 5000,
  "idmap_backend": "RID",
  "nss_info": null,
  "ldap_sasl_wrapping": "SIGN",
  "enable": false,
  "netbiosname": "CNAS05",
  "netbiosalias": []
}
debug finished in 0 seconds for Active Directory Settings


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

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


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


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 @1600707853                      +
+--------------------------------------------------------------------------------+


[global]
        dns proxy = No
        aio max threads = 2
        max log size = 51200
        allocation roundup size = 0
        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 = 3
        obey pam restrictions = False
        enable web service discovery = True
        logging = file
        server min protocol = SMB2_02
        unix extensions = No
        map to guest = Bad User
        server string = CNAS05 FreeNAS Storage Server
        bind interfaces only = Yes
        netbios name = CNAS05
        netbios aliases =
        server role = standalone
        workgroup = our.workgroup
        idmap config *: backend = tdb
        idmap config *: range = 90000001-100000000

        include = /usr/local/etc/smb4_share.conf
debug finished in 0 seconds for /usr/local/etc/smb4.conf


+--------------------------------------------------------------------------------+
+                     Kerberos Tickets - 'klist' @1600707853                     +
+--------------------------------------------------------------------------------+
klist: No ticket file: /tmp/krb5cc_0
debug finished in 0 seconds for Kerberos Tickets - 'klist'


+--------------------------------------------------------------------------------+
+                   Kerberos Principals - 'ktutil' @1600707853                   +
+--------------------------------------------------------------------------------+
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' @1600707853             +
+--------------------------------------------------------------------------------+
wbcCheckTrustCredentials(our.workgroup): 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 our.workgroup via RPC calls failed
debug finished in 0 seconds for Active Directory Trust Secret - 'wbinfo -t'


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


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


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


+--------------------------------------------------------------------------------+
+        Active Directory own domain - 'wbinfo --own-domain' @1600707853         +
+--------------------------------------------------------------------------------+
our.workgroup
debug finished in 0 seconds for Active Directory own domain - 'wbinfo --own-domain'


+--------------------------------------------------------------------------------+
+     Active Directory online status - 'wbinfo --online-status' @1600707853      +
+--------------------------------------------------------------------------------+
BUILTIN : active connection
CNAS05 : active connection
debug finished in 1 seconds for Active Directory online status - 'wbinfo --online-status'


+--------------------------------------------------------------------------------+
+     Active Directory domain info - 'wbinfo --domain-info=our.workgroup' @1600707854      +
+--------------------------------------------------------------------------------+
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=our.workgroup'


+--------------------------------------------------------------------------------+
+  Active Directory DC name - 'wbinfo --dsgetdcname="OUR.DOMAIN"' @1600707854  +
+--------------------------------------------------------------------------------+
Could not find dc for "OUR.DOMAIN"
debug finished in 2 seconds for Active Directory DC name - 'wbinfo --dsgetdcname="OUR.DOMAIN"'


+--------------------------------------------------------------------------------+
+         Active Directory DC info - 'wbinfo --dc-info=our.workgroup' @1600707856          +
+--------------------------------------------------------------------------------+
Could not find dc info our.workgroup
debug finished in 0 seconds for Active Directory DC info - 'wbinfo --dc-info=our.workgroup'


+--------------------------------------------------------------------------------+
+                Active Directory Users - 'wbinfo -u' @1600707856                +
+--------------------------------------------------------------------------------+
Error looking up domain users
+--------------------------------------------------------------------------------+
+               Active Directory Groups - 'wbinfo -g' @1600707856                +
+--------------------------------------------------------------------------------+
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 @1600707856                      +
+--------------------------------------------------------------------------------+
[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.7/site-packages/middlewared/main.py", line 130, in call_method
    io_thread=False)
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1084, in _call
    return await methodobj(*args)
  File "/usr/local/lib/python3.7/site-packages/middlewared/schema.py", line 961, in nf
    return await f(*args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/activedirectory.py", line 1370, in get_spn_list
    f"Failed to generate SPN list: [{netads.stderr.decode().strip()}]"
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 4 seconds for Active Directory SPN list
 

andrewjones216

Junior Member
Joined
Jun 7, 2016
Messages
15
Hi all,

Following on my last posts we have upgraded our NAS to 11.3-U5. When joining the domain once again this happened:

1604584712109.png


So I pulled the middleware log, which did have some different errors. In particular the error "SASL GSSAPI bind failed" is in there a couple of times. The interface than stopped responding for around 45 mins before letting me log back in:


Code:
[2020/11/03 17:51:37] (DEBUG) application.__crash_reporting():173 - [Crash Reporting] is disabled using sentinel file.
[2020/11/03 17:53:22] (DEBUG) EtcService.generate():275 - No new changes for /etc/krb5.conf
[2020/11/03 18:06:18] (DEBUG) ActiveDirectoryService.get_n_working_servers():167 - Request for [1] of server type [PDC] returned: [{'host': 'CWM-DC-02.our.domain', 'port': 389}]
[2020/11/03 18:06:18] (DEBUG) ActiveDirectoryService.start():953 - Starting Active Directory service for [OUR.DOMAIN]
[2020/11/03 18:06:31] (DEBUG) urllib3.connectionpool._new_conn():959 - Starting new HTTPS connection (1): update-master.ixsystems.com:443
[2020/11/03 18:06:32] (WARNING) UpdateService.get_trains():297 - Failed to retrieve trains redirection
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/urllib3/connection.py", line 157, in _new_conn
    (self._dns_host, self.port), self.timeout, **extra_kw
  File "/usr/local/lib/python3.7/site-packages/urllib3/util/connection.py", line 84, in create_connection
    raise err
  File "/usr/local/lib/python3.7/site-packages/urllib3/util/connection.py", line 74, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 61] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 672, in urlopen
    chunked=chunked,
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 376, in _make_request
    self._validate_conn(conn)
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 994, in _validate_conn
    conn.connect()
  File "/usr/local/lib/python3.7/site-packages/urllib3/connection.py", line 334, in connect
    conn = self._new_conn()
  File "/usr/local/lib/python3.7/site-packages/urllib3/connection.py", line 169, in _new_conn
    self, "Failed to establish a new connection: %s" % e
urllib3.exceptions.NewConnectionError: <urllib3.connection.VerifiedHTTPSConnection object at 0x836c56850>: Failed to establish a new connection: [Errno 61] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/requests/adapters.py", line 449, in send
    timeout=timeout
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 720, in urlopen
    method, url, error=e, _pool=self, _stacktrace=sys.exc_info()[2]
  File "/usr/local/lib/python3.7/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: /FreeNAS/trains_redir.json (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x836c56850>: Failed to establish a new connection: [Errno 61] Connection refused'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 295, in get_trains
    redir_trains = self._get_redir_trains()
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 277, in _get_redir_trains
    timeout=5,
  File "/usr/local/lib/python3.7/site-packages/requests/api.py", line 75, in get
    return request('get', url, params=params, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/api.py", line 60, in request
    return session.request(method=method, url=url, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 533, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/local/lib/python3.7/site-packages/raven/breadcrumbs.py", line 341, in send
    resp = real_send(self, request, *args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 646, in send
    r = adapter.send(request, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/adapters.py", line 516, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPSConnectionPool(host='update-master.ixsystems.com', port=443): Max retries exceeded with url: /FreeNAS/trains_redir.json (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x836c56850>: Failed to establish a new connection: [Errno 61] Connection refused'))
[2020/11/03 18:06:32] (DEBUG) freenasOS.Configuration.TryGetNetworkFile():606 - TryGetNetworkFile(['https://update.ixsystems.com/FreeNAS/trains.txt', 'https://update-master.ixsystems.com/FreeNAS/trains.txt'])
[2020/11/03 18:06:32] (DEBUG) urllib3.connectionpool._new_conn():959 - Starting new HTTPS connection (1): update.ixsystems.com:443
[2020/11/03 18:06:32] (ERROR) freenasOS.Configuration.TryGetNetworkFile():692 - Unable to connect to url https://update.ixsystems.com/FreeNAS/trains.txt: HTTPSConnectionPool(host='update.ixsystems.com', port=443): Max retries exceeded with url: /FreeNAS/trains.txt (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x833438950>: Failed to establish a new connection: [Errno 61] Connection refused'))
[2020/11/03 18:06:32] (DEBUG) urllib3.connectionpool._new_conn():959 - Starting new HTTPS connection (1): update-master.ixsystems.com:443
[2020/11/03 18:06:32] (ERROR) freenasOS.Configuration.TryGetNetworkFile():692 - Unable to connect to url https://update-master.ixsystems.com/FreeNAS/trains.txt: HTTPSConnectionPool(host='update-master.ixsystems.com', port=443): Max retries exceeded with url: /FreeNAS/trains.txt (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x836ae78d0>: Failed to establish a new connection: [Errno 61] Connection refused'))
[2020/11/03 18:06:32] (ERROR) freenasOS.Configuration.TryGetNetworkFile():709 - Unable to load ['https://update.ixsystems.com/FreeNAS/trains.txt', 'https://update-master.ixsystems.com/FreeNAS/trains.txt']: Unable to connect to url https://update-master.ixsystems.com/FreeNAS/trains.txt
[2020/11/03 18:06:32] (WARNING) application.call_method():168 - Exception while calling update.check_available(*[])
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 130, in call_method
    io_thread=False)
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1098, in _call
    return await run_method(methodobj, *args)
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1022, in _run_in_conn_threadpool
    return await self.run_in_executor(self.__ws_threadpool, method, *args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1010, in run_in_executor
    return await loop.run_in_executor(pool, functools.partial(method, *args, **kwargs))
  File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/schema.py", line 965, in nf
    return f(*args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 422, in check_available
    trains = self.middleware.call_sync('update.get_trains')
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1157, in call_sync
    io_thread=True, job_on_progress_cb=job_on_progress_cb,
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1180, in run_coroutine
    return fut.result()
  File "/usr/local/lib/python3.7/concurrent/futures/_base.py", line 428, in result
    return self.__get_result()
  File "/usr/local/lib/python3.7/concurrent/futures/_base.py", line 384, in __get_result
    raise self._exception
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1098, in _call
    return await run_method(methodobj, *args)
  File "/usr/local/lib/python3.7/site-packages/middlewared/utils/run_in_thread.py", line 10, in run_in_thread
    return await self.loop.run_in_executor(self.run_in_thread_executor, functools.partial(method, *args, **kwargs))
  File "/usr/local/lib/python3.7/site-packages/middlewared/utils/io_thread_pool_executor.py", line 25, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/schema.py", line 965, in nf
    return f(*args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/update.py", line 302, in get_trains
    for name, descr in (conf.AvailableTrains() or {}).items():
  File "/usr/local/lib/freenasOS/Configuration.py", line 987, in AvailableTrains
    fileref = self.TryGetNetworkFile(file=TRAIN_FILE, reason="FetchTrains")
  File "/usr/local/lib/freenasOS/Configuration.py", line 710, in TryGetNetworkFile
    raise url_exc
freenasOS.Exceptions.UpdateNetworkConnectionException: Unable to connect to url https://update-master.ixsystems.com/FreeNAS/trains.txt
[2020/11/03 18:06:32] (DEBUG) application.__crash_reporting():173 - [Crash Reporting] is disabled using sentinel file.
[2020/11/03 18:07:34] (DEBUG) ActiveDirectoryService.port_is_listening():105 - connection to cdc01.our.domain failed with error: [Errno 60] Operation timed out
[2020/11/03 18:07:34] (DEBUG) ActiveDirectoryService.get_n_working_servers():167 - Request for [3] of server type [DOMAINCONTROLLER] returned: [{'host': 'cwm-dc-02.our.domain', 'port': 389}, {'host': 'CWM-DC-01.our.domain', 'port': 389}, {'host': 'CWM-DC-02.our.domain', 'port': 389}]
[2020/11/03 18:07:34] (DEBUG) ActiveDirectoryService._open():240 - Successfully initialized LDAP server: [ldap://cwm-dc-02.our.domain:389]
[2020/11/03 18:25:03] (DEBUG) ActiveDirectoryService._open():348 - SASL GSSAPI bind failed.
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/activedirectory.py", line 341, in _open
    self._handle.sasl_gssapi_bind_s()
  File "/usr/local/lib/python3.7/site-packages/ldap/ldapobject.py", line 487, in sasl_gssapi_bind_s
    self.sasl_non_interactive_bind_s('GSSAPI',serverctrls,clientctrls,sasl_flags,authz_id)
  File "/usr/local/lib/python3.7/site-packages/ldap/ldapobject.py", line 475, in sasl_non_interactive_bind_s
    self.sasl_interactive_bind_s('',auth,serverctrls,clientctrls,sasl_flags)
  File "/usr/local/lib/python3.7/site-packages/ldap/ldapobject.py", line 465, in sasl_interactive_bind_s
    return self._ldap_call(self._l.sasl_interactive_bind_s,who,auth,RequestControlTuples(serverctrls),RequestControlTuples(clientctrls),sasl_flags)
  File "/usr/local/lib/python3.7/site-packages/ldap/ldapobject.py", line 329, in _ldap_call
    reraise(exc_type, exc_value, exc_traceback)
  File "/usr/local/lib/python3.7/site-packages/ldap/compat.py", line 44, in reraise
    raise exc_value
  File "/usr/local/lib/python3.7/site-packages/ldap/ldapobject.py", line 313, in _ldap_call
    result = func(*args,**kwargs)
ldap.LOCAL_ERROR: {'desc': 'Local error', 'errno': 60, 'info': 'SASL(-1): generic failure: GSSAPI Error:  Miscellaneous failure (see text)OUR.DOMAIN (unable to reach any KDC in realm OUR.DOMAIN)'}
[2020/11/03 18:25:03] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 18:25:03] (DEBUG) ActiveDirectoryService._open():240 - Successfully initialized LDAP server: [ldap://CWM-DC-01.our.domain:389]
[2020/11/03 18:42:32] (DEBUG) ActiveDirectoryService._open():348 - SASL GSSAPI bind failed.
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/activedirectory.py", line 341, in _open
    self._handle.sasl_gssapi_bind_s()
  File "/usr/local/lib/python3.7/site-packages/ldap/ldapobject.py", line 487, in sasl_gssapi_bind_s
    self.sasl_non_interactive_bind_s('GSSAPI',serverctrls,clientctrls,sasl_flags,authz_id)
  File "/usr/local/lib/python3.7/site-packages/ldap/ldapobject.py", line 475, in sasl_non_interactive_bind_s
    self.sasl_interactive_bind_s('',auth,serverctrls,clientctrls,sasl_flags)
  File "/usr/local/lib/python3.7/site-packages/ldap/ldapobject.py", line 465, in sasl_interactive_bind_s
    return self._ldap_call(self._l.sasl_interactive_bind_s,who,auth,RequestControlTuples(serverctrls),RequestControlTuples(clientctrls),sasl_flags)
  File "/usr/local/lib/python3.7/site-packages/ldap/ldapobject.py", line 329, in _ldap_call
    reraise(exc_type, exc_value, exc_traceback)
  File "/usr/local/lib/python3.7/site-packages/ldap/compat.py", line 44, in reraise
    raise exc_value
  File "/usr/local/lib/python3.7/site-packages/ldap/ldapobject.py", line 313, in _ldap_call
    result = func(*args,**kwargs)
ldap.LOCAL_ERROR: {'desc': 'Local error', 'errno': 60, 'info': 'SASL(-1): generic failure: GSSAPI Error:  Miscellaneous failure (see text)OUR.DOMAIN (unable to reach any KDC in realm OUR.DOMAIN)'}
[2020/11/03 18:42:32] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 18:42:32] (DEBUG) ActiveDirectoryService._open():240 - Successfully initialized LDAP server: [ldap://CWM-DC-02.our.domain:389]
[2020/11/03 18:42:32] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (DEBUG) ActiveDirectoryService._open():348 - SASL GSSAPI bind failed.
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/activedirectory.py", line 341, in _open
    self._handle.sasl_gssapi_bind_s()
  File "/usr/local/lib/python3.7/site-packages/ldap/ldapobject.py", line 487, in sasl_gssapi_bind_s
    self.sasl_non_interactive_bind_s('GSSAPI',serverctrls,clientctrls,sasl_flags,authz_id)
  File "/usr/local/lib/python3.7/site-packages/ldap/ldapobject.py", line 475, in sasl_non_interactive_bind_s
    self.sasl_interactive_bind_s('',auth,serverctrls,clientctrls,sasl_flags)
  File "/usr/local/lib/python3.7/site-packages/ldap/ldapobject.py", line 465, in sasl_interactive_bind_s
    return self._ldap_call(self._l.sasl_interactive_bind_s,who,auth,RequestControlTuples(serverctrls),RequestControlTuples(clientctrls),sasl_flags)
  File "/usr/local/lib/python3.7/site-packages/ldap/ldapobject.py", line 329, in _ldap_call
    reraise(exc_type, exc_value, exc_traceback)
  File "/usr/local/lib/python3.7/site-packages/ldap/compat.py", line 44, in reraise
    raise exc_value
  File "/usr/local/lib/python3.7/site-packages/ldap/ldapobject.py", line 313, in _ldap_call
    result = func(*args,**kwargs)
ldap.LOCAL_ERROR: {'desc': 'Local error', 'errno': 60, 'info': 'SASL(-1): generic failure: GSSAPI Error:  Miscellaneous failure (see text)OUR.DOMAIN (unable to reach any KDC in realm OUR.DOMAIN)'}
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (ERROR) middlewared.job.run():361 - Job <bound method ActiveDirectoryService.start of <middlewared.plugins.activedirectory.ActiveDirectoryService object at 0x80e1d3b50>> failed
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/middlewared/job.py", line 349, in run
    await self.future
  File "/usr/local/lib/python3.7/site-packages/middlewared/job.py", line 385, in __run_body
    rv = await self.method(*([self] + args))
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/activedirectory.py", line 983, in start
    new_site = await self.middleware.call('activedirectory.get_site')
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1141, in call
    app=app, pipes=pipes, job_on_progress_cb=job_on_progress_cb, io_thread=True,
  File "/usr/local/lib/python3.7/site-packages/middlewared/main.py", line 1098, in _call
    return await run_method(methodobj, *args)
  File "/usr/local/lib/python3.7/site-packages/middlewared/utils/run_in_thread.py", line 10, in run_in_thread
    return await self.loop.run_in_executor(self.run_in_thread_executor, functools.partial(method, *args, **kwargs))
  File "/usr/local/lib/python3.7/site-packages/middlewared/utils/io_thread_pool_executor.py", line 25, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/activedirectory.py", line 1567, in get_site
    site = AD_LDAP.locate_site()
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/activedirectory.py", line 529, in locate_site
    self._open()
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/activedirectory.py", line 353, in _open
    self._convert_exception(saved_bind_error)
  File "/usr/local/lib/python3.7/site-packages/middlewared/plugins/activedirectory.py", line 212, in _convert_exception
    raise CallError(f"{errmsg} {type(ex)}")
middlewared.service_exception.CallError: [EFAULT] Local error: SASL(-1): generic failure: GSSAPI Error:  Miscellaneous failure (see text)OUR.DOMAIN (unable to reach any KDC in realm OUR.DOMAIN) <class 'ldap.LOCAL_ERROR'>
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) aiohttp.websocket._send_frame():565 - websocket connection is closing.
[2020/11/03 19:00:01] (WARNING) asyncio.write():863 - socket.send() raised exception.
[2020/11/03 19:00:01] (WARNING) middlewared.__periodic_task_wrapper():872 - Exception while calling periodic task


Any help debugging this on-going issue for us would be appreciated!
 

anodos

Sambassador
iXsystems
Joined
Mar 6, 2014
Messages
7,200
In 12.0 I rewrote the AD plugin to use samba's python bindings to perform our intial AD lookups of domain info (entirely removed py-ldap from the AD-side of directory services). Perhaps try 12.0-RELEASE in a VM and see if you have better luck there.
 

andrewjones216

Junior Member
Joined
Jun 7, 2016
Messages
15
Hi Anodos,

Thanks for the quick reply. We'd spoke about using 12.0-RELEASE here yesterday and could test on a VM. We won't be actually moving to it for production until U1.

We do have one NAS on 11.3-U5 that is connected to AD ok, and has remained that way through a nnumber of upgrades.

Do you think a rebuild of the NAS will make any difference here?
 

andrewjones216

Junior Member
Joined
Jun 7, 2016
Messages
15
Hi Anodos,

I finally managed to get a maintainance window to perform a fresh install (11.3-U5) on this box. Happy to say that firstly really impressed with the way FreeNAS handled exporting and importing of our pools (8 of them, totalling 60 disks!). Secondly that the AD join worked for us after completing the install.

I increased the AD and DNS timeouts and used SIGN in the auth method.

Thank you for your help on this, it has been invaluable.


Cheers
A
 
Top