[WIP] Improve log view so one can filter out messages based on verbosity or domains #830

zas · 2018-02-04T17:15:39Z

Summary

This is a…
- Bug fix
- Feature addition
- Refactoring
- Minor / simple change (like a typo)
- Other
Describe this change in 1-2 sentences:

Problem

Application log view is really user-friendly, but underlying log system neither.
To improve it, few features will be added:

log "domains", allowing devs to regroup logs in sets
log verbosity filtering in log view
log domains filtering in log view
log highlighting in log view
saving current log to file

Related to PICARD-1185

Solution

log "domains" are implemented, every log.(error|warn|debug|info)() now accepts an optional set of domains using domains kv parameter
log messages are stored in a list of MessageObj, which has domains and level properties
log verbosity can be set through a menu in log view
log domains can be hidden through a menu in log view
user-defined text can be highlighted in log view

Action

Review & test, the code is still very experimental, feedback welcome

samj1912 · 2018-02-05T08:21:41Z

picard/acoustid/__init__.py

            else:
                mparms = {
                    'error': document['error']['message'],
                    'filename': file.filename
                }
                log.error(
                    "AcoustID: Lookup error for '%(filename)s': %(error)r" %
-                    mparms)
+                    mparms, domains='acoustid')


Instead of manually specifying the domains, we can use the built in logging module from python stdlib and take advantage of its attributes https://docs.python.org/3/library/logging.html#logrecord-attributes

This will save us all the overhead and the repetitions

I'd say we can simply drop the domains part and just keep the UI additions and maybe we can continue this in another PR

Instead of manually specifying the domains, we can use the built in logging module from python stdlib and take advantage of its attributes https://docs.python.org/3/library/logging.html#logrecord-attributes

This will save us all the overhead and the repetitions

I don't see how LogRecord provides this feature, as is.
Using module is not what i want, since, in the same module, i want to be able to specify the domain of the log line. Filtering on module can be good, but that's not my goal.
In fact, to implement this you need to subclass logging.Logger, something like that:

def _onestr2set(domains): if not domains: return set() if isinstance(domains, str): # this is a shortcut: allow one to pass a domains as sole # argument, but use it as first argument of set return set((domains,)) else: return set(domains) class CustomLogger(logging.Logger): def _log(self, level, msg, args, exc_info=None, extra=None): if extra is None: extra = { 'domains': set() } super(CustomLogger, self)._log(level, msg, args, exc_info, extra) logging.setLoggerClass(CustomLogger) def debug(message, *args, domains=None): domains = _onestr2set(domains) root.debug(message, *args, extra={'domains': domains}) def info(message, *args, domains=None): domains = _onestr2set(domains) root.info(message, *args, extra={'domains': domains}) def warning(message, *args, domains=None): domains = _onestr2set(domains) root.warning(message, *args, extra={'domains': domains}) def error(message, *args, domains=None): domains = _onestr2set(domains) root.error(message, *args, extra={'domains': domains}) root = logging.getLogger('picard') root.setLevel(logging.DEBUG) handler = logging.StreamHandler() bf = logging.Formatter('{asctime} {levelname:8s} {message} {domains}', style='{') handler.setFormatter(bf) root.addHandler(handler)

samj1912 · 2018-02-05T08:30:13Z

picard/ui/logview.py

+            act.triggered.connect(partial(self._verbosity_changed, level))
+            self.verbosity_menu.addAction(act)
+
+        self.verbosity_menu_button = QtWidgets.QPushButton(_("Verbosity"))


Any reason for having the gui layouts part here instead of a ui file?

Nope, but since menus are generated, you'll not have much more than few widgets in ui file anyway.

samj1912 · 2018-02-05T11:16:16Z

picard/ui/logview.py

@@ -25,6 +27,8 @@

 class LogViewCommon(PicardDialog):

+    default_verbosity = {log.LOG_INFO, log.LOG_WARNING, log.LOG_ERROR, log.LOG_DEBUG}


I am not sure how much sense this makes. Generally debug includes all the levels above it. So if debug is checked all errors, info and warning logs should come too.
This is default behaviour in almost all loggers.

That's not the behaviour of the logger here, but the behaviour of the log viewer: each log message is set to a certain level (and that's the default behaviour of almost all loggers), whether you want to log or display a certain level is up to you.
For example, i may want to write only debug messages to one debug file, and the rest in a common file, or each level in a separate file, that's not defined by the logger, but by the log handler.

The idea here is to reduce the view to what is interesting, if i know the thing i'm looking for is a debug message, i want to hide the other levels. And this is possible here.

samj1912 · 2018-02-05T11:17:30Z

picard/ui/logview.py

@@ -37,7 +41,11 @@ def __init__(self, title, logger, w=740, h=340, parent=None):
        self.browser.setDocument(self.doc)
        self.vbox = QtWidgets.QVBoxLayout(self)
        self.vbox.addWidget(self.browser)
-        self._display()
+        self._setup_formats()
+        self.verbosity = self.default_verbosity


Dont really get the use of the debug checkbox and this drop down. We can keep only this and remove the checkbox?

Dont really get the use of the debug checkbox and this drop down. We can keep only this and remove the checkbox?

That's 2 different things, once again, you mix up the logger and the log viewer:

debug mode controls if we log debug messages (if disabled, they aren't written anywhere at all)

verbosity debug unchecked will hide the debug messages from the view, but they are still outputted to console for example

Hmm, can we separate the logger config from the log viewer config?

Hmm, can we separate the logger config from the log viewer config?

What do you mean ?

Debug mode is just a trick to allow user to enable the debug mode from within the app (before it was only possible using the -d command line option).
Logging level setting could be moved elsewhere in Options, but then it would be a bit cumbersome to toggle debug mode on/off.

Think about the end user:

open Log View

check Debug mode checkbox

do some action

press Save as

uncheck Debug mode checkbox

Instead of:

Open Options

go to panel "Advanced"

set the log level to Debug (if it wasn't already...)

Press OK

open the Log View

do some action

press Save as

Open Options

go to panel "Advanced"

set the log level back to what it was (if you remember)

Press OK

samj1912 · 2018-02-05T11:19:21Z

picard/ui/logview.py

-        self._display()
+        self._setup_formats()
+        self.verbosity = self.default_verbosity
+        self.hidden_domains = set()


Again, don't get why both domains and show only domains are needed? Does selecting domains discard messages altogether and show only create a temp filter? If so, we should keep the distinction between filters and records separate.

Because domains is a tuple (even if a trick allows to pass just a string, when the tuple should have only one element), example:

a message A with domains ('ws', 'ratecontrol')

a message B with domains ('ws')

a message C with domains ('ratecontrol')

a message D with domains ('ws', 'ratecontrol', 'subratecontrol')

Show only (ws) shows A,B,D (only)
Show only (ws, ratecontrol) shows A, B, C,D

Show only (ws, ratecontrol) + hide ('subratecrontrol') shows A, B, C but not D

Show only totally unset + hide ('ws') shows C only

That said, i didn't write tests to ensure the actual behaviour is the one i expect ;)

Do you get why both are needed ? Include list + exclude list, both working together to provide more than you could do with just one.

samj1912 · 2018-02-05T11:20:34Z

picard/ui/logview.py

+        self.hbox.addWidget(self.domains_menu_button)
+        self.hbox.addWidget(self.show_only_domains_menu_button)
+
+        self.highlight_text = QtWidgets.QLineEdit()


Pressing enter after inputting text shifts the UI to verbosity selection instead of applying the HL.

Yes, i know, i'll clean up those UI quirks later when we are sure which features we want and how (experimental PR)

samj1912 · 2018-02-05T11:21:27Z

picard/ui/logview.py

+        self.hbox.addWidget(self.highlight_button)
+        self.highlight_button.clicked.connect(self._highlight_do)
+
+        self.clear_log_button = QtWidgets.QPushButton(_("Clear Log"))


Can we add some tooltips for all these options? It is unclear to a user whether these are destructive or just temp.

Yes, of course, this option actually clears the circular buffer. UI tuning will come at the end.

samj1912 · 2018-02-06T08:40:03Z

picard/log.py

+    if enabled:
+        main_logger.setLevel(logging.DEBUG)
+    else:
+        main_logger.setLevel(logging.INFO)


Shouldn't the default level be WARNING?

Historically, log was showing anything but debug level

samj1912 · 2018-02-06T09:22:26Z

Thought of a good idea to add domains to a function - (This can go in picard.util )

from picard import log
from functools import partial, wraps
def domain(*domains):
    def wrapper(f):
        @wraps(f)
        def caller(*args, **kwargs):
            log.debug = partial(log.debug, domains=domains)
            log.info = partial(log.info, domains=domains)
            log.warning = partial(log.warning, domains=domains)
            log.error = partial(log.error, domains=domains)
            return f(*args, **kwargs)
        return caller
    return wrapper

It can be used as follows

@domain('random', 'more')
def random_func(*args):
    log.debug('logs as the above domains')

Makes the above more readable too as we know what domain a function is associated with. And ofc if we supply the domains explicitly, it overrides the decorator.

Convert Logger to QObject, and emit a signal when the domain list is modified Disable updates when the menu is shown No need to open/close log view anymore

Name, prefix and color for each log level are set in one place

It implies few changes, most notably a re-implementation of a circular buffer (deque-based) as a logging handler. The way history log is displayed in the History View was adapted too.

- get rid of LogMessage and old Logger class - adapt log view code according to those changes - code tidy up and simplification

- funcname and pathname are now correct - drop ratelimit wrapper - accept domains kv argument on all log.*(): log.debug('string', domains={'a','b','c'}) - provide a useful "name" since we are using only one logger, and since module is useless for submodules (=__init__ for all)

logger.(debug|error|...)() are just doing that

- much simpler and reliable - fix few button enabled/disabled quirks - fix highlighting on log updates - highlight exactly the string entered, but support wildcards (* and ?)

@Domain

- Overhead is reduced compared to previous version - support mixing domains= log.*() argument and @Domain decorator, sets are merged - add support for log.log()

zas · 2018-02-09T13:28:53Z

Replaced by simpler #834

zas requested a review from samj1912 February 4, 2018 17:47

samj1912 reviewed Feb 5, 2018

View reviewed changes

samj1912 requested changes Feb 5, 2018

View reviewed changes

zas force-pushed the log_domains branch from f370880 to d0da70f Compare February 5, 2018 14:06

samj1912 reviewed Feb 6, 2018

View reviewed changes

zas force-pushed the log_domains branch from c494dd2 to 22d5ae9 Compare February 7, 2018 10:10

zas added 22 commits February 8, 2018 01:09

[WIP] Log domains

f62883f

Fix up HistoryView._formatted_log_line()

b8a6c92

Add verbosity control to log view

1f82fac

Add a way to highlight text in the log view

9c606da

Add preliminary support for filtering by domains

fbc6504

Fix Dangerous default value _log_prefixes (builtins.dict) as argument

2a879c6

Rebuild the domains menu dynamically

eb00033

Convert Logger to QObject, and emit a signal when the domain list is modified Disable updates when the menu is shown No need to open/close log view anymore

Fix Redefining built-in 'format'

a137b00

Add the possibility to show only specified domains

d5e6649

Add a button to clear displayed log

30838d7

Add Save As feature: save current view to file

bc78f1f

Use logging module levels

6d1e544

Reduce code redundancy, introducing levels features

83bf06a

Name, prefix and color for each log level are set in one place

Replace LogViewCommon.default_verbosity with set(log.levels_features)

d58b253

Do not crash when no receiver was registered and dialog is closed

586efa2

Introduce a parent class LogViewDialog

08972fb

Make Codacy happier

1b84053

Use logging module to log history

fc49a45

It implies few changes, most notably a re-implementation of a circular buffer (deque-based) as a logging handler. The way history log is displayed in the History View was adapted too.

Replace _stderr_receiver() with logging.StreamHandler()

334e26b

Add support for domains to TailLogger and TailLogHandler

318ca6a

Fully switch to logging module

78fe701

- get rid of LogMessage and old Logger class - adapt log view code according to those changes - code tidy up and simplification

Drop log.*() domains argument, and use log.domain decorator instead

630d593

zas added 15 commits February 8, 2018 01:09

Add missing import

55cf8ae

Add comments about findCaller()

90a8395

Fix Parameters differ from overridden 'display' method

3494ae2

Replace hardcoded max tail length by a constant

9381072

Fix Clear Log in Log View

6d7fe7c

Use same log format for in-app and console

edad4f8

Clean log view UI, add confirmation on Clear Log, etc..

2c9c47b

Add log.exception()

490fc7b

Do the level check and call logging._log() directly

26456b1

logger.(debug|error|...)() are just doing that

Fix up record.name in few corner cases, normalize paths

a53908d

Add lineno to default log format

35766e1

Rework plugin.py logging, adding domains and using log.exception()

73a2f77

Fix name_filter() and tidy up log output

19253a8

Re-implement highlighting using QSyntaxHighlighter

95116f2

- much simpler and reliable - fix few button enabled/disabled quirks - fix highlighting on log updates - highlight exactly the string entered, but support wildcards (* and ?)

zas force-pushed the log_domains branch from cdf4321 to 95116f2 Compare February 8, 2018 00:10

zas added 2 commits February 9, 2018 00:19

Improve @Domain decorator

fe955cc

- Overhead is reduced compared to previous version - support mixing domains= log.*() argument and @Domain decorator, sets are merged - add support for log.log()

Fix domains filtering logic

534c82f

zas mentioned this pull request Feb 9, 2018

Rework logging system and in-app log view #834

Merged

zas closed this Feb 9, 2018

zas deleted the log_domains branch March 30, 2019 15:09

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[WIP] Improve log view so one can filter out messages based on verbosity or domains #830

[WIP] Improve log view so one can filter out messages based on verbosity or domains #830

zas commented Feb 4, 2018 •

edited

samj1912 Feb 5, 2018

samj1912 Feb 5, 2018

zas Feb 5, 2018

samj1912 Feb 5, 2018

zas Feb 5, 2018

samj1912 Feb 5, 2018

zas Feb 5, 2018

samj1912 Feb 5, 2018

zas Feb 5, 2018

samj1912 Feb 5, 2018

zas Feb 5, 2018

samj1912 Feb 5, 2018

zas Feb 5, 2018

samj1912 Feb 5, 2018

zas Feb 5, 2018

samj1912 Feb 5, 2018

zas Feb 5, 2018

samj1912 Feb 6, 2018

zas Feb 6, 2018

samj1912 commented Feb 6, 2018 •

edited

zas commented Feb 9, 2018

		@@ -25,6 +27,8 @@

		class LogViewCommon(PicardDialog):

		default_verbosity = {log.LOG_INFO, log.LOG_WARNING, log.LOG_ERROR, log.LOG_DEBUG}

[WIP] Improve log view so one can filter out messages based on verbosity or domains #830

[WIP] Improve log view so one can filter out messages based on verbosity or domains #830

Conversation

zas commented Feb 4, 2018 • edited

Summary

Problem

Solution

Action

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

samj1912 commented Feb 6, 2018 • edited

zas commented Feb 9, 2018

zas commented Feb 4, 2018 •

edited

samj1912 commented Feb 6, 2018 •

edited