Bug 22622 - gesetzter ldap/idletimeout kann Initialisierung des AD-Connectors stören
gesetzter ldap/idletimeout kann Initialisierung des AD-Connectors stören
Status: CLOSED FIXED
Product: UCS
Classification: Unclassified
Component: AD Connector
UCS 2.3
Other Linux
: P3 normal (vote)
: UCS 2.4-3
Assigned To: Stefan Gohmann
Moritz Muehlenhoff
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2011-05-26 14:31 CEST by Ingo Steuwer
Modified: 2011-09-14 10:57 CEST (History)
1 user (show)

See Also:
What kind of report is it?: ---
What type of bug is this?: ---
Who will be affected by this bug?: ---
How will those affected feel about the bug?: ---
User Pain:
Enterprise Customer affected?:
School Customer affected?:
ISV affected?:
Waiting Support:
Ticket number:
Bug group (optional):
Max CVSS v3 score:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Ingo Steuwer univentionstaff 2011-05-26 14:31:21 CEST
Situation:

- ldap/idletimeout ist auf 330 gesetzt
- ein relativ großes AD soll nach UCS synchronisiert werden

Der Connector baut zu OpenLDAP und AD eine LDAP-Verbindung auf. Während der Initialisierung wird eine Objektliste des AD erstellt, was in dieser Situation länger als 330 Sekunden dauert. Bei der Synchronisation des ersten Objektes muss die OpenLDAP-Verbindung daher neu aufgebaut werden.
Der Connector initialisiert dann zu viel und glaubt, alle im AD ermittelten Objekte auch schon synchronisiert zu haben. Als Ergebnis wird nichts synchronisiert und der Connector geht in den normalen Betrieb und wartet auf geänderte Objekte.

Unklar ist, wie dieses Verhalten im normalen Betrieb zuschlägt, evtl. verliert der Connector auch dann den gerade im AD erkannten Satz Änderungen.

Auszug aus der connector.log mit aktivierter debug-function:

25.05.2011 14:45:42,106 LDAP        (INFO   ): _ignore_object: Do not ignore CN=Users,ou=somwehre,dc=ad,dc=local
25.05.2011 14:45:42,106 MAIN        (------ ): UNIVENTION_DEBUG_END    : ldap._ignore_object
25.05.2011 14:45:42,106 MAIN        (------ ): UNIVENTION_DEBUG_BEGIN  : ldap.sync_to_ucs
25.05.2011 14:45:42,107 MAIN        (------ ): UNIVENTION_DEBUG_BEGIN  : ldap.get_ucs_object
25.05.2011 14:45:42,107 MAIN        (------ ): UNIVENTION_DEBUG_BEGIN  : ldap.get_ucs_ldap_object
25.05.2011 14:45:47,103 MAIN        (------ ): UNIVENTION_DEBUG_BEGIN  : ldap.initialize
25.05.2011 14:45:47,103 MAIN        (------ ): UNIVENTION_DEBUG_BEGIN  : ldap.resync_rejected
25.05.2011 14:45:47,103 MAIN        (------ ): UNIVENTION_DEBUG_BEGIN  : ldap._list_rejected
25.05.2011 14:45:47,103 MAIN        (------ ): UNIVENTION_DEBUG_BEGIN  : ldap._get_config_items
25.05.2011 14:45:47,103 MAIN        (------ ): UNIVENTION_DEBUG_END    : ldap._get_config_items
25.05.2011 14:45:47,104 MAIN        (------ ): UNIVENTION_DEBUG_END    : ldap._list_rejected
25.05.2011 14:45:47,104 MAIN        (------ ): UNIVENTION_DEBUG_END    : ldap.resync_rejected
25.05.2011 14:45:47,104 MAIN        (------ ): UNIVENTION_DEBUG_BEGIN  : ldap._get_lastUSN
25.05.2011 14:45:47,104 MAIN        (------ ): UNIVENTION_DEBUG_BEGIN  : ldap._get_config_option
25.05.2011 14:45:47,104 MAIN        (------ ): UNIVENTION_DEBUG_END    : ldap._get_config_option
25.05.2011 14:45:47,104 MAIN        (------ ): UNIVENTION_DEBUG_END    : ldap._get_lastUSN
25.05.2011 14:45:47,105 MAIN        (------ ): UNIVENTION_DEBUG_BEGIN  : ldap.poll
Comment 1 Stefan Gohmann univentionstaff 2011-05-30 09:30:18 CEST
So richtig kann ich das Problem in einer Testumgebung (UCS 2.4-2) nicht reproduzieren.

Anhand des Debug Outputs kann folgendes angenommen werden:

- der AD Connector sucht im AD, das dauert deutlich länger als der idletimout des UCS LDAP

- der AD Connector such dann im UCS LDAP das erste Objekt (ldap.get_ucs_ldap_object)

- dort tritt der LDAP Server Down Traceback auf

- der AD Connector springt aus seiner Initialisierungsphase, wartet das Intervall ab (5 Sekunden). Er interpretiert das LDAP Server down als Rückgabe vom AD LDAP.

- danach wird die Synchronisation fortgesetzt

Hier sind zwei TODOs:

1. der Traceback muss abgefangen werden und darf nicht als AD LDAP Traceback interpretiert werden

2. es muss festgestellt werden, warum die neue USN gespeichert wird
Comment 2 Stefan Gohmann univentionstaff 2011-06-01 09:31:15 CEST
(In reply to comment #1)
> 2. es muss festgestellt werden, warum die neue USN gespeichert wird

Der AD Connector generiert eine Liste über uSNCreated und uSNChanged. Das Objekt mit der kleinsten uSNCreated ist immer das Basis-Objekt. Der AD Connector speichert dann die uSNChanged des Basis-Objekt als LastUSN. Da der Connector dann aufgrund des idletimeouts an der Stelle weitermacht, wird ein Teil ausgelassen.

Entweder die USN wird erstmalig nach der Initialisierung gespeichert oder wir ändern es generell so, dass beim Abarbeiten des Blocks die höchste usn-Nummer erst gespeichert wird, wenn der komplette Block abgearbeitet ist.
Comment 3 Stefan Gohmann univentionstaff 2011-06-01 15:12:06 CEST
fixed

Es hat jetzt drei Änderungen gegeben:

- rejects werden nur noch synchronisiert, wenn die Initialisierung einmal gestartet wurde

- die letzte USN wird nur gespeichert, wenn die Suchergebnisse abgearbeitet sind

- wenn der Idletimeout lokal zuschlägt während der Suche im AD, dann wird die Verbinsung erneut aufgebaut
Comment 4 Moritz Muehlenhoff univentionstaff 2011-08-19 09:55:55 CEST
Ich habe ldap/idletimeout auf 5 Sekunden gesetzt und  libnss/idle/timelimit auf 4 Sekunden.

Anschliessend habe ich ein AD 2008 mit 4000 Benutzern im Read-Modus synchronisiert. Der initiale Sync dauerte dabei deutlich länger als 5 Sekunden und der Sync der Benutzer funktionierte. (Wg. eines anderen Problems wurden nur 3600 der 4000 Benutzer synchronisiert, aber das Problem mit dem Idle Timeout ist soweit ok).
Comment 5 Stefan Gohmann univentionstaff 2011-09-02 11:56:47 CEST
(In reply to comment #3)
> - die letzte USN wird nur gespeichert, wenn die Suchergebnisse abgearbeitet
> sind

Ich mache den Bug nochmal wieder auf. Zumindest im S4 Connector Setup führte das zu einem Fehler.

Wenn das Objekt im UCS nicht angelegt werden konnte, so gabe es im Connector eine Endlosschleife.
Comment 6 Stefan Gohmann univentionstaff 2011-09-08 20:49:52 CEST
(In reply to comment #5)
> (In reply to comment #3)
> > - die letzte USN wird nur gespeichert, wenn die Suchergebnisse abgearbeitet
> > sind
> 
> Ich mache den Bug nochmal wieder auf. Zumindest im S4 Connector Setup führte
> das zu einem Fehler.
> 
> Wenn das Objekt im UCS nicht angelegt werden konnte, so gabe es im Connector
> eine Endlosschleife.

Das konnte ich mit UCS 2.4-3 nicht reproduzieren.


@Moritz, vielleicht kannst du nochmal kurz in deiner Umgebung kurz prüfen, was passiert, wenn ein Objekt rejected wird. Im S4 Connector war es nur, wenn das Objekt nicht von AD nach UCS synchronisiert wurde.
Comment 7 Moritz Muehlenhoff univentionstaff 2011-09-12 09:14:53 CEST
(In reply to comment #6)

> @Moritz, vielleicht kannst du nochmal kurz in deiner Umgebung kurz prüfen, was
> passiert, wenn ein Objekt rejected wird. Im S4 Connector war es nur, wenn das
> Objekt nicht von AD nach UCS synchronisiert wurde.

Ich habe einen 2.4-3 AD Connector gegen ein AD 2008 im Read-Modus konfiguriert. Dann habe ich die LDAP-ACLs für den Administrator auf UCS-Seite entfernt und im AD einen Benutzer angelegt. Dieser landet dann in der Ausgabe von univention-connector-list-rejected. Es gibt keine hohe Systemlast o.ä. und die Objekte werden alle 20 Sekunden erneut zu replizieren versucht:

19.08.2011 19:08:21,14 LDAP        (ERROR  ): failed in post_con_modify_functions
19.08.2011 19:08:21,14 LDAP        (ERROR  ):  --  for details see /var/log/univention/connector-tracebacks.log -- 
19.08.2011 19:08:21,15 LDAP        (WARNING): sync to ucs was not successfull, save rejected
19.08.2011 19:08:21,16 LDAP        (WARNING): object was: CN=maul wurf,CN=Users,DC=test,DC=ad
19.08.2011 19:08:42,350 LDAP        (ERROR  ): failed in post_con_modify_functions
19.08.2011 19:08:42,350 LDAP        (ERROR  ):  --  for details see /var/log/univention/connector-tracebacks.log -- 
19.08.2011 19:08:42,351 LDAP        (WARNING): sync to ucs was not successfull, save rejected
19.08.2011 19:08:42,351 LDAP        (WARNING): object was: CN=maul wurf,CN=Users,DC=test,DC=ad

Ein Restart ist ebenfalls erfolgreich und ändert nichts.
Comment 8 Sönke Schwardt-Krummrich univentionstaff 2011-09-14 10:57:09 CEST
UCS 2.4-3 wurde veröffentlicht. Sollte der hier beschriebene Bug mit einer
neueren Version von UCS erneut auftreten, so sollte der Bug dupliziert werden:
"Clone This Bug".