Elapsed running time

150 views
Skip to first unread message

f.javier...@upc.edu

unread,
Sep 29, 2021, 2:42:14 PM9/29/21
to AMPL Modeling Language
Hi everybody, there something I don't understand about running times.
I'm solving some large-scale MIQP with CPLEX 20.1.0.0 on multithread server (up to 128 threads). The times reported by AMPL are:
_solve_elapsed_time = 292948
_solve_system_time = 6929.73
_solve_user_time = 313033

while CPLEX's timing=1 log (clocktype at its default value => elapsed wall-clock) is:
Times (seconds):
Input = 2.81938
Solve = 32587.7
Output = 287373

According to CPLEX, times are elapsed wall-clock seconds, meaning a total elapsed time of ~319,963.5 sec. That amount coincides almost exactly with the AMPL's _solve_time=_solve_system_time+_solve_user_time=319,962.73, sec, so I assume that _solve_system are also wall-clock sec.

My concern is about AMPL's _solve_elapsed_time = 292948 . I though that this amount was the total elapsed time of the CPLEX's run, so I  don't understand the reason for the large discrepancy between  _solve_elapsed_time  and both _solve_time  and the elapsed time reported by CPLEX (a discrepancy greater than 27,000 sec).

So, the point is: if I do want to take the elapsed wall-clock running time of a solve command (in a multi-threading execution), what parameter I should take? _solve_elapsed_time or _solve_time ?

Thank you

Javier


AMPL Google Group

unread,
Sep 30, 2021, 3:22:35 PM9/30/21
to AMPL Modeling Language
The _solve_elapsed_time is the elapsed (wall-clock) time. This is what you want.

The _solve_time is the total CPU time summed over all parallel threads, which is not a good measure of the efficiency of a parallel MIP solve. So this is not what you want.

The timing=1 output from CPLEX is always comparable to _solve_time, regardless of the clocktype setting. So this is also not what you want.

To see detailed elapsed time data from CPLEX, set mipdisplay=2. Then CPLEX will display a progress log, with a time summary like this at the end:

Root node processing (before b&c):
  Real time             =    0.14 sec. (22.73 ticks)
Parallel b&c, 4 threads:
  Real time             =  119.88 sec. (47223.83 ticks)
  Sync time (average)   =    5.96 sec.
  Wait time (average)   =    0.02 sec.
                          ------------
Total (root+branch&cut) =  120.02 sec. (47246.56 ticks)

The "Total (root+branch&cut)" time will be close to the _solve_elapsed_time.


--
Robert Fourer
am...@googlegroups.com
{#HS:1645686449-106479#}
Reply all
Reply to author
Forward
0 new messages