Univention Bugzilla – Bug 22622
gesetzter ldap/idletimeout kann Initialisierung des AD-Connectors stören
Last modified: 2011-09-14 10:57:09 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
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
(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.
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
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).
(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.
(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.
(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.
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".