How can I print the elapsed running time for repeated runs?

ponpoko · February 24, 2025, 12:31pm

Hello,

I would like to print the elapsed (CPU) time every few steps.
The run command is executed repeatedly inside a loop, so I tried to define a variable (runTime) to store the elapsed time.
However, I noticed that the LAMMPS thermo keyword cpu seems to reset each time the run command is invoked.

#Test
units           si
atom_style      sphere
comm_modify     vel yes

region          r1 block -10 10 -10 10 -10 10
create_box      1 r1

timestep	    1E-3
region          r2 block -5 5 -5 5 0 5

create_atoms    1 random 10 12123123 r2
pair_style      gran/hertz/history 1E8 1E5 1000 100 0.5 1
pair_coeff      * *
fix             f1  all nve/sphere

variable        nStep     equal step
variable        runTime   equal 0
variable        RrunTime  equal ${runTime}+cpu

#variable        start timer

label           l1
variable        indexP loop 5
    fix             f2 all print 20000000 "index ${indexP} step ${nStep} runTime $(v_RrunTime:%8.5f)"
    run             100000000

    next            indexP                                                                # Next step for Pouring
    jump            SELF l1

#variable        stop timer

I am confused by the resulting output:
the runTime variable appears to reset in every run, yet there is an unexpected line printed before starting the next loop iteration.
That line repeats the final step of the previous loop and shows an accumulated elapsed time after the third loop.

Could someone please explain how to consistently print the correct elapsed time in each run?

=== 1st loop ===
Setting up Verlet run ...
  Unit style    : si
  Current step  : 0
  Time step     : 0.001
index 1 step 0 runTime  0.00000
Per MPI rank memory allocation (min/avg/max) = 10.31 | 10.31 | 10.31 Mbytes
   Step          Temp          E_pair         E_mol          TotEng         Press
         0   0              0              0              0              0
index 1 step 20000000 runTime  8.45127
index 1 step 40000000 runTime 16.75214
index 1 step 60000000 runTime 25.05487
index 1 step 80000000 runTime 33.35907
index 1 step 100000000 runTime 41.66397
 100000000   0              0              0              0              0
Loop time of 41.664 on 1 procs for 100000000 steps with 10 atoms

100.0% CPU use with 1 MPI tasks x 1 OpenMP threads

=== 2dn loop ===
Setting up Verlet run ...
  Unit style    : si
  Current step  : 100000000
  Time step     : 0.001
index 2 step 100000000 runTime  0.01740
Per MPI rank memory allocation (min/avg/max) = 10.31 | 10.31 | 10.31 Mbytes
   Step          Temp          E_pair         E_mol          TotEng         Press
 100000000   0              0              0              0              0
index 2 step 120000000 runTime  8.29881
index 2 step 140000000 runTime 16.60269
index 2 step 160000000 runTime 24.90508
index 2 step 180000000 runTime 33.20836
index 2 step 200000000 runTime 41.51192
 200000000   0              0              0              0              0
Loop time of 41.512 on 1 procs for 100000000 steps with 10 atoms

100.0% CPU use with 1 MPI tasks x 1 OpenMP threads

=== 3rd loop ===
Setting up Verlet run ...
  Unit style    : si
  Current step  : 200000000
  Time step     : 0.001
index 3 step 200000000 runTime 41.68179
Per MPI rank memory allocation (min/avg/max) = 10.31 | 10.31 | 10.31 Mbytes
   Step          Temp          E_pair         E_mol          TotEng         Press
 200000000   0              0              0              0              0
index 3 step 220000000 runTime  8.30832
index 3 step 240000000 runTime 16.61235
index 3 step 260000000 runTime 24.92323
index 3 step 280000000 runTime 33.22722
index 3 step 300000000 runTime 41.53040
 300000000   0              0              0              0              0
Loop time of 41.5304 on 1 procs for 100000000 steps with 10 atoms

100.0% CPU use with 1 MPI tasks x 1 OpenMP threads


=== 4th loop ===
Setting up Verlet run ...
  Unit style    : si
  Current step  : 300000000
  Time step     : 0.001
index 4 step 300000000 runTime 83.19410
Per MPI rank memory allocation (min/avg/max) = 10.31 | 10.31 | 10.31 Mbytes
   Step          Temp          E_pair         E_mol          TotEng         Press
 300000000   0              0              0              0              0
index 4 step 320000000 runTime  8.30554
index 4 step 340000000 runTime 16.61124
index 4 step 360000000 runTime 24.91832
index 4 step 380000000 runTime 33.22760
index 4 step 400000000 runTime 41.53892
 400000000   0              0              0              0              0
Loop time of 41.539 on 1 procs for 100000000 steps with 10 atoms

100.0% CPU use with 1 MPI tasks x 1 OpenMP threads

=== 5th loop ===
Setting up Verlet run ...
  Unit style    : si
  Current step  : 400000000
  Time step     : 0.001
index 5 step 400000000 runTime 124.72491
Per MPI rank memory allocation (min/avg/max) = 10.31 | 10.31 | 10.31 Mbytes
   Step          Temp          E_pair         E_mol          TotEng         Press
 400000000   0              0              0              0              0
index 5 step 420000000 runTime  8.31042
index 5 step 440000000 runTime 16.61925
index 5 step 460000000 runTime 24.92573
index 5 step 480000000 runTime 33.23294
index 5 step 500000000 runTime 41.54407
 500000000   0              0              0              0              0
Loop time of 41.5441 on 1 procs for 100000000 steps with 10 atoms

100.0% CPU use with 1 MPI tasks x 1 OpenMP threads

akohlmey · February 24, 2025, 3:08pm

Accumulating data in a variable over multiple runs is not something that LAMMPS was designed to do. Consequently, you have to go through some hoops to be able to access that data.

The main problem is that you cannot access thermo keywords outside of a run. So you have to cache them using something like fix ave/time. Then you have to redefine the accumulated variable use the current value with ${name} expansion (so you don’t get a recursive variable evaluation).
However, this does not allow you to access the current elapsed total CPU time during a run, since fix ave/time has to be set to get the total cpu time, i.e. must no be accessed in between. Thus you need to have a second variable, if you want to print intermediate values.

Here is a simple example demonstrating this:

# set up a simple system
include ../bench/in.lj

# set up printing current and total CPU time
variable cpu equal cpu
variable total equal 0.0
variable runsteps index 10
variable current equal ${total}+cpu

# set up fix ave/time for caching the total time for each run
fix 0 all ave/time ${runsteps} 1 ${runsteps} v_cpu
# set up fix print for printing intermediate values
fix 9 all print 2 "Current total: ${current}"

# start loop
label loop
variable index loop 5

# redefine current and total variables using the current value of v_total
variable current equal ${total}+cpu
variable total equal f_0+${total}

run ${runsteps} post no

# access the accumulated total time through fix ave/time
print "Final total CPU: ${total}"

next index
jump SELF loop

You have to use “current” inside a run, e.g. in fix print, and “total” outside the run.

ponpoko · February 25, 2025, 4:02am

Thank you

Appreciate