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

Overhaul logging mechanism #80

Merged
merged 4 commits into from
Feb 21, 2022
Merged

Overhaul logging mechanism #80

merged 4 commits into from
Feb 21, 2022

Conversation

psalz
Copy link
Member

@psalz psalz commented Jan 24, 2022

This changes the logging mechanism used throughout the runtime from having to pass around the detail::logger class to simple free-standing macros such as CELERITY_INFO(...). While the new mechanism no longer allows for arbitrarily nested "contexts", a single context can be set through CELERITY_SET_LOG_CTX (currently only used in worker jobs).

Full list of changes:

  • Get rid of JSON output for trace log level
  • Remove logger class, use macros instead
  • Only a single level of context supported
  • Adjust log level for many messages, distinguish between debug/trace
  • Add additional information in various logging messages
  • Default log level to info (release builds) and debug (debug builds)

Copy link
Contributor

@fknorr fknorr left a comment

Choose a reason for hiding this comment

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

Thank you, human readable logs are a very welcome change! A few things:

include/command_graph.h Outdated Show resolved Hide resolved
include/log.h Outdated Show resolved Hide resolved
include/log.h Outdated Show resolved Hide resolved
include/log.h Show resolved Hide resolved
include/log.h Outdated Show resolved Hide resolved
src/print_graph.cc Show resolved Hide resolved
src/command_graph.cc Outdated Show resolved Hide resolved
include/log.h Outdated Show resolved Hide resolved
include/log.h Outdated Show resolved Hide resolved
Copy link
Contributor

@fknorr fknorr left a comment

Choose a reason for hiding this comment

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

Thanks! A few more things, mostly about includes. I would prefer if we kept iostreams out of as many translation units as possible because it tends to be quite expensive to compile.

include/command_graph.h Outdated Show resolved Hide resolved
include/log.h Outdated Show resolved Hide resolved
include/task_manager.h Outdated Show resolved Hide resolved
src/print_graph.cc Show resolved Hide resolved
include/log.h Outdated Show resolved Hide resolved
test/unit_test_suite_celerity.cc Outdated Show resolved Hide resolved
@psalz
Copy link
Member Author

psalz commented Feb 9, 2022

I've addressed the additional feedback by @fknorr and in that process also made some improvements to the user_bench utilities, along with some breaking changes (the whole thing is experimental and we don't use it in any of the examples currently, so I think it should be fine).

As mentioned in the comment above, I've mainly gotten rid of the log_map type as an alias for std::unordered_map, both to address limitations in the types that can be used, as well as to avoid the unnecessary overhead of creating a whole hash map only for it to be immediately turned into a string. Note that the log_map type still exists, but only as a helper to specialize fmt::formatter. While I could've moved the formatting of the std::tuple directly into the constructor of log_context, I didn't want to repeatedly call fmt::format and then concatenate everything into a stringstream because that seemed wasteful.

Copy link
Contributor

@fknorr fknorr left a comment

Choose a reason for hiding this comment

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

Thank you! After some digging, the tie-in between fmt and iostreams in our code, aka <fmt/ostr.h> has two origins:

  • print_utils.h and .cpp expose ostream& operator<< for the subrange and chunk types, which are internally implemented using fmt, so we are going back and forth between fmt and stringstreams.
  • The Allscale headers define ostream& operator<< on the GridBox type. Its only use is in region_map_testspy::print_regions, and that is currently dead code as the only (transitive) invocation is commented out in graph_compaction_tests:142.

However, the major offender now is the Allscale assertions header which pulls in <iostreams> unconditionally. I feel like this is beyond the scope of this PR now, so I'll cease my iostreams crusade.

This changes the logging mechanism used throughout the runtime from
having to pass around the `detail::logger` class to simple free-standing
macros such as `CELERITY_INFO(...)`. While the new mechanism no longer
allows for arbitrarily nested "contexts", a single context can be set
through `CELERITY_SET_LOG_CTX` (currently only used in worker jobs).

Full list of changes:
- Get rid of JSON output for trace log level
- Remove logger class, use macros instead
- Only a single level of context supported
- Adjust log level for many messages, distinguish between debug/trace
- Add additional information in various logging messages
- Default log level to info (release builds) and debug (debug builds)
...to control how large task/command graphs can be before their GraphViz
output is omitted.
Replaces `log_map` (which was an `std::unordered_map`) with `std::tuple`
to have less runtime overhead and allow for arbitrary types to be logged.

Changes to `user_bench` utilities:
  - Logging through `log_map` is no longer supported.
  - Replace `log_user_config` by `log_once` function to log messages
    only on master node.
  - Print delta time since previous event.
  - Ensure thread safety for all functions.
@psalz psalz merged commit e068a2d into master Feb 21, 2022
@psalz psalz deleted the overhaul-logging branch February 21, 2022 16:21
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