possible bug in AD sync connector

Univention Corporate Server (Wiki)

possible bug in AD sync connector

Postby talleyrand » Thu 26. Jan 2017, 03:35

I think there may be a bug in the connection to a 2008 AD.

We are running a mirror off the main AD, as a test measure.
yesterday we had a non-graceful C&B (crash & burn) loss of a UPS, this took the 2008 AD server down hard.

After the system was brought back up and functioning, we noticed the Uni. could not re-connect and was filling the error logs

it seems that once a connection is made to a MS AD , there is not any real checking to see if the connection goes down, instead the log files just fill with PY errors, even after the remote system comes backup.

a stopping of the AD connection at univention & a restarting, fixes the log errors and catches up on the domain syncs.

it seems the error routines need to be made a bit more robust & try re-forming the connection if the code is producing connection errors.

26.01.2017 09:44:37,729 LDAP (ERROR ): failed in post_con_modify_functions
26.01.2017 09:44:37,730 LDAP (ERROR ): Traceback (most recent call last):
File "/usr/lib/pymodules/python2.7/univention/connector/__init__.py", line 1326, in sync_to_ucs
f(self, property_type, object)
File "/usr/lib/pymodules/python2.7/univention/connector/ad/password.py", line 381, in password_sync
res = get_password_from_ad(connector, univention.connector.ad.compatible_modstring(object['dn']))
File "/usr/lib/pymodules/python2.7/univention/connector/ad/password.py", line 180, in get_password_from_ad
(level, ctr) = connector.drs.DsGetNCChanges(connector.drsuapi_handle, 8, req8)
NTSTATUSError: (-1073741300, 'The transport connection is now disconnected.')


then after re-connecting:
File "/usr/lib/pymodules/python2.7/univention/connector/__init__.py", line 1326, in sync_to_ucs
f(self, property_type, object)
File "/usr/lib/pymodules/python2.7/univention/connector/ad/password.py", line 381, in password_sync
res = get_password_from_ad(connector, univention.connector.ad.compatible_modstring(object['dn']))
File "/usr/lib/pymodules/python2.7/univention/connector/ad/password.py", line 180, in get_password_from_ad
(level, ctr) = connector.drs.DsGetNCChanges(connector.drsuapi_handle, 8, req8)
NTSTATUSError: (-1073741300, 'The transport connection is now disconnected.')

26.01.2017 09:45:18,218 MAIN (------ ): DEBUG_INIT
26.01.2017 09:45:18,237 LDAP (ERROR ): Failed to lookup AD LDAP base, using UCR value.
26.01.2017 09:45:18,270 LDAP (PROCESS): Building internal group membership cache
26.01.2017 09:45:18,411 LDAP (PROCESS): Internal group membership cache was created
26.01.2017 09:45:18,449 LDAP (PROCESS): Using GP01 as AD Netbios domain name
26.01.2017 09:45:18,521 LDAP (PROCESS): sync from ucs: Resync rejected file: /var/lib/univention-connector/ad/1485393377.000030
26.01.2017 09:45:18,548 LDAP (PROCESS): sync from ucs: [ user] [ modify] cn=xxxxxx,ou=hk office,DC=xx,DC=xx,DC=xxx,DC=xx


and everything is fine with the world until next time
talleyrand
 
Posts: 25
Joined: Wed 24. Feb 2016, 04:03

Re: possible bug in AD sync connector

Postby Thorp-Hansen » Fri 27. Jan 2017, 11:46

Hi, can you provide us with the logfiles that show this behaviour? I can then try to reproduce it and create an issue entry in our tracker.

Thanks in advance,
Jens
User avatar
Thorp-Hansen
Univention Support
 
Posts: 456
Joined: Mon 11. May 2015, 08:21

Re: possible bug in AD sync connector

Postby talleyrand » Thu 2. Feb 2017, 09:30

yep, if you tell me exactly what you want and where to send them.

I'm not going to upload them to the forum , since they have user and domain info.
talleyrand
 
Posts: 25
Joined: Wed 24. Feb 2016, 04:03

Re: possible bug in AD sync connector

Postby Thorp-Hansen » Fri 3. Feb 2017, 13:30

I built a testingenvironment with a membermode and killed the ad-master hard. My UCS complained at first but re-established a connection as the AD-Master was back online by itself. So I cannot reproduce your issue - I used UCS 4.1-4 in the latest Errata.
User avatar
Thorp-Hansen
Univention Support
 
Posts: 456
Joined: Mon 11. May 2015, 08:21

Re: possible bug in AD sync connector

Postby talleyrand » Mon 6. Feb 2017, 04:18

latest version 4.1-4 errata
AD server 2008 SP2, fully patched
WAN connection latency ~10-25ms, possible packet drops under heavy load.

system memory is 4GB , with <1GB used
system swap =0
CPU is not particularly loaded

Once the connection is manually restarted, everything syncs up again with no errors, just massive log files of failed connections.

Really it could do with some sort of trapping to capture this situation or deeper logging.

05.02.2017 06:25:07,509 MAIN (------ ): DEBUG_INIT
05.02.2017 06:25:07,592 LDAP (PROCESS): Building internal group membership cache
05.02.2017 06:25:07,724 LDAP (PROCESS): Internal group membership cache was created
05.02.2017 06:25:07,752 LDAP (PROCESS): Using GP01 as AD Netbios domain name
05.02.2017 08:02:04,772 LDAP (PROCESS): sync to ucs: [ user] [ modify] uid=(user & DN here)
05.02.2017 08:05:34,378 LDAP (PROCESS): sync to ucs: [ user] [ modify] uid=(user & DN here)
05.02.2017 08:48:27,525 LDAP (PROCESS): sync to ucs: [ user] [ modify] uid= (user & DN here)
05.02.2017 08:48:27,557 LDAP (ERROR ): failed in post_con_modify_functions
05.02.2017 08:48:27,558 LDAP (ERROR ): Traceback (most recent call last):
File "/usr/lib/pymodules/python2.7/univention/connector/__init__.py", line 1323, in sync_to_ucs
f(self, property_type, object)
File "/usr/lib/pymodules/python2.7/univention/connector/ad/password.py", line 381, in password_sync
res = get_password_from_ad(connector, univention.connector.ad.compatible_modstring(object['dn']))
File "/usr/lib/pymodules/python2.7/univention/connector/ad/password.py", line 180, in get_password_from_ad
(level, ctr) = connector.drs.DsGetNCChanges(connector.drsuapi_handle, 8, req8)
NTSTATUSError: (-1073741299, 'The transport connection has been reset.')
talleyrand
 
Posts: 25
Joined: Wed 24. Feb 2016, 04:03

Re: possible bug in AD sync connector

Postby talleyrand » Wed 8. Feb 2017, 10:17

Ok,

Today i did a completely new install from a brand new downloaded 4.1 iso into a clean VM machine.

Updated to the latest errata,
then did a bi-directional mirror connection to a fully patched 2008 SP2 AD server.

it did a full sync with a few AD object errors, which resolved.

Then it ran for several hours,
finally exactly the same error on the connection occurred.
Restarted the server and it fully synced again on the out of date records, (if it is the records causing the problem , it should not restart with no errors)

So clearly something is going on with the connections, even though the WAN is showing no disconnects or package loss latency?
talleyrand
 
Posts: 25
Joined: Wed 24. Feb 2016, 04:03

Re: possible bug in AD sync connector

Postby Thorp-Hansen » Wed 8. Feb 2017, 12:11

Apart from a flaky connection, I just tried again to reproduce the issue. I setup a UCS Server as a member to an existing Windows Server, configured the password sync, waited some time and then killed the AD. That is what I see in the log:

Code: Select all
08.02.2017 10:44:57,503 MAIN        (------ ): DEBUG_INIT
08.02.2017 10:44:58,209 LDAP        (PROCESS): Using HEL as AD Netbios domain name
08.02.2017 10:45:08,974 LDAP        (PROCESS): sync to ucs:   [          user] [    modify] uid=tmtt,cn=users,dc=hel,dc=underworld

Modified a user to test the sync and some seconds afterwards killed the AD hard.

Code: Select all
08.02.2017 10:52:12,775 MAIN        (------ ): DEBUG_INIT
08.02.2017 10:52:44,860 LDAP        (PROCESS): Building internal group membership cache
08.02.2017 10:52:44,883 LDAP        (PROCESS): Internal group membership cache was created
08.02.2017 10:52:44,893 LDAP        (PROCESS): Using HEL as AD Netbios domain name

After around 5 minutes I rebooted the AD again. As you can see my log went silent for about 5 - 7 minutes and then resumed connection by its own.

I have a question:

Updated to the latest errata,
then did a bi-directional mirror connection to a fully patched 2008 SP2 AD server.


If you join an UCS via AD-Connector to a Windows Domain, that is not bi-directional. The AD is always the defining DC and changes are "mirrored" from the AD to the UCS. So if you have another setting you should let me know.
User avatar
Thorp-Hansen
Univention Support
 
Posts: 456
Joined: Mon 11. May 2015, 08:21

Re: possible bug in AD sync connector

Postby talleyrand » Thu 9. Feb 2017, 05:47

CLARIFICATION:
Our difference seems we are not making it part of an existing system.
Can you clarify which ports are required to be open to sync data & password hashes? (we want to double check this)

Should we perhaps be looking at the windows AD blocking the password request for some reason (but why a restart of the UCS fixes it)?

OUR TEST SYSTEM SETUP:
1.Create a NEW UCS domain NOT part of current schema, (finish procedure, update)
2.load in Active directory connection
3. Set UCS debugging to 3 (connector/debug/level)
4. "synchronisation of account data between an Active Directory and this UCS Domain"
5. allow to synchronise.
6. user usage via connection to the AD server (MS)

TESTING:
We now find it is not necessary to loose power to the systems, the systems randomly disconnects.
sometimes an hour, sometimes 3 hours, yesterday it was 16 hours.

FURTHER VALIDATION TESTING:
1. we rebuilt the windows AD server on a new machine, rebuilt a new UCS system
2. turned on UCS debugging =3


FURTHER SCOPE testing:
1. Check ports/ protocols (TCP/UDP)
2. Check python resources, connection limits etc
3. Check MTU/ Packet Fragmenting/Timeout
4. Check if it is OSX computer based objects triggering crash.

OUTCOME:
The UCS server then ran for 16 hours without erroring,
but finally the connection crashed again (logging an OSX client) & the first computer in the morning.

log was clean until this:
09.02.2017 09:01:44,420 LDAP (INFO ): Search AD with filter: (uSNCreated>=329249)
09.02.2017 09:01:44,439 LDAP (INFO ): Search AD with filter: (uSNChanged>=329249)
09.02.2017 09:01:49,493 LDAP (INFO ): Search AD with filter: (uSNCreated>=329249)
09.02.2017 09:01:49,507 LDAP (INFO ): Search AD with filter: (uSNChanged>=329249)
09.02.2017 09:01:54,556 LDAP (INFO ): Search AD with filter: (uSNCreated>=329249)
09.02.2017 09:01:54,567 LDAP (INFO ): Search AD with filter: (uSNChanged>=329249)
09.02.2017 09:01:59,585 LDAP (INFO ): Search AD with filter: (uSNCreated>=329249)
09.02.2017 09:01:59,600 LDAP (INFO ): Search AD with filter: (uSNChanged>=329249)
09.02.2017 09:02:04,645 LDAP (INFO ): Search AD with filter: (uSNCreated>=329249)
09.02.2017 09:02:04,661 LDAP (INFO ): Search AD with filter: (uSNChanged>=329249)
09.02.2017 09:02:04,684 LDAP (INFO ): encode_ad_object: attrib objectGUID ignored during encoding
09.02.2017 09:02:04,696 LDAP (INFO ): object_from_element: olddn: CN=some.user,OU=oa office,DC=gp01,DC=org,DC=somedomain,DC=com
09.02.2017 09:02:04,697 LDAP (INFO ): _ignore_object: Do not ignore CN=some.user,OU=oa office,DC=gp01,DC=org,DC=somedomain,DC=com
09.02.2017 09:02:04,697 LDAP (INFO ): _object_mapping: map with key user and type con
09.02.2017 09:02:04,697 LDAP (INFO ): _dn_type con
09.02.2017 09:02:04,704 LDAP (INFO ): samaccount_dn_mapping: check newdn for key dn:
09.02.2017 09:02:04,714 LDAP (INFO ): samaccount_dn_mapping: premapped UCS object found
09.02.2017 09:02:04,714 LDAP (INFO ): samaccount_dn_mapping: check newdn for key olddn:
09.02.2017 09:02:04,715 LDAP (INFO ): _ignore_object: Do not ignore uid=some.user,ou=oa office,dc=mirror-of01,dc=org,dc=somedomain,dc=com
09.02.2017 09:02:04,717 LDAP (INFO ): get_ucs_object: object found: uid=some.user,ou=oa office,dc=mirror-of01,dc=org,dc=somedomain,dc=com
09.02.2017 09:02:04,717 LDAP (PROCESS): sync to ucs: [ user] [ modify] uid=some.user,ou=oa office,dc=mirror-of01,dc=org,dc=somedomain,dc=com
09.02.2017 09:02:04,717 LDAP (INFO ): sync_to_ucs: set position to ou=oa office,dc=mirror-of01,dc=org,dc=somedomain,dc=com
09.02.2017 09:02:04,718 LDAP (INFO ): _ignore_object: Do not ignore uid=some.user,ou=oa office,dc=mirror-of01,dc=org,dc=somedomain,dc=com
09.02.2017 09:02:04,721 LDAP (INFO ): __set_values: set attribute, ucs_key: firstname - value: [u'some']
09.02.2017 09:02:04,721 LDAP (INFO ): __set_values: module users/user has no custom attributes
09.02.2017 09:02:04,721 LDAP (INFO ): __set_values: set attribute, ucs_key: username - value: [u'some.user']
09.02.2017 09:02:04,721 LDAP (INFO ): __set_values: module users/user has no custom attributes
09.02.2017 09:02:04,721 LDAP (INFO ): __set_values: set attribute, ucs_key: lastname - value: [u'user']
09.02.2017 09:02:04,721 LDAP (INFO ): __set_values: module users/user has no custom attributes
09.02.2017 09:02:04,722 LDAP (INFO ): __set_values: mapping for attribute: mobilePhone
09.02.2017 09:02:04,722 LDAP (INFO ): __set_values: no ldap_attribute defined in <univention.connector.attribute instance at 0x3744cf8>, we unset the key mobileTelephoneNumber in the ucs-object
09.02.2017 09:02:04,722 LDAP (INFO ): __set_values: mapping for attribute: street
09.02.2017 09:02:04,722 LDAP (INFO ): __set_values: no ldap_attribute defined in <univention.connector.attribute instance at 0x3744ab8>, we unset the key street in the ucs-object
09.02.2017 09:02:04,722 LDAP (INFO ): __set_values: mapping for attribute: postcode
09.02.2017 09:02:04,722 LDAP (INFO ): __set_values: no ldap_attribute defined in <univention.connector.attribute instance at 0x3744b48>, we unset the key postcode in the ucs-object
09.02.2017 09:02:04,722 LDAP (INFO ): __set_values: mapping for attribute: scriptpath
09.02.2017 09:02:04,722 LDAP (INFO ): __set_values: no ldap_attribute defined in <univention.connector.attribute instance at 0x3744c20>, we unset the key scriptpath in the ucs-object
09.02.2017 09:02:04,723 LDAP (INFO ): __set_values: mapping for attribute: sambaWorkstations
09.02.2017 09:02:04,723 LDAP (INFO ): __set_values: no ldap_attribute defined in <univention.connector.attribute instance at 0x3744b90>, we unset the key sambaUserWorkstations in the ucs-object
09.02.2017 09:02:04,723 LDAP (INFO ): __set_values: mapping for attribute: pager
09.02.2017 09:02:04,723 LDAP (INFO ): __set_values: no ldap_attribute defined in <univention.connector.attribute instance at 0x3744d40>, we unset the key pagerTelephoneNumber in the ucs-object
09.02.2017 09:02:04,723 LDAP (INFO ): __set_values: mapping for attribute: homePhone
09.02.2017 09:02:04,723 LDAP (INFO ): __set_values: no ldap_attribute defined in <univention.connector.attribute instance at 0x3744cb0>, we unset the key homeTelephoneNumber in the ucs-object
09.02.2017 09:02:04,723 LDAP (INFO ): __set_values: mapping for attribute: description
09.02.2017 09:02:04,723 LDAP (INFO ): __set_values: no ldap_attribute defined in <univention.connector.attribute instance at 0x3744a70>, we unset the key description in the ucs-object
09.02.2017 09:02:04,724 LDAP (INFO ): __set_values: mapping for attribute: telephoneNumber
09.02.2017 09:02:04,724 LDAP (INFO ): __set_values: no ldap_attribute defined in <univention.connector.attribute instance at 0x3744c68>, we unset the key phone in the ucs-object
09.02.2017 09:02:04,724 LDAP (INFO ): __set_values: mapping for attribute: city
09.02.2017 09:02:04,724 LDAP (INFO ): __set_values: no ldap_attribute defined in <univention.connector.attribute instance at 0x3744b00>, we unset the key city in the ucs-object
09.02.2017 09:02:04,724 LDAP (INFO ): __set_values: mapping for attribute: displayName
09.02.2017 09:02:04,724 LDAP (INFO ): __set_values: set attribute, ucs_key: displayName - value: [u'Some User']
09.02.2017 09:02:04,724 LDAP (INFO ): __set_values: module users/user has no custom attributes
09.02.2017 09:02:04,724 LDAP (INFO ): __set_values: mapping for attribute: organisation
09.02.2017 09:02:04,725 LDAP (INFO ): __set_values: no ldap_attribute defined in <univention.connector.attribute instance at 0x3744a28>, we unset the key organisation in the ucs-object
09.02.2017 09:02:04,725 LDAP (INFO ): __set_values: mapping for attribute: profilepath
09.02.2017 09:02:04,725 LDAP (INFO ): __set_values: no ldap_attribute defined in <univention.connector.attribute instance at 0x3744bd8>, we unset the key profilepath in the ucs-object
09.02.2017 09:02:04,726 LDAP (INFO ): __modify_custom_attributes: no custom attributes found
09.02.2017 09:02:04,727 LDAP (INFO ): Call post_ucs_modify_functions: <function password_sync at 0x3748d70>
09.02.2017 09:02:04,727 LDAP (INFO ): _object_mapping: map with key user and type ucs
09.02.2017 09:02:04,727 LDAP (INFO ): _dn_type ucs
09.02.2017 09:02:04,728 LDAP (INFO ): samaccount_dn_mapping: check newdn for key dn:
09.02.2017 09:02:04,748 LDAP (INFO ): get_object: got object: cn=some.user,ou=oa office,DC=gp01,DC=org,DC=somedomain,DC=com
09.02.2017 09:02:04,748 LDAP (INFO ): encode_ad_object: attrib objectGUID ignored during encoding
09.02.2017 09:02:04,748 LDAP (INFO ): samaccount_dn_mapping: premapped AD object found
09.02.2017 09:02:04,749 LDAP (INFO ): samaccount_dn_mapping: check newdn for key olddn:
09.02.2017 09:02:04,763 LDAP (INFO ): password_sync: pwdLastSet from AD: 131292745455362513 ([('cn=some.user,ou=oa office,DC=gp01,DC=org,DC=somedomain,DC=com', {'pwdLastSet': ['131292745455362513'], 'objectSid': ['x01x05x00x00x00x00x00x05x15x00x00x00xe5cxd9>ex06xccxfax00xcex0b#x05x00x00']})])
09.02.2017 09:02:04,763 LDAP (INFO ): password_sync: sambaPwdLastSet: 1485393376
09.02.2017 09:02:04,764 LDAP (INFO ): get_password_from_ad: Read password from AD: cn=some.user,ou=oa office,DC=gp01,DC=org,DC=somedomain,DC=com
09.02.2017 09:02:04,776 LDAP (ERROR ): failed in post_con_modify_functions
09.02.2017 09:02:04,796 LDAP (ERROR ): Traceback (most recent call last):
File "/usr/lib/pymodules/python2.7/univention/connector/__init__.py", line 1323, in sync_to_ucs
f(self, property_type, object)
File "/usr/lib/pymodules/python2.7/univention/connector/ad/password.py", line 381, in password_sync
res = get_password_from_ad(connector, univention.connector.ad.compatible_modstring(object['dn']))
File "/usr/lib/pymodules/python2.7/univention/connector/ad/password.py", line 180, in get_password_from_ad
(level, ctr) = connector.drs.DsGetNCChanges(connector.drsuapi_handle, 8, req8)
NTSTATUSError: (-1073741299, 'The transport connection has been reset.')

09.02.2017 09:02:04,796 LDAP (INFO ): Return result for DN (uid=some.user,ou=oa office,dc=mirror-of01,dc=org,dc=somedomain,dc=com)
09.02.2017 09:02:04,797 LDAP (WARNING): sync to ucs was not successfull, save rejected
09.02.2017 09:02:04,797 LDAP (WARNING): object was: CN=some.user,OU=oa office,DC=gp01,DC=org,DC=somedomain,DC=com
09.02.2017 09:02:04,905 LDAP (INFO ): _set_lastUSN: new lastUSN is: 329780
09.02.2017 09:02:09,938 LDAP (INFO ): Search AD with filter: (uSNCreated>=329781)
09.02.2017 09:02:09,951 LDAP (INFO ): Search AD with filter: (uSNChanged>=329781)
09.02.2017 09:02:14,995 LDAP (INFO ): Search AD with filter: (uSNCreated>=329781)
09.02.2017 09:02:15,28 LDAP (INFO ): Search AD with filter: (uSNChanged>=329781)

talleyrand
 
Posts: 25
Joined: Wed 24. Feb 2016, 04:03

Re: possible bug in AD sync connector

Postby Thorp-Hansen » Thu 9. Feb 2017, 10:46

Our Setup is the same, we just achieved via different means (I set it up at Installation, you set it up later). We both have a UCS joined in a AD Domain and control the domain via the AD DC. The open Ports needed you can find here: http://sdb.univention.de/content/2/281/en/which-tcp-_-udp-ports-on-the-dc-master-must-be-accessable-by-other-ucs-systems.html

Code: Select all
NTSTATUSError: (-1073741299, 'The transport connection has been reset.')


Unfortunatly, this just tells you, that the connection is lost. Did you already check network, switches, router, etc.? In my case the connector just resumed its duty at reestablishing the connection, I would expect that to happen in your case also.
User avatar
Thorp-Hansen
Univention Support
 
Posts: 456
Joined: Mon 11. May 2015, 08:21

Re: possible bug in AD sync connector

Postby talleyrand » Mon 13. Feb 2017, 04:15

This is beginning to annoy me....

It just does not make any sense, the thing has been running fine since version 4.0, and even reinstalling 4.1 on a separate system does not work.

cannot find anything wrong with network or switches, everything else works

Clearly something has changed in the connection routines.
it can spend hours just throwing this error message, but as soon as i restart the AD connection on the univention, it works first time... until it breaks again.

So clearly something on the uinvention is blocking it from remaking the connection...?

where to start looking?
talleyrand
 
Posts: 25
Joined: Wed 24. Feb 2016, 04:03

Re: possible bug in AD sync connector

Postby talleyrand » Mon 13. Feb 2017, 06:02

On startup I have the following (stripped of other connections)


netstat -p
Active Internet connections (w/o servers)
Proto Recv-Q Send-Q Local Address Foreign Address State PID/Program name
tcp 0 0 mirror.mirror-gp0:41482 adsrv-se.gp01.org:49155 ESTABLISHED 6716/python2.7
......
tcp 0 0 mirror.mirror-gp0:38698 adsrv-se.gp01.org.:ldap ESTABLISHED 6716/python2.7



when the connection goes bad i have this:

.......
tcp 0 0 mirror.mirror-gp0:38698 adsrv-se.gp01.org.:ldap ESTABLISHED 6716/python2.7




and after re-starting the AD-connector, and the AD re-syncs.

tcp 0 0 mirror.mirror-gp0:41595 adsrv-se.gp01.org:49155 ESTABLISHED 8530/python2.7
...........
tcp 0 0 mirror.mirror-gp0:38811 adsrv-se.gp01.org.:ldap ESTABLISHED 8530/python2.7


Clearly we can see a double connection: (over a port that is not listed in your reference list 49155)
The question is, why the LDAP connection appeared to be able to maintain without falling over, but the other one cannot
talleyrand
 
Posts: 25
Joined: Wed 24. Feb 2016, 04:03

Re: possible bug in AD sync connector

Postby talleyrand » Tue 14. Feb 2017, 00:52

Think i have found it.

for some reason the TCP connection session protocol is showing as 'active' at the firewall, even though it is not as far as the application is concerened. (error messages)
14.02.2017 06:27:06,816 LDAP (ERROR ): failed in post_con_modify_functions
14.02.2017 06:27:06,816 LDAP (ERROR ): Traceback (most recent call last):
File "/usr/lib/pymodules/python2.7/univention/connector/__init__.py", line 1323, in sync_to_ucs
f(self, property_type, object)
File "/usr/lib/pymodules/python2.7/univention/connector/ad/password.py", line 381, in password_sync
res = get_password_from_ad(connector, univention.connector.ad.compatible_modstring(object['dn']))
File "/usr/lib/pymodules/python2.7/univention/connector/ad/password.py", line 180, in get_password_from_ad
(level, ctr) = connector.drs.DsGetNCChanges(connector.drsuapi_handle, 8, req8)
NTSTATUSError: (-1073741300, 'The transport connection is now disconnected.')


Expiring the connection at the firewall causes the connection to re-form and the AD to re-sync ,as you would expect and without the need to restart the actual AD-connector/univention instance.

As far as the "netstat" in the VM instance is concerened the connection:
tcp 0 0 mirror.mirror-gp0:41482 adsrv-se.gp01.org:49155 ESTABLISHED 6716/python2.7

Has "gone away"

but as far as the firewall is concerned "41482-49155" , has NOT gone away.

So what it looks like is as far as the host VM instance is concerned:

The python code is attempting to use a connection it cannot , because of some sort of error, between the KVM, hosted Kernel & Python.

Maybe this will be why you cannot duplicate it, because it is not actually a network/ high level python code problem.
but rather a kernel process/python Asynchronous socket failure that the application does not handle by resetting the socket handler.


So when this error is thrown, there needs to be some sort of shutdown & reforming of the underlying connection
talleyrand
 
Posts: 25
Joined: Wed 24. Feb 2016, 04:03

Re: possible bug in AD sync connector

Postby Thorp-Hansen » Wed 15. Feb 2017, 17:24

What I did not understand is: The error is

Code: Select all
NTSTATUSError: (-1073741300, 'The transport connection is now disconnected.')


so clearly, the UCS recognizes that the connection is lost (same as in my testing environment - I just do not cranked up the debuglevel). In my environment, the connection was reestablished as soon the AD was reachable again. So this actually happend:

So when this error is thrown, there needs to be some sort of shutdown & reforming of the underlying connection
User avatar
Thorp-Hansen
Univention Support
 
Posts: 456
Joined: Mon 11. May 2015, 08:21

Re: possible bug in AD sync connector

Postby talleyrand » Fri 17. Feb 2017, 06:55

Fine,
but clearly the systems are not synchronised.
Because if I re-set the connection (by deleting it at the firewall), then there are literally 10's of updates to the UCS system.

you can see here... a tail of the log...... with continual errors.

after clearing the connection at the firewall, you can see the log file changes. (the debug-init is where i did a forced firewall deletion of the connection)

This is on a network that does not fail nor does it drop packets.

the longer I leave the connection without a hard reset, the longer the re-sync list is.

If i don't reset the connection, then i just continually get the "disconnected error"
Attachments
re-set.png
talleyrand
 
Posts: 25
Joined: Wed 24. Feb 2016, 04:03

Re: possible bug in AD sync connector

Postby talleyrand » Mon 20. Feb 2017, 06:15

So...
its recovery not likely to be related to this in /__init__.py 1323, which does not fully check the return values after the connection


except: # FIXME: which exception is to be caught?
talleyrand
 
Posts: 25
Joined: Wed 24. Feb 2016, 04:03

Next

Return to UCS

Who is online

Users browsing this forum: Google [Bot] and 2 guests