Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Logging clean up #3518

Merged
merged 3 commits into from
Jan 6, 2021
Merged

Logging clean up #3518

merged 3 commits into from
Jan 6, 2021

Conversation

daschuer
Copy link
Member

@daschuer daschuer commented Jan 4, 2021

this removes the confusing
debug unknown
entries
and a redundant check.

Copy link
Contributor

@uklotzde uklotzde left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The %{function} placeholder works well for me:

debug mixxx::Logger::debug [aoide] mixxx::network::WebTask - aoide::ListCollectionsTask(0xce066a0) Received reply for request QUrl("http://[::1]:37719/c")
debug WTrackTableView::loadTrackModel [Main] WTrackTableView::loadTrackModel() LibraryTableModel(0x3f62220)
debug BaseSqlTableModel::select [Main] LibraryTableModel(0x3f62220) select() took 0 ms 45
debug WLibrary::switchToView [Main] trying to restore position
debug GLSLWaveformWidget::GLSLWaveformWidget [Main] Created QGLWidget. Context Valid: true Sharing: true

This will become even more useful once we drop our custom logging wrapper in favor of logging categories.

@Holzhaus
Copy link
Member

Holzhaus commented Jan 4, 2021

Probably only works for debug builds.

@uklotzde
Copy link
Contributor

uklotzde commented Jan 4, 2021

Probably only works for debug builds.

Probably. Then we need conditional compilation depending on if debug symbols are available or not.

@daschuer
Copy link
Member Author

daschuer commented Jan 4, 2021

This will become even more useful once we drop our custom logging wrapper in favor of logging categories

If this only works for some conditions, we unfortunately can't rely on this. We need to keep this in mind for future considerations.

Can we remove the function part for all?
If it contains relevant information, we have to put it to the message part to have it always available.
Than the extra entry is only clutter.

I cannot remember that I have missed that info, and in hard cases it can be made visible by the environment variable.

This will speed up the normal case and produces shorter and better readable debug messages.

@uklotzde
Copy link
Contributor

uklotzde commented Jan 4, 2021

This will become even more useful once we drop our custom logging wrapper in favor of logging categories

If this only works for some conditions, we unfortunately can't rely on this. We need to keep this in mind for future considerations.

Can we remove the function part for all?
If it contains relevant information, we have to put it to the message part to have it always available.
Than the extra entry is only clutter.

I cannot remember that I have missed that info, and in hard cases it can be made visible by the environment variable.

This will speed up the normal case and produces shorter and better readable debug messages.

Please enclose in an ifdef. This is valuable information as the example I published demonstrates. Otherwise you loose the context.

debug WLibrary::switchToView [Main] trying to restore position vs. debug [Main] trying to restore position

@Holzhaus
Copy link
Member

Holzhaus commented Jan 4, 2021

If we keep the function, can we put if after the thread name? I find it much harder to read at the moment.

@daschuer
Copy link
Member Author

daschuer commented Jan 4, 2021

debug WLibrary::switchToView [Main] trying to restore position vs. debug [Main] trying to restore position

On one hand you are right, but the issue is that currently the info is only sometimes available. The author of the message needs to make sure that it is understandable without the function name.

Practically it is not much of a difference to find in files for "WLibrary::switchToView" or for "trying to restore position vs. debug".

The other question rises, why only for qDebug().

I have just checked how it is implemented. Qt uses the compiler generated function name PRETTY_FUNCTION which has no runtime overhead. It is controlled via a QT_MESSAGELOGCONTEXT flag.

So if we need to rely on this feature, we have the option to have it always enabled.

For now I like to disable it, to not have an inconsistent state and merge this PR as it is. Waiting for a consistent solution.

In general I am in the opinion to not clutter the output by default with function names using the self explaining messages.
We have always the option to enable it as long the function names are compiled in (QT_MESSAGELOGCONTEXT)

What do you think?

@uklotzde
Copy link
Contributor

uklotzde commented Jan 4, 2021

We still have lots of legacy log messages where the class name is explicitly logged as part of the log message, which causes lots of inconsistencies. Instead this context should be provided implicitly and added to the log message.

Without context many log messages are not self-contained. I don't want to lookup each and every log message in the IDE for the context when reading a log file. This is not feasible.

Please also note that we still misuse the debug log level as info. I agree that info/warn/error log messages should be comprehensible without access to the source code.

@daschuer
Copy link
Member Author

daschuer commented Jan 4, 2021

Yes, that would work for me. So we have these todos:

  • decide which log level should print function names
  • find out how to enable the feature it independent from build type
  • remove all manual added function names.

Unfortunately I have no interest to do this within this PR. Can we merge this to go back to the old somehow consistent state and than do the transition in another PR once one finds time.

@uklotzde
Copy link
Contributor

uklotzde commented Jan 4, 2021

Could we keep the removed template pattern in a TODO comment? As a blueprint for re-adding it later. In this case it makes sense to preserve deleted code snippets to avoid reinventing the wheel later.

@Holzhaus
Copy link
Member

Holzhaus commented Jan 4, 2021

We still have it in the git history.

@uklotzde
Copy link
Contributor

uklotzde commented Jan 4, 2021

We still have it in the git history.

We need a TODO comment that mentions the extension anyway. Including that part of the template pattern for clarification and illustration would help to rediscover it.

@poelzi
Copy link
Contributor

poelzi commented Jan 4, 2021

If you remove the {function} pattern, then please don't set if QT_MESSAGE_PATTERN env is set. This way, the user can still use a custom pattern that includes it.

@daschuer
Copy link
Member Author

daschuer commented Jan 5, 2021

In general, comments are better than none, so I will summerize the state of discussion.

If you remove the {function} pattern, then please don't set if QT_MESSAGE_PATTERN env is set.

Yes right. This behaviour does not change here. Qt takes care of it. No need to replicate the logic in Mixxx.

@daschuer
Copy link
Member Author

daschuer commented Jan 5, 2021

There is an unrelated issue with libkeyfinder

-- verifying file...
       file='/home/runner/work/mixxx/mixxx/build/download/libKeyFinder/v2.2.3.zip'
-- SHA256 hash of
    /home/runner/work/mixxx/mixxx/build/download/libKeyFinder/v2.2.3.zip
  does not match expected value
    expected: '56887e7b51834223d4264f4ea9acf16f0b6a0c706c218478afbaf89ad1f9c6ea'
      actual: 'ad43ca006e3bbed0810ff62e170d04522a64f8606c2166bfa5a9b9158b7ebc11'
-- Hash mismatch, removing...
CMake Error at libKeyFinder-stamp/download-libKeyFinder.cmake:159 (message):
  Each download failed!

Copy link
Contributor

@uklotzde uklotzde left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

@uklotzde uklotzde merged commit 02a2213 into mixxxdj:main Jan 6, 2021
daschuer added a commit to daschuer/mixxx that referenced this pull request Aug 16, 2021
daschuer added a commit to daschuer/mixxx that referenced this pull request Aug 16, 2021
@daschuer daschuer deleted the logging branch September 26, 2021 17:38
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants