Bug 29603 - Log-Spam: UNIVENTION_DEBUG_(BEGIN|END) : admin.handlers.base.__getitem__ key =
Log-Spam: UNIVENTION_DEBUG_(BEGIN|END) : admin.handlers.base.__getitem__ key =
Status: CLOSED FIXED
Product: UCS
Classification: Unclassified
Component: UMC (Generic)
UCS 3.1
All Linux
: P5 minor (vote)
: UCS 3.1-1-errata
Assigned To: Jascha Geerds
Philipp Hahn
:
Depends on:
Blocks: 31421
  Show dependency treegraph
 
Reported: 2012-12-06 14:29 CET by Philipp Hahn
Modified: 2013-05-22 21:57 CEST (History)
5 users (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:
Flags outvoted (downgraded) after PO Review:
Ticket number:
Bug group (optional): Cleanup, Troubleshooting
Max CVSS v3 score:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Philipp Hahn univentionstaff 2012-12-06 14:29:10 CET
In /var/log/univention/management-console-module-udm.log stehen massenhaft Meldungen der Art
  UNIVENTION_DEBUG_BEGIN : admin.handlers.base.__getitem__ key = network
  UNIVENTION_DEBUG_END   : admin.handlers.base.__getitem__ key = network
  UNIVENTION_DEBUG_BEGIN : admin.handlers.base.__getitem__ key = name
  UNIVENTION_DEBUG_END   : admin.handlers.base.__getitem__ key = name
  ... domain ... primaryGroup ... unixhome ... primaryGroup ... name ... ip ... dnsEntryZoneForward ... ip ... mac
  ... admin.handlers.simpleLdap._update_policies
  ... uldap.getPolicies
  ... uldap.parentDn
  ... uldap.getAttr

Ich finde diese Meldungen nicht hilfreich und sie verdecken wichtige Meldungen eher durch ihr Rauschen. IMHO sollten sie nicht standardmäßig geloggt werden.
Comment 1 Dirk Wiesenthal univentionstaff 2013-02-26 21:56:00 CET
+1. Das gilt für jedes Modul, das mal eben kurz im LDAP suchen will (vor allem, wenn es dann object.open() aufruft). Bei mir ist das das App Center.

Wer im Glashaus sitzt... das App Center Log besteht zu einem guten Prozentsatz aus apt-get update Meldungen. Dafür mache ich mal einen eigenen Bug auf, wenn ich die Zeit finde.
Comment 2 Stefan Gohmann univentionstaff 2013-02-27 06:46:17 CET
Ziel der Begin / End Meldungen ist es eine Rückverfolgung der Funktionen zu ermöglichen. Wenn nicht gewünscht, dann kann in der init-Funktion von debug übergeben werden, dass diese nicht geloggt werden sollen.
Comment 3 Alexander Kläser univentionstaff 2013-03-04 14:10:14 CET
enum uv_debug_flag_flush {
    UV_DEBUG_NO_FLUSH = 0x00,
    UV_DEBUG_FLUSH = 0x01
};

enum uv_debug_flag_function {
    UV_DEBUG_NO_FUNCTION = 0x00,
    UV_DEBUG_FUNCTION = 0x01
};

> FILE * univention_debug_init(const char *logfile, enum uv_debug_flag_flush flush, enum uv_debug_flag_function function)

$ rgrep init.*FLUSH src/
src/univention/management/console/log.py:       fd = ud.init( filename, ud.FLUSH, ud.FUNCTION )

D.h. dazu müsste in umc.log das ud.FUNTION durch ein ud.NO_FUNCTION ersetzt werden? Die Werte werden momentan so fix für alle Module gesetzt. Wir könnten sie für UMC-Module generisch durch diese Änderung rausnehmen. Wäre ich soweit dafür.
Comment 4 Philipp Hahn univentionstaff 2013-04-05 15:48:14 CEST
Das ist heute erneut bei einem Kunden aufgefallen:
(In reply to comment #2)
> Ziel der Begin / End Meldungen ist es eine Rückverfolgung der Funktionen zu
> ermöglichen. Wenn nicht gewünscht, dann kann in der init-Funktion von debug
> übergeben werden, dass diese nicht geloggt werden sollen.

die Funktionen sind teilweise sehr kurz, aber trotzdem werden pro Funktionsaufruf jeweils zwei Zeilen geloggt: UNIVENTION_DEBUG_BEGIN und ..._END

Die millionenfache Aussgabe von "__getitem__ key = name" macht die Fehlersuche nicht einfacher, sondern schwieriger, weil die relevanten Zeilen verdeckt werden.
Comment 5 Philipp Hahn univentionstaff 2013-04-05 16:01:52 CEST
(In reply to comment #4)
> Das ist heute erneut bei einem Kunden aufgefallen:

Um eine konkrete Zahl zu nennen: Das öffnen eines (!) Rechnerobjekts hat 
157.326 Logzeilen generiert,
 12.534 waren keine __getitem__ Logmeldungen, d.h.
144.792 waren __getitem__ Logmeldungen

Bei dem Kunden gibt es 1312 Gruppen im LDAP, inklusive Gruppen in Gruppen.
Comment 6 Jascha Geerds univentionstaff 2013-04-17 14:28:05 CEST
Wie von Alex vorgeschlagen wurde "ud.FLUSH" und "ud.FUNCTION" durch "ud.NO_FLUSH" und "ud.NO_FUNCTION" ersetzt. UNIVENTION_DEBUG_{BEGIN, END} Informationen werden nicht mehr gelogt.

- ucs3.1-2 & changelog:
Package: univention-management-console
Version: 5.0.63-1.728.201304171401

- ucs3.1-1 & YAML:
Package: univention-management-console
Version: 5.0.62-2.729.201304171418
Comment 7 Philipp Hahn univentionstaff 2013-04-29 15:38:09 CEST
(In reply to comment #6)
> Wie von Alex vorgeschlagen wurde "ud.FLUSH" und "ud.FUNCTION" durch
> "ud.NO_FLUSH" und "ud.NO_FUNCTION" ersetzt. UNIVENTION_DEBUG_{BEGIN, END}
> Informationen werden nicht mehr gelogt.

OK: UNIVENTION_DEBUG_(BEGIN|END) sind weg.

> - ucs3.1-2 & changelog:
> Package: univention-management-console
> Version: 5.0.63-1.728.201304171401

OK: svn39776
OK: upgrade 3.1-1 → errata3.1-1 → 3.1-2
FIXED: ChangeLog: \_ escaping for LaTeX

> - ucs3.1-1 & YAML:
> Package: univention-management-console
> Version: 5.0.62-2.729.201304171418

OK: svn40048
OK: upgrade 3.1-1 → 3.1-2
OK: announce_errata -n 2013-04-17-univention-management-console.yaml
Comment 8 Moritz Muehlenhoff univentionstaff 2013-05-22 16:11:00 CEST
http://errata.univention.de/ucs/3.1/103.html