[elbe-devel] [PATCH 02/32] log.py - New logging system

[Torben Hohn]

On Fri, Jun 14, 2019 at 10:13:16PM +0200, dion at linutronix.de wrote:
> From: Olivier Dion <dion at linutronix.de>
> 
> The new ELBE logging system will be using the Python standard
> _logging_ module.
> 
> The _logging_ module is line oriented and module oriented.  What it
> means is that seperated modules should have seperated _logger_ object.

err... the logging is not really line oriented, how did you come to this
conclusion ?

its also not module oriented. How did you come to this conclusion ?

we want to get away from the asciidoc format, because its not good
to parse.

please make the code use logging.debug() and friends everywhere.
define 2 custom loglevels for validation.txt and elbe-report.txt

add a filter that collects contextual information.
https://docs.python.org/2/howto/logging-cookbook.html#using-filters-to-impart-contextual-information

this has to query the current project path, which is supposed to be
setup in a thread local variable. 
https://docs.python.org/2/library/threading.html#threading.local
store the path and the current elbeproject.

these need to be setup in elbepack/asyncworker.py

then hook several handlers into the root logger.

one for elbe-report.txt, and validation.txt and log.txt each.
you probably need to filter things a bit. because you dont want
elbe-report things in log.txt....

then add another logger, that pushes the structured events into
a queue, and make the wait_busy code just read out that queue.
the soap interface allows to pass objects.
Map the LogRecord to a soap object.
(you need to convert a few internal python objects (like the ElbeProject
and exc_info to strings)

https://docs.python.org/2/library/logging.html#logging.LogRecord 

and then change the code in wait_busy to continously drain that queue.
and print the logging infos.

> This is not working well with ELBE.  Thus, the _logging_ module has
> being wrapped in "log.py".
> 
> * Block message
> 
>   Logged message are format in _block_.  A block is composed of 3
>   parts.
> 
>     - Header (optional)
>     - Message
>     - Footer (optional)
> 
>   Headers are underline by '=' and footers are overline by '-'.
> 
>   A block's message can also be marked to be verbatim.  In that case,
>   the message is enclosed by ">>>>>\n" and "<<<<<".
> 
> ** Example
> 
>    ```````````````````````````````````````````````````````````````````
>    log.debug("My very very very long message\n", verbatim=True,
>              header="This is a header",
>              footer="Here's my footer")
>    ```````````````````````````````````````````````````````````````````
> 
>    Will result in the following message to be log:
>    ```````````````````````````````````````````````````````````````````
>    This is a header
>    ================
>    >>>>>
>    My very very very long message
>    <<<<<
>    ----------------
>    Here's my footer
>    ```````````````````````````````````````````````````````````````````
> 
> * Log Level
> 
>   There's not difference between log levels.  At least not in the
>   formating of a message.  Log levels exist only to filter different
>   messages.
> 
> * Redirection
> 
>   There's 3 modes of redirection of the logged messages.  Only one of
>   them can be choose at a time.
> 
> ** File
> 
>    Using 'log.new(filename)', the log object will create a new 'file
>    handler' at 'filename'.  All consequent messages send to that log
>    will be write to 'filename'.  'log::new' is often used when opening
>    a project, since it's at this moment that we know the build
>    directory of that project.
> 
> ** Stdout
> 
>    Using 'log.stdout()' will redirect all further messages to the
>    default 'stream handler' of the process.
> 
> ** Null
> 
>    Using 'log.null()' will redirect all further messages to
>    "/dev/null".
> 
> * elbe-report
> 
>   The 'log' object is reserved for logging to "log.txt".  To log to
>   the "elbe-report.txt", use the 'report' object.
> 
> ** Example
> 
>    ``````````````````````````````````````````````````````````````````
>    from elbepack.log import log, report
>    log.new("/var/cache/elbe/buildir-id/log.txt")
>    report.stdout()
>    log.info("This will log to log.txt")
>    report.info("This will log to stdout")
>    report.new("/var/cache/elbe/buildir-id/elbe-report.txt")
>    report.critical("This will log to elbe-report.txt")
>    ``````````````````````````````````````````````````````````````````
> 
> Signed-off-by: Olivier Dion <dion at linutronix.de>
> ---
>  elbepack/log.py | 105 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++
>  1 file changed, 105 insertions(+)
>  create mode 100644 elbepack/log.py
> 
> diff --git a/elbepack/log.py b/elbepack/log.py
> new file mode 100644
> index 00000000..6188e163
> --- /dev/null
> +++ b/elbepack/log.py
> @@ -0,0 +1,105 @@
> +# ELBE - Debian Based Embedded Rootfilesystem Builder
> +# Copyright (c) 2019 Olivier Dion <dion at linutronix.de>
> +#
> +# SPDX-License-Identifier: GPL-3.0-or-later
> +
> +import os
> +import logging
> +import logging.config
> +
> +raw_fmt = logging.Formatter("\n%(message)s")
> +
> +class log:
> +
> +    log = None
> +    filename = None
> +    handler = None
> +
> +    @classmethod
> +    def fmt_footer(cls, footer, c):
> +        if footer:
> +            return "\n%s\n%s" % ((c * len(footer)), footer)
> +        return ""
> +
> +    @classmethod
> +    def fmt_header(cls, header, c, end="\n"):
> +        if header:
> +            return "%s\n%s%s" % (header, (c * len(header)), end)
> +        return ""
> +
> +    @classmethod
> +    def fmt_msg(cls, msg, header, footer, verbatim):
> +        if verbatim:
> +            msg = ">>>>>\n%s<<<<<" % msg
> +        return "%s%s%s" % (cls.fmt_header(header, '='),
> +                           msg,
> +                           cls.fmt_footer(footer, '-'))
> +
> +    @classmethod
> +    def new(cls, filename):
> +        cls.filename = filename
> +        cls.log = logging.getLogger(cls.__name__)
> +        cls.log.setLevel(logging.DEBUG)
> +        cls.log.propagate = False
> +        if cls.handler is not None:
> +            cls.log.removeHandler(cls.handler)
> +        cls.handler = logging.FileHandler(cls.filename)
> +        cls.handler.setFormatter(raw_fmt)
> +        cls.log.addHandler(cls.handler)
> +
> +    @classmethod
> +    def stdout(cls):
> +        cls.filename = "STDOUT"
> +        cls.log = logging.getLogger(cls.__name__)
> +        cls.log.setLevel(logging.DEBUG)
> +        cls.log.propagate = False
> +        if cls.handler is not None:
> +            cls.log.removeHandler(cls.handler)
> +        cls.handler = logging.StreamHandler()
> +        cls.log.addHandler(cls.handler)
> +
> +    @classmethod
> +    def null(cls):
> +        cls.filename = "/dev/null"
> +        cls.log = logging.getLogger(cls.__name__)
> +        cls.log.setLevel(logging.DEBUG)
> +        cls.log.propagate = False
> +        if cls.handler is not None:
> +            cls.log.removeHandler(cls.handler)
> +        cls.handler = logging.FileHandler("/dev/null")
> +        cls.log.addHandler(cls.handler)
> +
> +    @classmethod
> +    def h1(cls, header):
> +        cls.info("%s" % (log.fmt_header(header, '=', end="")))
> +
> +    @classmethod
> +    def h2(cls, header, msg=""):
> +        cls.info("%s" % (log.fmt_header(header, '-', end="")))
> +
> +    @classmethod
> +    def debug(cls, msg, header="", footer="", verbatim=False):
> +        cls.log.debug(cls.fmt_msg(msg, header, footer, verbatim))
> +
> +    @classmethod
> +    def info(cls, msg, header="", footer="", verbatim=False):
> +        cls.log.info(cls.fmt_msg(msg, header, footer, verbatim))
> +
> +    @classmethod
> +    def warning(cls, msg, header="", footer="", verbatim=False):
> +        cls.log.warning(cls.fmt_msg(msg, header, footer, verbatim))
> +
> +    @classmethod
> +    def error(cls, msg, header="", footer="", verbatim=False):
> +        cls.log.error(cls.fmt_msg(msg, header, footer, verbatim))
> +
> +    @classmethod
> +    def critical(cls, msg, header="", footer="", verbatim=False):
> +        cls.log.critical(cls.fmt_msg(msg, header, footer, verbatim))
> +
> +    @classmethod
> +    def exception(cls, msg, header="", footer="", verbatim=False):
> +        cls.log.exception(cls.fmt_msg(msg, header, footer, verbatim))
> +
> +class report(log):
> +    pass
> -- 
> 2.11.0
> 
> 
> _______________________________________________
> elbe-devel mailing list
> elbe-devel at linutronix.de
> https://lists.linutronix.de/mailman/listinfo/elbe-devel

-- 
Torben Hohn
Linutronix GmbH | Bahnhofstrasse 3 | D-88690 Uhldingen-Mühlhofen
Phone: +49 7556 25 999 18; Fax.: +49 7556 25 999 99

Hinweise zum Datenschutz finden Sie hier (Informations on data privacy 
can be found here): https://linutronix.de/kontakt/Datenschutz.php

Linutronix GmbH | Firmensitz (Registered Office): Uhldingen-Mühlhofen | 
Registergericht (Registration Court): Amtsgericht Freiburg i.Br., HRB700 
806 | Geschäftsführer (Managing Directors): Heinz Egger, Thomas Gleixner