local profiler;
/* DOCUMENT profiler.i --- Routines for profiling execution time

   List of routines
 * timer_init:    initialization
 * timer_call:    function call
 * timer_return:  function return
 * timer_show:    display
 *
 * Modified: 11 Sep 1997, R. Saravanan
 *
 */

// Maximum calling stack size (for timing info)
TIMER_MAXCALL= 256;

TIMER_STACK= array(long,TIMER_MAXCALL);
TIMER_START= array(double,3,TIMER_MAXCALL);
TIMER_NEST=  array(double,3,TIMER_MAXCALL);

// Maximum recursion level (for timing info)
TIMER_RECLEV= 10;

TIMER_NAMES= [];

struct timer_struc{    // Timer structure
long count, curlev;
double accum(3,TIMER_RECLEV);
}

func timer_init(track=,ignore=)
/* DOCUMENT  timer_init,track=,ignore=
   Initialize (or reset) execution time counters for functions.
   Should be called from the main program.
   Calls to function name strings TRACK, if specified, are stratified based
   upon the calling function.
   Calls to function name strings IGNORE, if specified, are ignored
   (i.e., their timings are lumped with that of the calling function)
   SEE ALSO: timer_call, timer_return, timer_show, timer
 */
{
  extern TIMER_STACK, TIMER_START, TIMER_NEST, TIMER_TRACK, TIMER_IGNORE,
         TIMER_CALLNO, TIMER_CURFUN, TIMER_CALLFUN, TIMER_NAMES, TIMER_PARS;

// Initialize calling stack index
  TIMER_CALLNO= 0;

// Initialize timing operations
  TIMER_NAMES= "*main*";
  TIMER_PARS=  timer_struc();

  TIMER_TRACK= track;
  TIMER_IGNORE= ignore;

  TIMER_CURFUN= "";
  TIMER_CALLFUN= "";

  timer_call, "*main*";

  return;
}

func timer_call( func_name )
/* DOCUMENT  timer_call( func_name )
   Log a function call to FUNC_NAME for execution timing.
   (If FUNC_NAME == "", ignore this call)
   SEE ALSO: timer_init, timer_return, timer_show, timer
 */
{
  extern TIMER_STACK, TIMER_START, TIMER_NEST, TIMER_TRACK, TIMER_IGNORE,
         TIMER_CALLNO, TIMER_CURFUN, TIMER_CALLFUN, TIMER_NAMES, TIMER_PARS;

  if (is_void(TIMER_NAMES) || (func_name == "") ||
      anyof(TIMER_IGNORE == func_name) ) return;

  if (anyof(TIMER_TRACK == func_name)) {
    stack_name= TIMER_CALLFUN+"->"+func_name;
    if (stack_name != TIMER_CURFUN)
      stack_name= TIMER_CURFUN+"->"+func_name;

  } else {
    stack_name= func_name;
  }

// Set name of calling function (excluding immediate recursive calls)
  if (TIMER_CURFUN != stack_name) TIMER_CALLFUN= TIMER_CURFUN;

// Name of current function call
  TIMER_CURFUN= stack_name;

// Locate function name
  list= where(TIMER_NAMES == stack_name);

  if (!numberof(list)) {
//  Add new function name to list
    grow, TIMER_NAMES, stack_name;
    grow, TIMER_PARS,  timer_struc();
    ifun= numberof(TIMER_NAMES);
  } else {
    ifun= list(1);
  }

// Stack call
  TIMER_CALLNO += 1;
  if (TIMER_CALLNO > TIMER_MAXCALL)
    error, "Too many function calls";
  TIMER_STACK(TIMER_CALLNO)= ifun;

// Save start time for this call
  elapsed= array(double,3);
  timer, elapsed;
  TIMER_START(,TIMER_CALLNO)= elapsed;
  TIMER_NEST(,TIMER_CALLNO)= 0.;

// Increment calling level and count for function
  curlev= TIMER_PARS(ifun).curlev;
  curlev+= 1;
  if (curlev > TIMER_RECLEV)
    error, "Too many recursion levels for function '"+func_name+"'";

  TIMER_PARS(ifun).curlev= curlev;
  TIMER_PARS(ifun).count= TIMER_PARS(ifun).count + 1;

  return;
}

func timer_return( func_name, return_value )
/* DOCUMENT  timer_return( func_name, return_value )
   Log a return from function FUNC_NAME for execution timing,
   with optional RETURN_VALUE, which is simply returned as it is.
   (If FUNC_NAME == "", ignore this call, and return RETURN_VALUE)
   (May also be invoked as a subroutine)
   SEE ALSO: timer_init, timer_call, timer_show, timer
 */
{
  extern TIMER_STACK, TIMER_START, TIMER_NEST, TIMER_TRACK, TIMER_IGNORE,
         TIMER_CALLNO, TIMER_CURFUN, TIMER_CALLFUN, TIMER_NAMES, TIMER_PARS;

  if (is_void(TIMER_NAMES) || (func_name == "") ||
      anyof(TIMER_IGNORE == func_name) ) return return_value;

  if (anyof(TIMER_TRACK == func_name))
    stack_name= TIMER_CALLFUN+"->"+func_name;
  else
    stack_name= func_name;

  ifun= TIMER_STACK(TIMER_CALLNO);

  if (TIMER_NAMES(ifun) != stack_name)
    error, "Called '"+TIMER_NAMES(ifun)+"' but returning from '"+stack_name;

// Compute time spent in this function
  elapsed= TIMER_START(,TIMER_CALLNO);
  split= array(double,3);
  timer, elapsed, split;

// Accumulate time spent in this function (but not in nested calls)
  curlev= TIMER_PARS(ifun).curlev;
  if (curlev < 1)
    error, "Attempt to return without calling from function '"+func_name+"'";
  TIMER_PARS(ifun).accum(,curlev)= TIMER_PARS(ifun).accum(,curlev) -
                                   TIMER_NEST(,TIMER_CALLNO) + split;
  curlev -= 1;
  TIMER_PARS(ifun).curlev= curlev;

// Pop call, and accumulate time spent on nested call for calling function
  TIMER_CALLNO -= 1;
  TIMER_NEST(,TIMER_CALLNO)= TIMER_NEST(,TIMER_CALLNO) + split;

// Reset name of current function call
  TIMER_CURFUN= TIMER_NAMES(TIMER_STACK(TIMER_CALLNO));

// Set name of calling function (excluding immediate recursive calls)
  icallno= TIMER_CALLNO-1;
  while ((icallno > 1) && (TIMER_CURFUN==TIMER_NAMES(TIMER_STACK(icallno))))
    icallno--;

  TIMER_CALLFUN= TIMER_NAMES(TIMER_STACK(icallno));

  return return_value;
}

func timer_show( ndisp, recursion=, sort_count= )
/* DOCUMENT  timer_show, ndisp, recursion=0/1, sortcount=0/1
   Display sorted timing statistics for all logged function calls,
   starting from the function that takes the most execution time.
   The optional parameter NDISP determines the number of functions to
   be displayed (the default is to display the top 20).
   If RECURSION==1, then execution times for different levels of recursive
   function calls are also reported separately
   (in addition to the total for the function).
   If SORT_COUNT==1, then sort by number of calls.

   NOTE:
   Execution times for functions whose calls are not logged using
   TIMER_CALL/TIMER_RETURN are lumped together with the execution times
   for the functions within which these calls originated.
   For calls from the main program, unlogged function call timings
   are lumped together with the execution time for *main*.

   SEE ALSO: timer_init, timer_call, timer_return, timer
 */
{
  extern TIMER_STACK, TIMER_START, TIMER_NEST, TIMER_TRACK, TIMER_IGNORE,
         TIMER_CALLNO, TIMER_CURFUN, TIMER_CALLFUN, TIMER_NAMES, TIMER_PARS;

  if (is_void(ndisp)) ndisp= 20;

  if (is_void(TIMER_NAMES))
    error, "Timing counters should be initialized by calling TIMER_INIT";

// Time main program
  elapsed= TIMER_START(,1);
  split= array(double,3);
  timer, elapsed, split;

// Compute time spent in main program (but not in nested calls)
  TIMER_PARS(1).accum(,1)= split - TIMER_NEST(,1);

  countall= TIMER_PARS().count;
  accumall= TIMER_PARS().accum;
  if ((dimsof(accumall))(1) == 2) accumall= accumall(..,-);

  write, format="%29s   %10s  %10s  %10s  %10s\n",
    "Function", "CPU sec", "System sec", "Wall sec", "Call count"

  write, format="%29s   %10.3f  %10.3f  %10.3f\n",
    "*TOTAL*", accumall(1,sum,sum), accumall(2,sum,sum), accumall(3,sum,sum)

// Sort in reverse order of execution times
  if (param_set(sort_count)) {
    isort= sort( -countall );
  } else {
    isort= sort( -accumall(1,sum,) );
  }

  nfun= min([numberof(TIMER_NAMES), ndisp]);
  for (j=1; j<=nfun; j++) {
    ifun= isort(j);

//  Display total time for function calls
    write, format="%29s   %10.3f  %10.3f  %10.3f  %10d\n", TIMER_NAMES(ifun),
      accumall(1,sum,ifun), accumall(2,sum,ifun),
      accumall(3,sum,ifun), countall(ifun);

    nlev= sum( accumall(sum,,ifun) > 0 );
    if ((nlev > 1) && param_set(recursion)) {
//    Display time for different recursion levels
      for (ilev=1; ilev<=nlev; ilev++) {
        write, format="%29d   %10.3f  %10.3f  %10.3f\n", ilev,
          accumall(1,ilev,ifun), accumall(2,ilev,ifun),
          accumall(3,ilev,ifun);
      }
    }
  }
}