Univention Bugzilla – Bug 16098
univention-directory-listener cache scheint auf Master nicht aktualisiert zu werden
Last modified: 2011-05-11 15:55:43 CEST
Auf Master Systemen scheinen die Daten im Listener Cache nicht immer aktualisiert zu werden und der Listener scheint unter Umständen den Listener Modulen im 'new' Objekt alte Daten (aus dem Cache?) zu übergeben. Es ist noch unklar, ob das ggf. durch defekte Einträge in der Cache Datenbank ausgelöst wird. Ein Anhaltspunkt könnte sein, dass univention-directory-listener-verify \ -D uid=Administrator,cn=users,dc=univention,dc=test\ -b dc=univention,dc=test -w 'passwort' auf einem Slave zufrieden über den Zustand des Caches im Vergleich zu den Daten im Verzeichnis ist, auf einem Master aber Inkonsistenzen gemeldet werden.
Tritt auch auf Backup auf. Ggf. ist das auf die lowercase Änderungen am Listener für Bug #15003 zurückzuführen. Auf den betroffenen Systemen (Master & Backup) zeigt "univention-directory-listener-dump -O /tmp/cache.ldif" folgende Informationen (gekürzt): ( In den folgenden Debug-Auszügen ist ou=<localtion1>,<$ldap/basedn> an den DNs sinngemäss zu ergänzen ) Master: ====== dn: uid=tts,ou=People, modifyTimestamp: 20090901131127Z listenerModule: directory_logger listenerModule: custom_export dn: uid=tts,ou=people, quota: 12345 <- Attribut vorhanden modifyTimestamp: 20091027132023Z <- das ist laut ldapsearch aktuell listenerModule: custom_export listenerModule: directory_logger Backup: ====== dn: uid=tts,ou=People, modifyTimestamp: 20090901131127Z listenerModule: replication dn: uid=tts,ou=people, modifyTimestamp: 20090901131127Z listenerModule: replication listenerModule: custom_export Auf dem Backup liefert der Listener bei einem resync auf das custom_export Modul als 'new' einen Eintrag ohne 'quota' Attribut und kein 'old'. Auf dem Master wird ebenfalls der alte Eintrag geliefert. Eine künstlich erzeugte Debug Ausgabe im listener.log zeigt kein 'quota' Attribut und den alten mofifyTimestamp (gekürzt): 27.10.09 16:36:29 LISTENER ( INFO ) : custom_export: dn: uid=tts,ou=People, 27.10.09 16:36:29 LISTENER ( INFO ) : custom_export: new: {'uid': ['tts'], 'objectClass': ['top', 'person', 'univentionPWHistory', 'posixAccount', 'shadowAccount', 'univentionMail', 'sambaSamAccount', 'organizationalPerson', 'inetOrgPerson', 'krb5Principal', 'krb5KDCEntry', 'scalixUserClass'], 'modifyTimestamp': ['20090901131127Z'] } 27.10.09 16:36:29 LISTENER ( ERROR ) : custom_export: old: {}
Das betrifft nicht nur den Resync von Modulen, siehe: 2009111010000247
Der an Ticket#: 2009091610000446 vorgeschlagene Patch,der dafür sorgt, dass nicht mehr alte Cache-Einträge mit Uppercase DN-key aus dem Cache geholt werden, sondern immer erst der lowercase-Key versucht wird, war schonmal ein Anfang, aber nicht ausreichend. Beim resync eines Moduls werden in change_init_module alle Cache-Einträge sequentiell ausgelesen, das Modul daran entfernt und wieder geschrieben. Das führt mit dem Patch aus Bug #15003 dazu, dass ein alter Cache-Eintrag mit Uppercase DN-key ausgelesen und dann unter lowercase DN-key geschrieben wird. Es gibt jetzt die alte cache_update_entry Funktion wieder, die case-Preserving ist. Für das geänderte Verhalten aus Bug #15003 gibt es jetzt eine neue Funktion cache_update_entry_lower, die als wrapper für die alte Funktion implementiert ist. Analog gibt es zwei neue Funktionen cache_entry_get_lower_upper und cache_etnry_delete_lower_upper, die zunächst den lowercase DN-key verwenden und bei DB_NOTFOUND Ergebnis es nochmal mit dem Uppercase DN-key versuchen, falls der übergebene DN mixedCase war. Ein Testverfahren mit Debug.py Listener Modul wird angehängt. Changelog: \item Ein Fehler beim Auslesen der Cache-Daten im \ucsName{univention-directory-listener} wurde behoben, der dazu führen konnte, dass bei der Verwendung von Großsbuchstaben in DNs im Falle eines Resync auf ein Listener-Modul veraltete (pre UCS 2.2-2) Daten ausgegeben wurden. Dieser Fehler lag in einer Änderung in UCS 2.2-2 begründet. Ein ähnliches Verhalten bei der Modifikation von solchen Verzeichniseinträgen wurde ebenfalls korrigiert. (Bug 16098)
Created attachment 2206 [details] Debug Listener Modul Zum Test ist es sinnvoll, ein Debug Listener Modul zu verwenden und zunächst kurz eine ältere Version des univention-directory-listeners aus UCS 2.2-0 zu installieren, um damit z.B. einen User mit Uppercasse Uid anzulegen. Die alte Version von univention-directory-listener legt Uppercase DNs auch noch so im Cache ab. Ab UCS 2.2-2 schreibt univention-directory-listener solche DNs hingegen als lowercase in den Cache, wobei der alte Cache-Eintrag jedoch im Cache erhalten bleibt. --- # Debug Listener Modul installieren: scp debug.py testvm:/usr/lib/univention-directory-listener/system/debug.py # listener aus UCS 2.2-0 installieren: apt-get install univention-directory-listener=3.0.2-2.48.200902190935 /etc/init.d/univention-directory-listener restart # Test User1 anlegen eval $(ucr shell ldap/base) udm users/user create --position cn=users,$ldap_base --set username=User1 --set description=Test0 --set password=univention --set lastname=Univention # Am bestene heier gleich auch User2 und User3 mit anlegen für weitere Tests. # Cache-Check /etc/init.d/univention-directory-listener stop univention-directory-listener-dump |grep -i ^"dn: uid=User1" /etc/init.d/univention-directory-listener start # Aktualisierten Listener installieren apt-get install univention-directory-listener # Description am User ändern udm users/user modify --dn uid=User1,cn=users,$ldap_base --set description=Test1 # Cache-Check: zwei Einträge /etc/init.d/univention-directory-listener stop univention-directory-listener-dump |grep -i ^"dn: uid=User1" /etc/init.d/univention-directory-listener start # Erneut Description am User ändern udm users/user modify --dn uid=User1,cn=users,$ldap_base --set description=Test2 # Check /var/log/univention/listener.log: # - Die Änderung muss in 'old' als description 'Test1' und nicht 'Test0' zeigen # Resync auslösen: univention-directory-listener-ctrl resync debug # Check /var/log/univention/listener.log: # - Die Änderung muss in 'new' als description 'Test2' und nicht 'Test0' zeigen ## Gut wäre es, auch kurz das Löschen von Einträgen zu testen: # a) Upercase Cache-Eintrag erzeugen (User2) und dann direkt nach Installation des neuen listeners löschen. Erwartung: Uppercase Cache-Eintrag sollte entfernt werden. # b) Upercase Cache-Eintrag erzeugen (User2) und dann direkt nach Installation des neuen listeners modifizieren. Danach löschen. Erwartung: lowercase Cache-Eintrag sollte entfernt werden, Uppercase Cache-Eintrag bleibt erhalten (das ist ok).
An Ticket#: 2010012510000413 hat dieser Bug vermutlich das cups-printers Modul auf den Printservern(DC Backup) mit alten Daten versorgt, was zu erheblichen Schwierigkeiten beim Anlegen von ca. 400 Druckern führte. Es lagen nach dem resync Skripte mit falschen/alten Daten unter /var/cache/univention-printserver welche beim Cupsneustart versucht wurden auszuführen und fehlschlugen. Auch nach dem Ändern von fast allen Druckern im LDAP per udm cli, hat ein resync auf cups-printers die Werte von vor der Änderung verwendet. Bitte bei der QA berücksichtigen.
(In reply to comment #4) > # b) Upercase Cache-Eintrag erzeugen (User2) und dann direkt nach Installation > des neuen listeners modifizieren. Danach löschen. Erwartung: lowercase > Cache-Eintrag sollte entfernt werden, Uppercase Cache-Eintrag bleibt erhalten > (das ist ok). Das ist ein Problem: 2.2-0: create User2 2.3-0: modify User2 -> user2 2.3-0: remove user2 2.3-0: create user2 <-- hier wird in 'old' der ursprüngliche User2 aus dem Cache übergeben, d.h. das wird als 'modify' und nicht als 'create' gewertet! In Bug #16618 trat genau so ein Problem auf, daß sowohl 'old' alsauch 'new' übergeben wurden, so daß kein bind-Zonendatei-Eintrag hinzugefügt wurde. Vermutlich ist es geschickter, bei einem 'delete' alle Groß-/Klein-Schreibweisen aus dem Cache zu löschen.
Created attachment 2259 [details] Test-Skript Das Skript läuft mit dem derzeitig _fehlerhaften_ Verhalten auf einem Master durch. Das _gewünschte_ Verhalten ist in den FIXME-Kommentaren angegeben. Auf einem Slave scheitert am Ende das Löschen der angelegten Testbenutzer, da die Daten nicht aus dem Cache entfernt werden (können?): 02.02.10 11:15:16 LISTENER ( ERROR ) : DEBUG(modify): old: ['uid=User1,cn=users,dc=univention,dc=qa'] ['Test2'] 02.02.10 11:15:16 LISTENER ( ERROR ) : DEBUG(modify): new: ['uid=User1,cn=users,dc=univention,dc=qa'] ['Test3'] 02.02.10 11:15:26 LISTENER ( ERROR ) : DEBUG(delete): old: ['uid=User1,cn=users,dc=univention,dc=qa'] ['Test3'] 02.02.10 11:15:26 LISTENER ( ERROR ) : DEBUG(delete): new: 02.02.10 11:15:26 LISTENER ( WARN ) : listener does not have value for key entryCSN 02.02.10 11:15:26 LISTENER ( WARN ) : memberUid: LDAP values and listener values diff 02.02.10 11:15:26 LISTENER ( WARN ) : replication: old entries from LDAP server and Listener do not match 02.02.10 11:15:27 LISTENER ( WARN ) : listener does not have value for key krb5Key 02.02.10 11:15:27 LISTENER ( WARN ) : replication: old entries from LDAP server and Listener do not match univention-directory-listener-dump: dn: uid=User1,cn=users,dc=univention,dc=qa ... listenerModule: replication listenerModule: custom_export listenerModule: debug
Der univention-directory-listener versucht jetzt bei mixedcase DNs auch immer nicht nur den lowercase-Eintrag zu löschen, sondern auch den mixedcase-Eintrag. Das Test-Script lief erfolgreich durch.
Mein Test-Skript läuft jetzt auch erwartungsgemäß ohne anzuecken durch. Bezüglich der Druckertreiber sollte das Problem auch behoben sein: Die CUPS-Druckertreiber benutzen gemischte Groß-/Kleinschreibung in den DNs, was beim Modifizieren zu Doppeleintragungen (mixed- & lower-case) geführt hat. Mit der neusten Version in 2.3-1 sollte das jetzt behoben sein. ChangeLog-Eintrag ist vorhanden -> VERIFIED
UCS 2.3-1 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".