Question about timing discrepancy between _solve_elapsed_time and actual wall-clock time

Support
1

Dear AMPL Support Team,

I am currently developing a medium-sized cutting stock model in AMPL using CPLEX as the solver.

I am trying to analyze the computational times of my model, but I have noticed a significant discrepancy between the reported solver time and the actual wall-clock time. Specifically, when I use the command:

display _solve_elapsed_time;

AMPL reports approximately 10 seconds of solving time. However, when I measure the time manually with a stopwatch, the entire process takes more than 20 minutes.

Could you please clarify why there is such a large difference between these two measurements? Is it correct to assume that AMPL spends a considerable amount of time on model generation and data loading before the solver is invoked?

Also, could you let me know which internal AMPL options or commands can be used to accurately measure:

  1. The total elapsed (wall-clock) time, including model and data loading; and

  2. The time spent specifically in the solver?

Thank you very much for your help and clarification.

Best regards,

1 Like
2

Hi dmorill,

The _solve_xxx parameters don’t include AMPL times.

There are separated built-in parameters for AMPL times (model/data loading, compilation/generation of the model, presolve, writing the NL file…) and the Solver times.

Here it’s the table with all these built-in parameters:

AMPL Process Timing

  • _ampl_elapsed_time - Elapsed seconds since the start of the AMPL process
  • _ampl_system_time - System CPU seconds used by the AMPL process itself
  • _ampl_user_time - User CPU seconds used by the AMPL process itself
  • _ampl_time - _ampl_system_time + _ampl_user_time

Most Recent Shell Command

  • _shell_elapsed_time - Elapsed seconds for most recent shell command
  • _shell_system_time - System CPU seconds used by most recent shell command
  • _shell_user_time - User CPU seconds used by most recent shell command
  • _shell_time - _shell_system_time + _shell_user_time

Most Recent Solve Command

  • _solve_elapsed_time - Elapsed seconds for most recent solve command
  • _solve_system_time - System CPU seconds used by most recent solve command
  • _solve_user_time - User CPU seconds used by most recent solve command
  • _solve_time - _solve_system_time + _solve_user_time

Cumulative Shell Commands

  • _total_shell_elapsed_time - Elapsed seconds used by all shell commands
  • _total_shell_system_time - System CPU seconds used by all shell commands
  • _total_shell_user_time - User CPU seconds used by all shell commands
  • _total_shell_time - _total_shell_system_time + _total_shell_user_time

Cumulative Solve Commands

  • _total_solve_elapsed_time - Elapsed seconds used by all solve commands
  • _total_solve_system_time - System CPU seconds used by all solve commands
  • _total_solve_user_time - User CPU seconds used by all solve commands
  • _total_solve_time - _total_solve_system_time + _total_solve_user_time

It might be helpful to turn on some debugging options:

ampl.option['times'] = 1
ampl.option['gentimes'] = 1
ampl.option['show_stats'] = 1

Is it correct to assume that AMPL spends a considerable amount of time on model generation and data loading before the solver is invoked?

We would be really interested in such an example, if you’ve found such a problem send to support@ampl.com.