Bug 41595 - revise ucsschool logging
revise ucsschool logging
Status: CLOSED FIXED
Product: UCS@school
Classification: Unclassified
Component: Ucsschool-lib
UCS@school 4.1 R2
Other Linux
: P5 enhancement (vote)
: UCS@school 4.1 R2 vXXX
Assigned To: Daniel Tröder
Sönke Schwardt-Krummrich
: interim-2
Depends on:
Blocks: 42315
  Show dependency treegraph
 
Reported: 2016-06-16 12:45 CEST by Daniel Tröder
Modified: 2016-10-06 08:50 CEST (History)
3 users (show)

See Also:
What kind of report is it?: Development Internal
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):
Max CVSS v3 score:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Daniel Tröder univentionstaff 2016-06-16 12:45:43 CEST
Depending on the client (umc / import scripts) the libs log output goes through different logging backends (Python logging, udebug) and different formatting. Formatting and retention policies (rotation) depend on the backend.

Unify the logging API as well as the backend for the ucsschool lib and its clients.
Comment 1 Daniel Tröder univentionstaff 2016-07-14 17:18:31 CEST
A function to comfortably and efficiently handle hierarchical Python loggers was added to the ucs-school-lib package. It allows to retrieve stream and file loggers, customization etc. It takes care, that handlers for the same target (stdout / a file) are not added twice to a logger.

The import-script code was adapted, code that is touched by UMC modules has not been altered, as it could conflict with univention.debug.

code change ucs-school-lib: 71004
code change ucs-school-import: 71005
advisory build numbers: 71006


def get_logger(name, level="INFO", target=sys.stdout, handler_kwargs=None, formatter_kwargs=None):
	"""
	Get a logger object below the ucsschool root logger.

	* The logger will use UniStreamHandler(StreamHandler) for streams
	(sys.stdout etc) and UniFileHandler(TimedRotatingFileHandler) for files if
	not configured differently through handler_kwargs[cls].
	* A call with the same name will return the same logging object.
	* There is only one handler per name-target combination.
	* If name and target are the same, and only the log level changes, it will
	return the logging object with the same handlers and change both the log
	level of the respective handler and of the logger object to be the lowest
	of the previous and the new level.
	* Complete output customization is possible, setting kwargs for the
	constructors of the handler and formatter.
	* Using custom handler and formatter classes is possible by configuring
	the 'cls' key of handler_kwargs and formatter_kwargs.
	* The logging level can be configured through ucsschool/logging/level/<name>.

	:param name: str: will be appended to "ucsschool." as name of the logger
	:param level: str: loglevel (DEBUG, INFO etc), the UCRV
	ucsschool/logging/level/<name> overwrites this setting!
	:param target: stream (open file) or a str (file path)
	:param handler_kwargs: dict: will be passed to the handlers constructor.
	It cannot be used to modify a handler, as it is only used at creation time.
	If it has a key 'cls' it will be used as handler instead of UniFileHandler
	or UniStreamHandler. It should be a subclass of one of those!
	:param formatter_kwargs: dict: will be passed to the formatters constructor,
	if it has a key 'cls' it will be used to create a formatter instead of
	logging.Formatter.
	:return: a python logging object
Comment 2 Daniel Tröder univentionstaff 2016-07-15 09:51:22 CEST
Added small fixes in r71018 and r71019.
Comment 3 Daniel Tröder univentionstaff 2016-07-22 11:13:25 CEST
r71187 adds the log output of the ucsschool.lib to the one from the import.
Comment 4 Sönke Schwardt-Krummrich univentionstaff 2016-08-24 16:38:47 CEST
I'm not that happy with the new UCR variable 
"ucsschool/logging/level/XYZ=(DEBUG|INFO|WARN|ERROR)" :

a) the set of possible values differs from our known debug level system: 0-4 
b) the UCR variable name does not end with "/debug/level" → unexpected by customers

I would suggest the following:

ucsschool/XYZ/debug/level=(DEBUG|WARN|INFO|ERROR|0|1|2|3|4)

The numeric values are mapped to "logging" values: 
0→ERROR, 1→WARN, 2+3→INFO, 4→DEBUG


Additionally: the UCR variable has precedence over other level settings (CLI settings), which is not optimal.

# cd /usr/share/ucs-school-import/scripts/
# ucr set ucsschool/logging/level/import=ERROR
Create ucsschool/logging/level/import
# ./ucs-school-user-import -i B2 --sourceUID B2
# ./ucs-school-user-import -i B2 --sourceUID B2 -v
# 

Additionally: if debug level is set to ERROR, in the case above nothing is logged to stdout or /var/lib/univention/ucs-school-import.log
Comment 5 Sönke Schwardt-Krummrich univentionstaff 2016-08-24 16:50:11 CEST
As discussed, the UCR variable has to be removed for now. After a sensible logging concept has been defined, the UCR variable should be reintegrated.
Comment 6 Daniel Tröder univentionstaff 2016-08-26 11:01:16 CEST
r71962: remove UCRV support for setting the effective log level
Comment 7 Sönke Schwardt-Krummrich univentionstaff 2016-08-26 16:37:05 CEST
OK: code change
OK: functional test
OK: YAML
Comment 8 Sönke Schwardt-Krummrich univentionstaff 2016-10-04 13:24:43 CEST
UCS@school 4.1 R2 v5 has been released.

http://docs.software-univention.de/changelog-ucsschool-4.1R2v5-de.html

If this error occurs again, please clone this bug.