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

Replace logging implementation with spdlog #1093

Merged
merged 79 commits into from
May 7, 2024

Conversation

msimberg
Copy link
Contributor

@msimberg msimberg commented Apr 16, 2024

This replaces the internal (boost logging-based) logging implementation with spdlog (https://github.com/gabime/spdlog). At the same time I've noticeably simplified the logging setup.

Compared to before, there is only one log now which can be used with PIKA_LOG(level, "msg {}", arg). Logging is done to stderr by default. The default log level is warnings and more severe. The default logging output looks like this now (a snippet from hello_world):

[2024-04-16 17:27:38.942414484] [pika] [info] [host:pf3dx1(-1)] [pid:2180336] [tid:2180341] [pool:0000/0003/0003] [parent:----/----] [task:0x7f01ec028b00/----] [runtime.cpp:400/set_state] runtime_state::startup
[2024-04-16 17:27:38.942424521] [pika] [info] [host:pf3dx1(-1)] [pid:2180336] [tid:2180341] [pool:0000/0003/0003] [parent:----/----] [task:0x7f01ec028b00/----] [runtime.cpp:1023/run_helper] (4th stage) run_helper: ran startup functions
[2024-04-16 17:27:38.942433060] [pika] [info] [host:pf3dx1(-1)] [pid:2180336] [tid:2180341] [pool:0000/0003/0003] [parent:----/----] [task:0x7f01ec028b00/----] [runtime.cpp:1026/run_helper] (4th stage) runtime::run_helper: bootstrap complete
[2024-04-16 17:27:38.942440892] [pika] [info] [host:pf3dx1(-1)] [pid:2180336] [tid:2180341] [pool:0000/0003/0003] [parent:----/----] [task:0x7f01ec028b00/----] [runtime.cpp:400/set_state] runtime_state::running
[2024-04-16 17:27:38.942450837] [pika] [info] [host:pf3dx1(-1)] [pid:2180336] [tid:2180341] [pool:0000/0003/0003] [parent:----/----] [task:0x7f01ec028b00/----] [runtime.cpp:1032/run_helper] (last stage) runtime::run_helper: about to invoke pika_main
Hello World!
[2024-04-16 17:27:38.942485701] [pika] [info] [host:pf3dx1(-1)] [pid:2180336] [tid:2180336] [pool:----/0004/----] [parent:----/----] [task:----/----] [runtime.cpp:1189/wait] runtime: about to enter wait state
[2024-04-16 17:27:38.942594025] [pika] [info] [host:pf3dx1(-1)] [pid:2180336] [tid:2180342] [pool:----/----/----] [parent:----/----] [task:----/----] [runtime.cpp:1158/wait_finalize] runtime: about to enter wait state
[2024-04-16 17:27:38.942607966] [pika] [info] [host:pf3dx1(-1)] [pid:2180336] [tid:2180342] [pool:----/----/----] [parent:----/----] [task:----/----] [runtime.cpp:1160/wait_finalize] runtime: exiting wait state
  • The time and pika is always printed first (useful to users who might not know that pika is running under the hood, at least they have something to search for)
  • The log level comes next, and is printed in color (see color: https://github.com/gabime/spdlog/wiki/3.-Custom-formatting#pattern-flags)
  • The hostname is printed along with the MPI rank (if defined), based on
    struct hostname_print_helper
    {
    PIKA_EXPORT char const* get_hostname() const;
    PIKA_EXPORT int guess_rank() const;
    PIKA_EXPORT friend std::ostream& operator<<(
    std::ostream& os, hostname_print_helper const& h);
    };
  • The process and thread id are printed with the formatting provided by spdlog (%P and %t from https://github.com/gabime/spdlog/wiki/3.-Custom-formatting#pattern-flags)
  • The pool and worker thread are printed in the format <pool num>/<global thread num>/<local thread num>. ---- is printed when any of them is not set.
  • The parent and self task ids are printed with the default thread_id formatter.
  • The filename, line number, and function are always printed to add some context.
  • The actual log message is always printed last.

The log format is customizable with PIKA_LOG_FORMAT or --pika:log-format. The pika information (thread ids, hostname, worker thread information) is implemented using custom spdlog formatters.

The log level follows spdlog's log levels, from 0 (trace) to 6 (off) and can be set with PIKA_LOG_LEVEL or --pika:log-level.

The destination can be set with PIKA_LOG_DESTINATION or --pika:log-destination, and defaults to cerr. This can be cerr or cout for stderr and stdout, or a file otherwise.

msimberg added 30 commits March 22, 2024 13:32
Always have logging enabled.
Add command-line options --pika:log-destination, --pika:log-level, and --pika:log-format to
correspond to PIKA_LOGDESTINATION, PIKA_LOGLEVEL, and PIKA_LOGFORMAT. Logging is always enabled, at
level warning.
@msimberg msimberg force-pushed the cleanup-logging branch from 95ebf33 to 65ae122 Compare May 3, 2024 17:09
@pika-bot
Copy link
Collaborator

pika-bot commented May 3, 2024

Performance test report

pika Performance

Comparison

BENCHMARKRESULT
Task Overhead - Create Thread Hierarchical - Latch-

Info

PropertyBeforeAfter
pika Commit0abc0841b8bbb6
pika Datetime2024-02-19T15:15:15+00:002024-05-03T17:09:08+00:00
Envfile
Compiler/apps/daint/SSL/pika/spack/lib/spack/env/clang/clang++ 11.0.1/apps/daint/SSL/pika/spack/lib/spack/env/clang/clang++ 11.0.1
Hostnamenid00025nid00025
Clusternamedaintdaint
Datetime2024-02-19T16:26:16.072067+01:002024-05-03T19:17:05.041455+02:00

Explanation of Symbols

SymbolMEANING
=No performance change (confidence interval within ±1%)
(=)Probably no performance change (confidence interval within ±2%)
(+)/(-)Very small performance improvement/degradation (≤1%)
+/-Small performance improvement/degradation (>10%)
++/--Large performance improvement/degradation (>10%)
+++/---Very large performance improvement/degradation (>10%)
?Probably no change, but quite large uncertainty (confidence interval with ±5%)
??Unclear result, very large uncertainty (±10%)
???Something unexpected…

@msimberg msimberg force-pushed the cleanup-logging branch from 65ae122 to 2185d31 Compare May 3, 2024 18:41
@msimberg msimberg force-pushed the cleanup-logging branch from 2185d31 to 3d96243 Compare May 3, 2024 18:55
@msimberg msimberg added this pull request to the merge queue May 6, 2024
@github-merge-queue github-merge-queue bot removed this pull request from the merge queue due to failed status checks May 6, 2024
@pika-bot
Copy link
Collaborator

pika-bot commented May 6, 2024

Performance test report

pika Performance

Comparison

BENCHMARKRESULT
Task Overhead - Create Thread Hierarchical - Latch-

Info

PropertyBeforeAfter
pika Commit0abc084058ebd8
pika Datetime2024-02-19T15:15:15+00:002024-05-06T11:57:16+00:00
Envfile
Datetime2024-02-19T16:26:16.072067+01:002024-05-06T14:11:42.348357+02:00
Clusternamedaintdaint
Compiler/apps/daint/SSL/pika/spack/lib/spack/env/clang/clang++ 11.0.1/apps/daint/SSL/pika/spack/lib/spack/env/clang/clang++ 11.0.1
Hostnamenid00025nid00025

Explanation of Symbols

SymbolMEANING
=No performance change (confidence interval within ±1%)
(=)Probably no performance change (confidence interval within ±2%)
(+)/(-)Very small performance improvement/degradation (≤1%)
+/-Small performance improvement/degradation (>10%)
++/--Large performance improvement/degradation (>10%)
+++/---Very large performance improvement/degradation (>10%)
?Probably no change, but quite large uncertainty (confidence interval with ±5%)
??Unclear result, very large uncertainty (±10%)
???Something unexpected…

@msimberg msimberg added this pull request to the merge queue May 6, 2024
@msimberg msimberg removed this pull request from the merge queue due to a manual request May 6, 2024
@msimberg msimberg enabled auto-merge May 6, 2024 18:16
@msimberg msimberg disabled auto-merge May 7, 2024 06:46
@msimberg msimberg force-pushed the cleanup-logging branch from 5d54464 to cf1be73 Compare May 7, 2024 06:46
@msimberg msimberg enabled auto-merge May 7, 2024 06:46
@msimberg msimberg added this pull request to the merge queue May 7, 2024
@github-merge-queue github-merge-queue bot removed this pull request from the merge queue due to failed status checks May 7, 2024
@msimberg msimberg enabled auto-merge May 7, 2024 08:57
@msimberg msimberg added this pull request to the merge queue May 7, 2024
Merged via the queue into pika-org:main with commit cc8e3b0 May 7, 2024
36 of 38 checks passed
@msimberg msimberg deleted the cleanup-logging branch May 7, 2024 10:36
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
Status: Archive
Development

Successfully merging this pull request may close these issues.

4 participants