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

Add simple summary profiler hook #1270

Merged
merged 17 commits into from
Feb 22, 2023
Merged

Add simple summary profiler hook #1270

merged 17 commits into from
Feb 22, 2023

Conversation

upsj
Copy link
Member

@upsj upsj commented Feb 6, 2023

This adds a simple summary hook to profilers. It outputs a table of the measured runtimes (inclusive/exclusive for nesting)

I could use an opinion on the following potential extensions:

  • consider adding nesting handling beyond inclusive/exclusive timings
  • consider adding automatic handling for synchronization (GPU devices) or making it configurable from the create function ----- a @note at the function declaration should be enough
  • consider making nesting failures non-fatal
  • consider exposing scope guard to users

Example output from preconditioned-solver (Markdown!)

Summary
Overhead estimate 674.4us

name total total (self) count avg avg (self)
total 11.4ms 5.8ms 1 11.4ms 5.8ms
apply(gko::solver::Cg) 3.5ms 1.6ms 1 3.5ms 1.6ms
generate(gko::solver::Cg::Factory) 1.6ms 58.2us 1 1.6ms 58.2us
generate(gko::preconditioner::Jacobi<double, int>::Factory) 1.5ms 384.5us 1 1.5ms 384.5us
check(gko::stop::Combined) 593.6us 152.6us 8 74.2us 19.1us
sort_by_column_index#1 505.0us 505.0us 1 505.0us 505.0us
generate#9 493.6us 448.4us 1 493.6us 448.4us
check(gko::stop::ResidualNorm) 393.7us 261.4us 8 49.2us 32.7us
apply(gko::matrix::Csr<double, int>) 340.8us 188.5us 7 48.7us 26.9us
apply(gko::preconditioner::Jacobi<double, int>) 332.1us 227.8us 8 41.5us 28.5us
advanced_apply(gko::matrix::Csr<double, int>) 260.8us 198.6us 2 130.4us 99.3us
allocate 240.2us 240.2us 47 5.1us 5.1us
spmv#3 152.3us 152.3us 7 21.8us 21.8us
compute_norm2#3 124.1us 124.1us 10 12.4us 12.4us
aos_to_soa#2 119.3us 119.3us 3 39.8us 39.8us
compute_conj_dot#4 118.1us 118.1us 15 7.9us 7.9us
simple_apply#8 104.3us 104.3us 8 13.0us 13.0us
free 93.7us 93.7us 47 2.0us 2.0us
step_2#7 85.8us 85.8us 7 12.3us 12.3us
step_1#5 84.5us 84.5us 7 12.1us 12.1us
residual_norm#9 74.1us 74.1us 8 9.3us 9.3us
fill#2 71.0us 71.0us 4 17.8us 17.8us
fill_array#3 62.8us 62.8us 2 31.4us 31.4us
advanced_spmv#5 62.2us 62.2us 2 31.1us 31.1us
find_blocks#4 54.1us 54.1us 1 54.1us 54.1us
initialize#8 50.5us 50.5us 1 50.5us 50.5us
check(gko::stop::Iteration) 47.3us 47.3us 8 5.9us 5.9us
fill_in_matrix_data#2 40.3us 40.3us 2 20.2us 20.2us
convert_idxs_to_ptrs#4 28.3us 28.3us 1 28.3us 28.3us
copy 27.9us 27.9us 4 7.0us 7.0us

and with nesting enabled:

Summary
Overhead estimate 820.0 us
|                              name                               |  total   | fraction | count |   avg    |
|-----------------------------------------------------------------|---------:|---------:|------:|---------:|
| total                                                           |   6.8 ms |          |     1 |   6.8 ms |
|   io                                                            |   2.6 ms |   38.5 % |     1 |   2.6 ms |
|     (self)                                                      |   2.4 ms |   93.2 % |     1 |   2.4 ms |
|     aos_to_soa#2                                                |  58.3 us |    2.2 % |     3 |  19.4 us |
|     fill_array#3                                                |  28.6 us |    1.1 % |     1 |  28.6 us |
|     fill_in_matrix_data#2                                       |  25.0 us |    1.0 % |     2 |  12.5 us |
|     allocate                                                    |  24.9 us |    1.0 % |    13 |   1.9 us |
|     fill#2                                                      |  23.2 us |    0.9 % |     2 |  11.6 us |
|     convert_idxs_to_ptrs#4                                      |  11.3 us |    0.4 % |     1 |  11.3 us |
|     free                                                        |   7.2 us |    0.3 % |     8 |   904 ns |
|   apply(gko::solver::Cg<double>)                                |   2.2 ms |   32.0 % |     1 |   2.2 ms |
|     (self)                                                      |   1.1 ms |   49.5 % |     1 |   1.1 ms |
|     check(gko::stop::Combined)                                  | 403.1 us |   18.6 % |     8 |  50.4 us |
|       check(gko::stop::ResidualNorm<double>)                    | 247.2 us |   61.3 % |     8 |  30.9 us |
|         (self)                                                  | 178.6 us |   72.3 % |     8 |  22.3 us |
|         residual_norm#9                                         |  37.1 us |   15.0 % |     8 |   4.6 us |
|         compute_norm2#3                                         |  31.5 us |   12.7 % |     8 |   3.9 us |
|       (self)                                                    | 128.5 us |   31.9 % |     8 |  16.1 us |
|       check(gko::stop::Iteration)                               |  27.3 us |    6.8 % |     8 |   3.4 us |
|     apply(gko::matrix::Csr<double, int>)                        | 202.8 us |    9.4 % |     7 |  29.0 us |
|       (self)                                                    | 119.6 us |   59.0 % |     7 |  17.1 us |
|       spmv#3                                                    |  83.2 us |   41.0 % |     7 |  11.9 us |
|     apply(gko::preconditioner::Jacobi<double, int>)             | 192.8 us |    8.9 % |     8 |  24.1 us |
|       (self)                                                    | 140.2 us |   72.7 % |     8 |  17.5 us |
|       simple_apply#8                                            |  52.6 us |   27.3 % |     8 |   6.6 us |
|     advanced_apply(gko::matrix::Csr<double, int>)               |  85.4 us |    3.9 % |     1 |  85.4 us |
|       (self)                                                    |  67.1 us |   78.6 % |     1 |  67.1 us |
|       advanced_spmv#5                                           |  18.3 us |   21.4 % |     1 |  18.3 us |
|     compute_conj_dot#4                                          |  58.2 us |    2.7 % |    15 |   3.9 us |
|     step_2#7                                                    |  46.8 us |    2.2 % |     7 |   6.7 us |
|     step_1#5                                                    |  43.2 us |    2.0 % |     7 |   6.2 us |
|     compute_norm2#3                                             |  22.7 us |    1.0 % |     1 |  22.7 us |
|     initialize#8                                                |  17.8 us |    0.8 % |     1 |  17.8 us |
|     allocate                                                    |  14.0 us |    0.6 % |    16 |   875 ns |
|     fill#2                                                      |   2.9 us |    0.1 % |     2 |   1.4 us |
|     free                                                        |   2.7 us |    0.1 % |     5 |   539 ns |
|   (self)                                                        | 986.9 us |   14.6 % |     1 | 986.9 us |
|   generate(gko::solver::Cg<double>::Factory)                    | 952.8 us |   14.1 % |     1 | 952.8 us |
|     generate(gko::preconditioner::Jacobi<double, int>::Factory) | 929.6 us |   97.6 % |     1 | 929.6 us |
|       generate#9                                                | 320.0 us |   34.4 % |     1 | 320.0 us |
|         (self)                                                  | 304.6 us |   95.2 % |     1 | 304.6 us |
|         allocate                                                |  11.3 us |    3.5 % |     9 |   1.3 us |
|         free                                                    |   4.2 us |    1.3 % |     9 |   464 ns |
|       sort_by_column_index#1                                    | 305.7 us |   32.9 % |     1 | 305.7 us |
|       (self)                                                    | 255.2 us |   27.5 % |     1 | 255.2 us |
|       find_blocks#4                                             |  33.1 us |    3.6 % |     1 |  33.1 us |
|       allocate                                                  |   6.3 us |    0.7 % |     6 |   1.1 us |
|       copy                                                      |   5.5 us |    0.6 % |     4 |   1.4 us |
|       free                                                      |   1.9 us |    0.2 % |     4 |   483 ns |
|       fill_array#3                                              |   1.8 us |    0.2 % |     1 |   1.8 us |
|     (self)                                                      |  23.2 us |    2.4 % |     1 |  23.2 us |
|   advanced_apply(gko::matrix::Csr<double, int>)                 |  38.1 us |    0.6 % |     1 |  38.1 us |
|     (self)                                                      |  25.5 us |   66.9 % |     1 |  25.5 us |
|     advanced_spmv#5                                             |  12.6 us |   33.1 % |     1 |  12.6 us |
|   free                                                          |  10.3 us |    0.2 % |    21 |   492 ns |
|   compute_norm2#3                                               |   4.3 us |    0.1 % |     1 |   4.3 us |
|   allocate                                                      |   3.3 us |    0.0 % |     3 |   1.1 us |

@upsj upsj added the 1:ST:need-feedback The PR is somewhat ready but feedback on a blocking topic is required before a proper review. label Feb 6, 2023
@upsj upsj self-assigned this Feb 6, 2023
@ginkgo-bot ginkgo-bot added reg:build This is related to the build system. mod:core This is related to the core module. labels Feb 6, 2023
@upsj upsj force-pushed the profiler_summary branch from 817103a to 1f442a8 Compare February 8, 2023 09:47
@upsj upsj added 1:ST:ready-for-review This PR is ready for review and removed 1:ST:need-feedback The PR is somewhat ready but feedback on a blocking topic is required before a proper review. labels Feb 8, 2023
@upsj upsj requested a review from a team February 8, 2023 09:47
@MarcelKoch
Copy link
Member

We already have the OperationLogger for our benchmarks. Does it make sense to converge these two? Besides, perhaps it makes sense to add json output as an option, and perhaps prefer (or only offer) that in the nested case.

@upsj
Copy link
Member Author

upsj commented Feb 10, 2023

@MarcelKoch good idea! Since this implementation deals with nesting more cleanly, I would suggest using it instead of OperationLogger, and provide some custom output handling to be used in the benchmark output. I would like to avoid having RapidJSON as a dependency for Ginkgo (as long as possible), so that would probably be a way to decouple things.

@upsj
Copy link
Member Author

upsj commented Feb 10, 2023

format-rebase!

@ginkgo-bot
Copy link
Member

Formatting rebase introduced changes, see Artifacts here to review them

@upsj
Copy link
Member Author

upsj commented Feb 10, 2023

@MarcelKoch I integrated your suggestion, it might make sense for this case to actually disable event forwarding any only capture the executor events, but that is up for discussion :)

@codecov
Copy link

codecov bot commented Feb 11, 2023

Codecov Report

Base: 91.24% // Head: 90.79% // Decreases project coverage by -0.46% ⚠️

Coverage data is based on head (2fc1b44) compared to base (e0ce4a9).
Patch coverage: 63.78% of modified lines in pull request are covered.

❗ Current head 2fc1b44 differs from pull request most recent head d4c7f72. Consider uploading reports for the commit d4c7f72 to get more accurate results

Additional details and impacted files
@@             Coverage Diff             @@
##           develop    #1270      +/-   ##
===========================================
- Coverage    91.24%   90.79%   -0.46%     
===========================================
  Files          565      563       -2     
  Lines        48026    48119      +93     
===========================================
- Hits         43822    43688     -134     
- Misses        4204     4431     +227     
Impacted Files Coverage Δ
core/log/profiler_hook_summary_writer.cpp 0.00% <0.00%> (ø)
core/log/profiler_hook.cpp 71.03% <56.25%> (-1.84%) ⬇️
core/log/profiler_hook_summary.cpp 90.11% <90.11%> (ø)
core/test/log/profiler_hook.cpp 94.17% <100.00%> (+1.96%) ⬆️
include/ginkgo/core/log/profiler_hook.hpp 100.00% <100.00%> (ø)
core/solver/cb_gmres.cpp 25.97% <0.00%> (-70.53%) ⬇️
common/unified/preconditioner/jacobi_kernels.cpp 45.00% <0.00%> (-16.54%) ⬇️
omp/reorder/rcm_kernels.cpp 94.44% <0.00%> (-3.09%) ⬇️
include/ginkgo/core/base/executor.hpp 72.55% <0.00%> (-2.09%) ⬇️
core/stop/residual_norm.cpp 96.42% <0.00%> (-1.22%) ⬇️
... and 15 more

Help us with your feedback. Take ten seconds to tell us how you rate us. Have a feature suggestion? Share it here.

☔ View full report at Codecov.
📢 Do you have feedback about the report comment? Let us know in this issue.

@MarcelKoch
Copy link
Member

Side note: I think it would be nice if the #N could be explained somewhere. If that can be explained in one sentence, then I think it would be fine to just also print that. Otherwise, It would probably better fit into the documentation.
BTW, I myself don't know what the #N mean...

Copy link
Collaborator

@fritzgoebel fritzgoebel left a comment

Choose a reason for hiding this comment

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

LGTM, only a few questions

Copy link
Member

@yhmtsai yhmtsai left a comment

Choose a reason for hiding this comment

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

LGTM.
Could we move some structure introduced in profiler_hook to the private header?

stream << "|\n";
for (int i = 0; i < widths.size(); i++) {
stream << '|';
// right-align for Markdown, assuming widths[i] > 0
Copy link
Member

Choose a reason for hiding this comment

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

Is the comment for next one?

Copy link
Member Author

Choose a reason for hiding this comment

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

yes, we need to add a : to the side we want to align the text with

* bar()
* bar()
* baz(
* bazz()
Copy link
Member

Choose a reason for hiding this comment

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

if bazz also uses bazzzz, will them be collected as one entry?

Copy link
Member Author

Choose a reason for hiding this comment

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

exactly, this one doesn't care about nesting

*/
static std::shared_ptr<ProfilerHook> create_nested_summary(
std::unique_ptr<nested_summary_writer> writer =
std::make_unique<table_summary_writer>(),
Copy link
Member

Choose a reason for hiding this comment

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

make_unique needs a complete class not forward declaration here?

Copy link
Member Author

Choose a reason for hiding this comment

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

yes, otherwise we can't specify the default parameter, since it needs to be visible at the call site

@upsj upsj added 1:ST:ready-to-merge This PR is ready to merge. and removed 1:ST:ready-for-review This PR is ready for review labels Feb 21, 2023
upsj and others added 13 commits February 22, 2023 20:39
Adds a link to the wiki to the output
* use CamelCase for polymorphic types
* improve documentation
* Follow AAA for tests
* output `(self)` entry in nested summary
* use ptr_param for set_object_name(...)
* replace fmt by format

Co-authored-by: Yuhsiang M. Tsai <yhmtsai@gmail.com>
Co-authored-by: Fritz Göbel <fritz.goebel@kit.edu>
newlines in raw string literals inside macro arguments get replaced by `\n`
@ginkgo-bot
Copy link
Member

Note: This PR changes the Ginkgo ABI:

Functions changes summary: 20 Removed, 4 Changed (26 filtered out), 841 Added functions
Variables changes summary: 0 Removed, 0 Changed, 0 Added variable

For details check the full ABI diff under Artifacts here

@upsj upsj merged commit 39a4392 into develop Feb 22, 2023
@upsj upsj deleted the profiler_summary branch February 22, 2023 23:01
@sonarqubecloud
Copy link

Kudos, SonarCloud Quality Gate passed!    Quality Gate passed

Bug A 0 Bugs
Vulnerability A 0 Vulnerabilities
Security Hotspot A 0 Security Hotspots
Code Smell A 37 Code Smells

85.0% 85.0% Coverage
0.0% 0.0% Duplication

tcojean added a commit that referenced this pull request Jun 16, 2023
Release 1.6.0 of Ginkgo.

The Ginkgo team is proud to announce the new Ginkgo minor release 1.6.0. This release brings new features such as:
- Several building blocks for GPU-resident sparse direct solvers like symbolic
  and numerical LU and Cholesky factorization, ...,
- A distributed Schwarz preconditioner,
- New FGMRES and GCR solvers,
- Distributed benchmarks for the SpMV operation, solvers, ...
- Support for non-default streams in the CUDA and HIP backends,
- Mixed precision support for the CSR SpMV,
- A new profiling logger which integrates with NVTX, ROCTX, TAU and VTune to
  provide internal Ginkgo knowledge to most HPC profilers!

and much more.

If you face an issue, please first check our [known issues page](https://github.com/ginkgo-project/ginkgo/wiki/Known-Issues) and the [open issues list](https://github.com/ginkgo-project/ginkgo/issues) and if you do not find a solution, feel free to [open a new issue](https://github.com/ginkgo-project/ginkgo/issues/new/choose) or ask a question using the [github discussions](https://github.com/ginkgo-project/ginkgo/discussions).

Supported systems and requirements:
+ For all platforms, CMake 3.13+
+ C++14 compliant compiler
+ Linux and macOS
  + GCC: 5.5+
  + clang: 3.9+
  + Intel compiler: 2018+
  + Apple Clang: 14.0 is tested. Earlier versions might also work.
  + NVHPC: 22.7+
  + Cray Compiler: 14.0.1+
  + CUDA module: CUDA 9.2+ or NVHPC 22.7+
  + HIP module: ROCm 4.5+
  + DPC++ module: Intel OneAPI 2021.3+ with oneMKL and oneDPL. Set the CXX compiler to `dpcpp`.
+ Windows
  + MinGW: GCC 5.5+
  + Microsoft Visual Studio: VS 2019+
  + CUDA module: CUDA 9.2+, Microsoft Visual Studio
  + OpenMP module: MinGW.

### Version Support Changes
+ ROCm 4.0+ -> 4.5+ after [#1303](#1303)
+ Removed Cygwin pipeline and support [#1283](#1283)

### Interface Changes
+ Due to internal changes, `ConcreteExecutor::run` will now always throw if the corresponding module for the `ConcreteExecutor` is not build [#1234](#1234)
+ The constructor of `experimental::distributed::Vector` was changed to only accept local vectors as `std::unique_ptr` [#1284](#1284)
+ The default parameters for the `solver::MultiGrid` were improved. In particular, the smoother defaults to one iteration of `Ir` with `Jacobi` preconditioner, and the coarse grid solver uses the new direct solver with LU factorization. [#1291](#1291) [#1327](#1327)
+ The `iteration_complete` event gained a more expressive overload with additional parameters, the old overloads were deprecated. [#1288](#1288) [#1327](#1327)

### Deprecations
+ Deprecated less expressive `iteration_complete` event. Users are advised to now implement the function `void iteration_complete(const LinOp* solver, const LinOp* b, const LinOp* x, const size_type& it, const LinOp* r, const LinOp* tau, const LinOp* implicit_tau_sq, const array<stopping_status>* status, bool stopped)` [#1288](#1288)

### Added Features
+ A distributed Schwarz preconditioner. [#1248](#1248)
+ A GCR solver [#1239](#1239)
+ Flexible Gmres solver [#1244](#1244)
+ Enable Gmres solver for distributed matrices and vectors [#1201](#1201)
+ An example that uses Kokkos to assemble the system matrix [#1216](#1216)
+ A symbolic LU factorization allowing the `gko::experimental::factorization::Lu` and `gko::experimental::solver::Direct` classes to be used for matrices with non-symmetric sparsity pattern [#1210](#1210)
+ A numerical Cholesky factorization [#1215](#1215)
+ Symbolic factorizations in host-side operations are now wrapped in a host-side `Operation` to make their execution visible to loggers. This means that profiling loggers and benchmarks are no longer missing a separate entry for their runtime [#1232](#1232)
+ Symbolic factorization benchmark [#1302](#1302)
+ The `ProfilerHook` logger allows annotating the Ginkgo execution (apply, operations, ...) for profiling frameworks like NVTX, ROCTX and TAU. [#1055](#1055)
+ `ProfilerHook::created_(nested_)summary` allows the generation of a lightweight runtime profile over all Ginkgo functions written to a user-defined stream [#1270](#1270) for both host and device timing functionality [#1313](#1313)
+ It is now possible to enable host buffers for MPI communications at runtime even if the compile option `GINKGO_FORCE_GPU_AWARE_MPI` is set. [#1228](#1228)
+ A stencil matrices generator (5-pt, 7-pt, 9-pt, and 27-pt) for benchmarks [#1204](#1204)
+ Distributed benchmarks (multi-vector blas, SpMV, solver) [#1204](#1204)
+ Benchmarks for CSR sorting and lookup [#1219](#1219)
+ A timer for MPI benchmarks that reports the longest time [#1217](#1217)
+ A `timer_method=min|max|average|median` flag for benchmark timing summary [#1294](#1294)
+ Support for non-default streams in CUDA and HIP executors [#1236](#1236)
+ METIS integration for nested dissection reordering [#1296](#1296)
+ SuiteSparse AMD integration for fillin-reducing reordering [#1328](#1328)
+ Csr mixed-precision SpMV support [#1319](#1319)
+ A `with_loggers` function for all `Factory` parameters [#1337](#1337)

### Improvements
+ Improve naming of kernel operations for loggers [#1277](#1277)
+ Annotate solver iterations in `ProfilerHook` [#1290](#1290)
+ Allow using the profiler hooks and inline input strings in benchmarks [#1342](#1342)
+ Allow passing smart pointers in place of raw pointers to most matrix functions. This means that things like `vec->compute_norm2(x.get())` or `vec->compute_norm2(lend(x))` can be simplified to `vec->compute_norm2(x)` [#1279](#1279) [#1261](#1261)
+ Catch overflows in prefix sum operations, which makes Ginkgo's operations much less likely to crash. This also improves the performance of the prefix sum kernel [#1303](#1303)
+ Make the installed GinkgoConfig.cmake file relocatable and follow more best practices [#1325](#1325)

### Fixes
+ Fix OpenMPI version check [#1200](#1200)
+ Fix the mpi cxx type binding by c binding [#1306](#1306)
+ Fix runtime failures for one-sided MPI wrapper functions observed on some OpenMPI versions [#1249](#1249)
+ Disable thread pinning with GPU executors due to poor performance [#1230](#1230)
+ Fix hwloc version detection [#1266](#1266)
+ Fix PAPI detection in non-implicit include directories [#1268](#1268)
+ Fix PAPI support for newer PAPI versions: [#1321](#1321)
+ Fix pkg-config file generation for library paths outside prefix [#1271](#1271)
+ Fix various build failures with ROCm 5.4, CUDA 12, and OneAPI 6 [#1214](#1214), [#1235](#1235), [#1251](#1251)
+ Fix incorrect read for skew-symmetric MatrixMarket files with explicit diagonal entries [#1272](#1272)
+ Fix handling of missing diagonal entries in symbolic factorizations [#1263](#1263)
+ Fix segmentation fault in benchmark matrix construction [#1299](#1299)
+ Fix the stencil matrix creation for benchmarking [#1305](#1305)
+ Fix the additional residual check in IR [#1307](#1307)
+ Fix the cuSPARSE CSR SpMM issue on single strided vector when cuda >= 11.6 [#1322](#1322) [#1331](#1331)
+ Fix Isai generation for large sparsity powers [#1327](#1327)
+ Fix Ginkgo compilation and test with NVHPC >= 22.7 [#1331](#1331)
+ Fix Ginkgo compilation of 32 bit binaries with MSVC [#1349](#1349)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
1:ST:ready-to-merge This PR is ready to merge. 1:ST:run-full-test mod:core This is related to the core module. reg:build This is related to the build system.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants