Hello all!
I am currently working on a simulation project and have been using Julia’s timing functionalities to monitor the performance of various sections of my code. The timing report provides a detailed breakdown of execution times and allocations, which is incredibly useful. However, given the extensive data in these reports, I find it challenging to quickly identify the most time-consuming sections.
Here is an example of the timing report generated by my simulation:
────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
Time Allocations
─────────────────────── ────────────────────────
Tot / % measured: 165s / 99.8% 1.53GiB / 99.7%
Section ncalls time %tot avg alloc %tot avg
────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
Step 0.1 | Update Neighbour system.nb.list 31.2k 78.1s 47.3% 2.50ms 399MiB 25.6% 13.1KiB
1.1 update particle positions 31.2k 25.8s 15.6% 826μs 128MiB 8.2% 4.21KiB
1.2 extract updated neighborlist 31.2k 46.4s 28.1% 1.49ms 268MiB 17.2% 8.78KiB
1.3 resize split neighborlist 31.2k 76.8ms 0.0% 2.46μs 2.78MiB 0.2% 93.6B
1.4 update values of split neighborlist 31.2k 5.64s 3.4% 181μs 0.00B 0.0% 0.00B
Step 0.2 | Reset arrays to zero and resize L arrays 31.2k 2.61s 1.6% 83.7μs 17.9MiB 1.1% 601B
1.1 resize calculation buffers 31.2k 352ms 0.2% 11.3μs 17.9MiB 1.1% 601B
1.2 reset calculation buffers 31.2k 2.15s 1.3% 69.0μs 0.00B 0.0% 0.00B
Step 1 | Update xᵢⱼ, kernel values and kernel gradient 31.2k 17.1s 10.4% 549μs 1.47KiB 0.0% 0.05B
1.1 calculate xᵢⱼ 31.2k 4.67s 2.8% 150μs 0.00B 0.0% 0.00B
1.2 calculate kernel and kernel gradient 31.2k 12.3s 7.5% 395μs 0.00B 0.0% 0.00B
Step 2 | Simulation Equations to update values, preparing for n+1/2 31.2k 14.8s 9.0% 475μs 2.20KiB 0.0% 0.07B
2.1 DDT 31.2k 3.58s 2.2% 115μs 0.00B 0.0% 0.00B
2.2 Pressure 31.2k 750ms 0.5% 24.0μs 0.00B 0.0% 0.00B
2.3 Artificial Viscosity Momentum Equation 31.2k 10.4s 6.3% 332μs 0.00B 0.0% 0.00B
Step 3 | Update values to n+1/2 31.2k 3.64s 2.2% 117μs 3.67KiB 0.0% 0.12B
3.1 vₙ⁺ 31.2k 648ms 0.4% 20.8μs 0.00B 0.0% 0.00B
3.2 Positionₙ⁺ 31.2k 579ms 0.4% 18.6μs 0.00B 0.0% 0.00B
3.3 ρₙ⁺ 31.2k 308ms 0.2% 9.86μs 0.00B 0.0% 0.00B
3.4 LimitDensityAtBoundary!(ρₙ⁺) 31.2k 383ms 0.2% 12.3μs 0.00B 0.0% 0.00B
3.5 updatexᵢⱼ! 31.2k 1.51s 0.9% 48.4μs 0.00B 0.0% 0.00B
Step 4 | Simulation Equations to update values, preparing for n+1 31.2k 12.6s 7.7% 405μs 2.94KiB 0.0% 0.10B
4.1 reset L arrays for density diffusion 31.2k 929ms 0.6% 29.8μs 0.00B 0.0% 0.00B
4.2 DDT 31.2k 3.22s 2.0% 103μs 0.00B 0.0% 0.00B
4.3 Pressure 31.2k 677ms 0.4% 21.7μs 0.00B 0.0% 0.00B
4.4 Artificial Viscosity Momentum Equation 31.2k 7.66s 4.6% 246μs 0.00B 0.0% 0.00B
Step 5 | Update values to n+1 31.2k 2.43s 1.5% 77.9μs 2.94KiB 0.0% 0.10B
5.1 DensityEpsi! 31.2k 304ms 0.2% 9.76μs 0.00B 0.0% 0.00B
5.2 LimitDensityAtBoundary!(Density) 31.2k 353ms 0.2% 11.3μs 0.00B 0.0% 0.00B
5.3 Velocity 31.2k 492ms 0.3% 15.8μs 0.00B 0.0% 0.00B
5.4 Position 31.2k 1.14s 0.7% 36.4μs 0.00B 0.0% 0.00B
Step 6 | Calculating time step 31.2k 1.39s 0.8% 44.6μs 2.20KiB 0.0% 0.07B
6.1 calculate dt 31.2k 1.23s 0.7% 39.5μs 0.00B 0.0% 0.00B
6.2 set new dt 31.2k 33.6ms 0.0% 1.08μs 0.00B 0.0% 0.00B
6.3 increment total dt 31.2k 33.0ms 0.0% 1.06μs 0.00B 0.0% 0.00B
Step 7 | Outputting save files and updating progress bar 31.2k 32.2s 19.5% 1.03ms 1.12GiB 73.3% 37.5KiB
7.1 outputting savefile 624 28.8s 17.5% 46.2ms 1.01GiB 66.3% 1.66MiB
7.2 updating progress bar 31.2k 3.32s 2.0% 106μs 110MiB 7.0% 3.60KiB
──────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────── ────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
I would like to learn if there’s a way to color-code these outputs based on the execution time (e.g., red for the most time-consuming sections, yellow for moderate, and green for the least). This enhancement would greatly aid in quickly identifying performance bottlenecks in my simulation.
Here is an example function:
using TimerOutputs
# Create a new timer object
const to = TimerOutput()
function simulation_step1()
@timeit to "Step 1" sleep(0.1) # Simulating a computation-heavy task
end
function simulation_step2()
@timeit to "Step 2" sleep(0.2) # Simulating a longer computation-heavy task
end
function simulation_step3()
@timeit to "Step 3" sleep(0.05) # Simulating a shorter computation-heavy task
end
function run_simulation()
simulation_step1()
simulation_step2()
simulation_step3()
end
run_simulation()
println(to)
Which outputs:
────────────────────────────────────────────────────────────────────
Time Allocations
─────────────────────── ────────────────────────
Tot / % measured: 555ms / 67.8% 2.71MiB / 0.0%
Section ncalls time %tot avg alloc %tot avg
────────────────────────────────────────────────────────────────────
Step 2 1 202ms 53.6% 202ms 112B 33.3% 112B
Step 1 1 113ms 30.1% 113ms 112B 33.3% 112B
Step 3 1 61.6ms 16.4% 61.6ms 112B 33.3% 112B
────────────────────────────────────────────────────────────────────
If anyone has color coded results from TimerOutputs before, it would be very appreciated if you could share how with me!
Kind regards