Skip to content

Clean up timer outputs #819

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

Open
wants to merge 2 commits into
base: main
Choose a base branch
from

Conversation

efaulhaber
Copy link
Member

@efaulhaber efaulhaber commented May 28, 2025

  1. The shifting callback was calling update_systems_and_nhs! outside an @timeit, which caused orphaned update timers like update density diffusion on the top level.
  2. For save solution, interpolation and shifting, the system/nhs update is usually negligible (and if not, the percentages should still be the same as in kick!), so there is no point in having all the sub-timers. Especially with Split fluid and TLSPH time integration to allow for TLSPH substeps #794, the timer output otherwise becomes very cluttered when multiple callbacks are used.

Before:

──────────────────────────────────────────────────────────────────────────────────────────
           TrixiParticles.jl                     Time                    Allocations      
                                        ───────────────────────   ────────────────────────
           Tot / % measured:                 5.84s /  89.6%           85.6MiB /  76.8%    

Section                         ncalls     time    %tot     avg     alloc    %tot      avg
──────────────────────────────────────────────────────────────────────────────────────────
kick!                              212    4.58s   87.5%  21.6ms   2.03MiB    3.1%  9.81KiB
  update systems and nhs           212    2.73s   52.2%  12.9ms   1.14MiB    1.7%  5.52KiB
    update density diffusion       212    2.61s   50.0%  12.3ms    262KiB    0.4%  1.23KiB
    update nhs                     212   69.0ms    1.3%   325μs    398KiB    0.6%  1.88KiB
    compute boundary pressure      424   34.3ms    0.7%  80.8μs    341KiB    0.5%     824B
    ~update systems and nhs~       212   10.7ms    0.2%  50.3μs   44.6KiB    0.1%     215B
    inverse state equation         424   3.63ms    0.1%  8.56μs    126KiB    0.2%     304B
  system interaction               212    1.84s   35.2%  8.69ms    851KiB    1.3%  4.01KiB
    fluid1-fluid1                  212    1.57s   30.1%  7.42ms    129KiB    0.2%     624B
    fluid1-boundary2               212    160ms    3.1%   755μs    129KiB    0.2%     624B
    fluid1-boundary3               212    106ms    2.0%   501μs    129KiB    0.2%     624B
    ~system interaction~           212   2.15ms    0.0%  10.1μs    463KiB    0.7%  2.19KiB
    boundary3-boundary2            212   3.46μs    0.0%  16.3ns     0.00B    0.0%    0.00B
    boundary2-fluid1               212   2.87μs    0.0%  13.5ns     0.00B    0.0%    0.00B
    boundary3-boundary3            212   2.71μs    0.0%  12.8ns     0.00B    0.0%    0.00B
    boundary2-boundary2            212   2.63μs    0.0%  12.4ns     0.00B    0.0%    0.00B
    boundary3-fluid1               212   2.58μs    0.0%  12.1ns     0.00B    0.0%    0.00B
    boundary2-boundary3            212   2.29μs    0.0%  10.8ns     0.00B    0.0%    0.00B
  reset ∂v/∂t                      212   3.33ms    0.1%  15.7μs   6.62KiB    0.0%    32.0B
  source terms                     212   2.24ms    0.0%  10.5μs   49.7KiB    0.1%     240B
  ~kick!~                          212    137μs    0.0%   645ns   1.55KiB    0.0%    7.47B
update density diffusion            20    250ms    4.8%  12.5ms   24.7KiB    0.0%  1.23KiB
particle shifting                   20    160ms    3.1%  7.99ms   38.4KiB    0.1%  1.92KiB
save solution                        1    132ms    2.5%   132ms   39.0MiB   59.4%  39.0MiB
  write to vtk                       3   76.5ms    1.5%  25.5ms   33.0MiB   50.3%  11.0MiB
  ~save solution~                    1   42.0ms    0.8%  42.0ms   5.97MiB    9.1%  5.97MiB
  update systems                     1   13.4ms    0.3%  13.4ms   7.06KiB    0.0%  7.06KiB
    update density diffusion         1   12.5ms    0.2%  12.5ms   1.23KiB    0.0%  1.23KiB
    update nhs                       1    395μs    0.0%   395μs   1.88KiB    0.0%  1.88KiB
    compute boundary pressure        2    280μs    0.0%   140μs   1.61KiB    0.0%     824B
    ~update systems~                 1    157μs    0.0%   157μs   1.75KiB    0.0%  1.75KiB
    inverse state equation           2   52.0μs    0.0%  26.0μs      608B    0.0%     304B
apply postprocess cb                 1   95.1ms    1.8%  95.1ms   24.5MiB   37.2%  24.5MiB
  interpolate plane                  1   55.2ms    1.1%  55.2ms   23.4MiB   35.6%  23.4MiB
  write to vtk                       1   28.0ms    0.5%  28.0ms   1.08MiB    1.6%  1.08MiB
  update systems                     1   11.9ms    0.2%  11.9ms   7.06KiB    0.0%  7.06KiB
    update density diffusion         1   11.3ms    0.2%  11.3ms   1.23KiB    0.0%  1.23KiB
    update nhs                       1    358μs    0.0%   358μs   1.88KiB    0.0%  1.88KiB
    compute boundary pressure        2    155μs    0.0%  77.3μs   1.61KiB    0.0%     824B
    ~update systems~                 1   39.2μs    0.0%  39.2μs   1.75KiB    0.0%  1.75KiB
    inverse state equation           2   11.5μs    0.0%  5.77μs      608B    0.0%     304B
  ~apply postprocess cb~             1   56.1μs    0.0%  56.1μs   5.68KiB    0.0%  5.68KiB
update nhs                          20   5.42ms    0.1%   271μs   37.5KiB    0.1%  1.88KiB
drift!                             212   4.88ms    0.1%  23.0μs   54.0KiB    0.1%     261B
  reset ∂u/∂t                      212   3.15ms    0.1%  14.9μs   6.62KiB    0.0%    32.0B
  velocity                         212   1.68ms    0.0%  7.91μs   46.4KiB    0.1%     224B
  ~drift!~                         212   53.9μs    0.0%   254ns      976B    0.0%    4.60B
compute boundary pressure           40   3.58ms    0.1%  89.6μs   32.2KiB    0.0%     824B
inverse state equation              40    548μs    0.0%  13.7μs   11.9KiB    0.0%     304B
──────────────────────────────────────────────────────────────────────────────────────────

This PR:

───────────────────────────────────────────────────────────────────────────────────────────
            TrixiParticles.jl                     Time                    Allocations      
                                         ───────────────────────   ────────────────────────
            Tot / % measured:                 8.88s /  73.1%            129MiB /  59.9%    

Section                          ncalls     time    %tot     avg     alloc    %tot      avg
───────────────────────────────────────────────────────────────────────────────────────────
kick!                               212    4.80s   73.9%  22.6ms   2.03MiB    2.6%  9.81KiB
  update systems and nhs            212    2.90s   44.6%  13.7ms   1.14MiB    1.5%  5.52KiB
    update density diffusion        212    2.75s   42.3%  13.0ms    262KiB    0.3%  1.23KiB
    update nhs                      212   83.3ms    1.3%   393μs    398KiB    0.5%  1.88KiB
    compute boundary pressure       424   45.5ms    0.7%   107μs    341KiB    0.4%     824B
    ~update systems and nhs~        212   14.1ms    0.2%  66.6μs   44.6KiB    0.1%     215B
    inverse state equation          424   4.06ms    0.1%  9.57μs    126KiB    0.2%     304B
  system interaction                212    1.89s   29.1%  8.92ms    851KiB    1.1%  4.01KiB
    fluid1-fluid1                   212    1.61s   24.8%  7.61ms    129KiB    0.2%     624B
    fluid1-boundary2                212    165ms    2.5%   778μs    129KiB    0.2%     624B
    fluid1-boundary3                212    111ms    1.7%   524μs    129KiB    0.2%     624B
    ~system interaction~            212   3.47ms    0.1%  16.4μs    463KiB    0.6%  2.19KiB
    boundary2-fluid1                212   5.79μs    0.0%  27.3ns     0.00B    0.0%    0.00B
    boundary2-boundary2             212   5.21μs    0.0%  24.6ns     0.00B    0.0%    0.00B
    boundary3-boundary2             212   4.00μs    0.0%  18.9ns     0.00B    0.0%    0.00B
    boundary3-boundary3             212   3.79μs    0.0%  17.9ns     0.00B    0.0%    0.00B
    boundary2-boundary3             212   3.05μs    0.0%  14.4ns     0.00B    0.0%    0.00B
    boundary3-fluid1                212   2.83μs    0.0%  13.4ns     0.00B    0.0%    0.00B
  reset ∂v/∂t                       212   7.70ms    0.1%  36.3μs   6.62KiB    0.0%    32.0B
  source terms                      212   2.05ms    0.0%  9.68μs   49.7KiB    0.1%     240B
  ~kick!~                           212    165μs    0.0%   777ns   1.55KiB    0.0%    7.47B
save solution                         1    973ms   15.0%   973ms   48.6MiB   63.0%  48.6MiB
  ~save solution~                     1    811ms   12.5%   811ms   15.5MiB   20.1%  15.5MiB
  write to vtk                        3    146ms    2.2%  48.7ms   33.1MiB   42.9%  11.0MiB
  update systems                      1   15.7ms    0.2%  15.7ms   5.52KiB    0.0%  5.52KiB
particle shifting callback           20    454ms    7.0%  22.7ms    150KiB    0.2%  7.49KiB
  update systems and nhs             20    267ms    4.1%  13.4ms    110KiB    0.1%  5.52KiB
  particle shifting                  20    186ms    2.9%  9.32ms   38.4KiB    0.0%  1.92KiB
  ~particle shifting callback~       20   65.2μs    0.0%  3.26μs      976B    0.0%    48.8B
apply postprocess cb                  1    266ms    4.1%   266ms   26.3MiB   34.1%  26.3MiB
  interpolate plane                   1    173ms    2.7%   173ms   23.4MiB   30.3%  23.4MiB
  ~apply postprocess cb~              1   41.8ms    0.6%  41.8ms   1.84MiB    2.4%  1.84MiB
  write to vtk                        1   33.2ms    0.5%  33.2ms   1.08MiB    1.4%  1.08MiB
  update systems and nhs              1   18.8ms    0.3%  18.8ms   5.52KiB    0.0%  5.52KiB
drift!                              212   5.05ms    0.1%  23.8μs   54.0KiB    0.1%     261B
  reset ∂u/∂t                       212   2.94ms    0.0%  13.9μs   6.62KiB    0.0%    32.0B
  velocity                          212   2.00ms    0.0%  9.42μs   46.4KiB    0.1%     224B
  ~drift!~                          212    117μs    0.0%   554ns      976B    0.0%    4.60B
───────────────────────────────────────────────────────────────────────────────────────────

@efaulhaber efaulhaber requested a review from Copilot May 28, 2025 14:52
@efaulhaber efaulhaber self-assigned this May 28, 2025
@efaulhaber efaulhaber added the enhancement New feature or request label May 28, 2025
Copy link

@Copilot Copilot AI left a comment

Choose a reason for hiding this comment

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

Pull Request Overview

This PR aims to clean up timer outputs by grouping update calls into block scopes and using the @notimeit macro to prevent creating extraneous sub-timers. Key changes include:

  • Wrapping update_systems_and_nhs calls in a begin…end block with @notimeit in I/O, post-process, and particle shifting callbacks.
  • Updating timer label names to reflect the encompassed operations.
  • Adjusting the TimerOutputs import to include the new @notimeit macro.

Reviewed Changes

Copilot reviewed 4 out of 4 changed files in this pull request and generated 1 comment.

File Description
src/io/write_vtk.jl Wrapped update_systems_and_nhs call in a block to suppress sub-timer output.
src/callbacks/post_process.jl Similar block wrapping applied with an updated timer label for clarity.
src/callbacks/particle_shifting.jl Nested timer blocks introduced to group update operations and prevent clutter.
src/TrixiParticles.jl Updated TimerOutputs import to include the new @notimeit macro.
Comments suppressed due to low confidence (2)

src/callbacks/post_process.jl:241

  • [nitpick] Consider standardizing the timer label names across modules. In src/io/write_vtk.jl the timer label remains 'update systems', whereas here it is 'update systems and nhs'. Choose one consistent label to avoid confusion.
@trixi_timeit timer() "update systems and nhs" begin

src/callbacks/particle_shifting.jl:40

  • [nitpick] Ensure the timer label 'update systems and nhs' is used consistently with similar timer blocks elsewhere, or adjust it if a different naming convention is intended.
@trixi_timeit timer() "update systems and nhs" begin

@efaulhaber efaulhaber requested review from LasNikas and svchb May 28, 2025 14:54
Copy link

codecov bot commented May 28, 2025

Codecov Report

Attention: Patch coverage is 0% with 11 lines in your changes missing coverage. Please review.

Project coverage is 70.70%. Comparing base (c4b008f) to head (d304e3c).

Files with missing lines Patch % Lines
src/callbacks/particle_shifting.jl 0.00% 7 Missing ⚠️
src/callbacks/post_process.jl 0.00% 2 Missing ⚠️
src/io/write_vtk.jl 0.00% 2 Missing ⚠️
Additional details and impacted files
@@            Coverage Diff             @@
##             main     #819      +/-   ##
==========================================
- Coverage   70.74%   70.70%   -0.05%     
==========================================
  Files         106      106              
  Lines        6710     6714       +4     
==========================================
  Hits         4747     4747              
- Misses       1963     1967       +4     
Flag Coverage Δ
unit 70.70% <0.00%> (-0.05%) ⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
enhancement New feature or request
Projects
None yet
Development

Successfully merging this pull request may close these issues.

1 participant