WIP*: Reduce logspam #1905
Closed
WIP*: Reduce logspam #1905
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This is a completely normal condition when running in the AppImage container, so it just amounts to unnecessary logspam.
Don't log attempt to set font, just failure Don't log when setting dark theme Convert "Processing command-line arguments:" into debug message
Don't log confusing "Skipping English..." message Don't log _attempts_ to load translators Log successful attempts as debug messages
Don't always log versions from project file in `upgrade_project_data_structures()`, only log when upgrade paths are taken. Don't spew generic message whenever files contain temp blender paths. Updated file-recovery output to be more informative Replaced some %-formatted strings in log messages with .format() strings
Don't log every time the preview is resized Promote "Error applying JSON to timeline..." messages from info to error
This will allow some log messages in Angular source to be reduced from `log.info()` to `log.debug()` priority
This reverts commit 3f453de.
Nearly every message is reduced from 'info' to 'debug', some redundant/low-information logs are eliminated, and a new, terse (but actually more informative) standard formatting for messages is introduced and applied to as many log messages as possible.
* Deleted "flow" checkpoints which logged no data (e.g.)
```python3
log.info('currentChanged')
log.info('updateSelection')
```
* Reduced most other messages to `log.debug()`
* Deleted _numerous_ blocks of program-flow debug printfs, like:
```python3
if result == QDialog.Accepted:
log.info('Import image sequence add confirmed')
else:
log.info('Import image sequence add cancelled')
# Or, every time a callback fires...
log.info('actionRedo_trigger')
```
* Many "checkpoint" messages removed or reduced to `log.debug`
* Where possible, checkpoint messages that logged every time
through a loop were replaced with more informative messages
that only log under interesting conditions, letting the
uninteresting loop iterations pass silently
* Remaining useful `log.info()` messages formatted to contain more
information, log more tersely (sometimes combining two or three
consecutive messages into a single, concise form
* Made `keyPressEvent` log messages debug-only
I got a little too ambitious beefing up one of the messages in `properties_model.py`
Every message is reduced to `log.debug()` _except_ the one about
changing the debug mode.
All debug messages are formatted with useful context, so...
```python3
log.info(value)
log.debug('{} set to {}'.format(param["setting"], value))
```
All `qt_log()` messages in the angular code are replaced with `qt_debug()` which only logs in debug mode.
This commit enables something I've been working towards for some time now: The ability to configure OpenShot's console output and logfile output to different logging levels, with potentially _more_ messages being logged to the logfile than are shown on the console. As a result, it brings all of the following: * Log messages of level INFO or higher are written to the console log * By default, initially the same messages are written to the logfile as well * The `debug-mode` preference now affects openshot-qt's own logging, as well as the libopenshot proxy logging. When `debug-mode` is switched on, the `openshot-qt.log` file will receive all messages of level DEBUG or higher. * Log messages proxied from libopenshot are now logged at level DEBUG, instead of INFO, so that they will be written to the log file (only if `debug-mode` is on), but will not be printed to the console output. This opens up the possibility of adding a second ZeroMQ logging channel for messages at a _higher_ severity than debug, which would always be active rather than being gated by the `debug-mode` switch. That priority logging channel could be used for messages which openshot should always log, such as error messages. This would be a possible means of addressing OpenShot#1450.
This reverts commit c0545df.
Closed
|
Forget it. I'm tired of wasting my time contributing to a completely unsupported project. |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
OpenShot outputs a staggering number of unnecessary, redundant, or generic messages to its log while running, especially on startup.
(A log message every time a fallback icon is used; every time an interface binding is created; every time an effect is loaded — that one just says "effects_model:INFO category: Video" every time, so super useless; every time the preview is resized; etc...)
The user doesn't care about any of these, and honestly they're of no help to developers either. They're just the equivalent of debug
printf()s being left in the code. So, this PR aims to wipe them out.Along the way, I'm fixing the type of some other messages (lowering some from log.info() to log.debug(), promoting others from
log.info()tolog.error(), etc.) and updating the formatting of any that use Python %-string formatting to instead use str.format.I've also made the logging asymmetrical between the console output and the logfile, and hooked the
debug-modepreference up to OpenShot's (file-based) logging. So,openshot-qt.logwill get INFO and higher messages normally, but DEBUG-and-higher when the debugging switch is enabled.(Replacement for PR #1772)
IMPORTANT:
* — This is very much WIP for real, please do NOT merge in current state. There are a lot of commits in here I was holding back on my local system, not pushing to my fork / the previous PR, to keep what was in the PR relatively harmless to merge. The changes here are extensive and no longer harmless, and they are not ready to go in yet.