esmc_timer.c

CCSM Research Tools: Community Atmosphere Model (CAM)

    return t_error ("t_stamp: times() failed. Timing bogus\n");

  *usr = buf.tms_utime / (double) ticks_per_sec;
  *sys = buf.tms_stime / (double) ticks_per_sec;

  gettimeofday (&tp, NULL);
  *wall = tp.tv_sec + 1.e-6*tp.tv_usec;

  return 0;
}


/*
** t_start.c: start a timer
**
** Input arguments:
**   name: timer name
**
** Return value: 0 (success) or -1 (failure)
*/

static int t_start (char *name)        /* timer name */
{
  struct timeval tp1, tp2;      /* argument to gettimeofday */
  struct node *ptr;             /* linked list pointer */

  int numchars;                 /* number of characters in timer */
  int mythread;                 /* thread index (of this thread) */
  int indent_level = 0;         /* required indentation level for this timer */
  int ret;                      /* return code */

  PCL_CNT_TYPE i_pcl_result1[PCL_COUNTER_MAX];     /* init. output fm PCLread */
  PCL_CNT_TYPE i_pcl_result2[PCL_COUNTER_MAX];     /* final output fm PCLread */
  PCL_FP_CNT_TYPE fp_pcl_result[PCL_COUNTER_MAX];  /* required by PCLread */

  /*
  ** 1st system timer call is solely for overhead timing
  */

#if ( defined DISABLE_TIMERS )
  return 0;
#endif

  if (wallenabled)
    gettimeofday (&tp1, NULL);

  if ( ! t_initialized)
    return t_error ("t_start: t_initialize has not been called\n");

  if ((mythread = get_thread_num ()) < 0)
    return t_error ("t_start\n");

  if (ncounter > 0) {
    ret = PCLread (descr[mythread], i_pcl_result1, fp_pcl_result, ncounter);
    if (ret != PCL_SUCCESS)
      return t_error ("t_start: error from PCLread: %s\n", t_pclstr (ret));
  }

  /*
  ** Look for the requested timer in the current list.  For those which don't
  ** match but are currently active, increase the indentation level by 1
  */

  for (ptr = timers[mythread]; ptr != NULL && ! STRMATCH (name, ptr->name); 
       ptr = ptr->next) {

    if (ptr->onflg) 
      indent_level++;
  }

  if (indent_level > max_indent_level[mythread])
    max_indent_level[mythread] = indent_level;
    
  /* 
  ** If a new thing is being timed, add a new link and initialize 
  */

  if (ptr == NULL) {

    if ((ptr = (struct node *) malloc (sizeof (struct node))) == NULL)
      return (t_error ("t_start: malloc failed\n"));

    memset (ptr, 0, sizeof (struct node));
    ptr->indent_level = indent_level;
    ptr->next = NULL;

    if (timers[mythread] == NULL)
      timers[mythread] = ptr;
    else
      last[mythread]->next = ptr;

    last[mythread] = ptr;

    /* 
    ** Truncate input name if longer than ESMC_PROFILER_MAX_CHARS characters 
    */

    numchars = MIN (strlen (name), ESMC_PROFILER_MAX_CHARS);
    strncpy (ptr->name, name, numchars);
    ptr->name[numchars] = '\0';

  } else {

    /*
    ** If computed indentation level is different than before or was
    ** already ambiguous, reset to ambiguous flag value.  This will likely
    ** happen any time the thing being timed is called from more than 1
    ** branch in the call tree.
    */

    if (ptr->indent_level != indent_level) 
      ptr->indent_level = AMBIGUOUS;

    if (ptr->onflg)
      return t_error ("t_start thread %d: timer %s was already on: "
		      "not restarting.\n", mythread, ptr->name);
  }

  ptr->onflg = true;

  if (usrsysenabled)
    if (get_cpustamp (&ptr->last_utime, &ptr->last_stime) < 0)
      return t_error ("t_start: get_cpustamp error");

  /*
  ** The 2nd system timer call is used both for overhead estimation and
  ** the input timer
  */

  if (wallenabled) {

    gettimeofday (&tp2, NULL);
    ptr->last_wtime_sec  = tp2.tv_sec;
    ptr->last_wtime_usec = tp2.tv_usec;
    overhead[mythread] +=       (tp2.tv_sec  - tp1.tv_sec) + 
                          1.e-6*(tp2.tv_usec - tp1.tv_usec);
  }

  if (ncounter > 0) {
    int n;
    int index;

    ret = PCLread (descr[mythread], i_pcl_result2, fp_pcl_result, ncounter); 
    if (ret != PCL_SUCCESS)
      return t_error ("t_start: error from PCLread: %s\n", t_pclstr (ret));

    for (n = 0; n < ncounter; n++) {
      ptr->last_pcl_result[n] = i_pcl_result2[n];
    }

    if (pcl_cyclesenabled) {
      index = pcl_cyclesindex;
      overhead_pcl[mythread] += i_pcl_result2[index] - i_pcl_result1[index];
    }
  } 

  return (0);
}

/*
** This stub should never actually be called
*/

#ifndef HAVE_PCL
static int PCLread (PCL_DESCR_TYPE descr, PCL_CNT_TYPE *i, PCL_CNT_TYPE *j, int k)
{
  return t_error ("PCLread called when library not there\n");
}
#endif


/*
** t_stop: stop a timer
**
** Input arguments:
**   name: timer name
**
** Return value: 0 (success) or -1 (failure)
*/

static int t_stop (char *name)
{
  long delta_wtime_sec;     /* wallclock change fm t_start() to t_stop() */    
  long delta_wtime_usec;    /* wallclock change fm t_start() to t_stop() */
  float delta_wtime;        /* floating point wallclock change */
  struct timeval tp1, tp2;  /* argument to gettimeofday() */
  struct node *ptr;         /* linked list pointer */

  int mythread;             /* thread number for this process */
  int ret;                  /* return code */

  long usr;
  long sys;

  PCL_CNT_TYPE i_pcl_result1[PCL_COUNTER_MAX];     /* init. output fm PCLread */
  PCL_CNT_TYPE i_pcl_result2[PCL_COUNTER_MAX];     /* final output fm PCLread */
  PCL_FP_CNT_TYPE fp_pcl_result[PCL_COUNTER_MAX];  /* required by PCLread */

#if ( defined DISABLE_TIMERS )
  return 0;
#endif

  if ( ! t_initialized)
    return t_error ("t_stop: t_initialize has not been called\n");

  /*
  ** The 1st system timer call is used both for overhead estimation and
  ** the input timer
  */

  if (wallenabled)
    gettimeofday (&tp1, NULL);

  if (usrsysenabled && get_cpustamp (&usr, &sys) < 0)
    return t_error (NULL);

  if ((mythread = get_thread_num ()) < 0)
    return t_error ("t_stop\n");

  if (ncounter > 0) {
    ret = PCLread (descr[mythread], i_pcl_result1, fp_pcl_result, ncounter);
    if (ret != PCL_SUCCESS)
      return t_error ("t_stop: error from PCLread: %s\n", t_pclstr (ret));
  }
  
  for (ptr = timers[mythread]; ptr != NULL && ! STRMATCH (name, ptr->name); 
       ptr = ptr->next);

  if (ptr == NULL) 
    return t_error ("t_stop: timer for %s had not been started.\n", name);

  if ( ! ptr->onflg )
    return t_error ("t_stop: timer %s was already off.\n",ptr->name);

  ptr->onflg = false;
  ptr->count++;

  /*
  ** 1st timer stoppage: set max and min to computed values.  Otherwise apply
  ** max or min function
  */

  if (wallenabled) {

    delta_wtime_sec  = tp1.tv_sec  - ptr->last_wtime_sec;
    delta_wtime_usec = tp1.tv_usec - ptr->last_wtime_usec;
    delta_wtime = delta_wtime_sec + 1.e-6*delta_wtime_usec;

    if (ptr->count == 1) {
      ptr->max_wtime = delta_wtime;
      ptr->min_wtime = delta_wtime;
      
    } else {
      
      ptr->max_wtime = MAX (ptr->max_wtime, delta_wtime);
      ptr->min_wtime = MIN (ptr->min_wtime, delta_wtime);
    }

    ptr->accum_wtime_sec  += delta_wtime_sec;
    ptr->accum_wtime_usec += delta_wtime_usec;

    /*
    ** Adjust accumulated wallclock values to guard against overflow in the
    ** microsecond accumulator.
    */

    if (ptr->accum_wtime_usec > 1000000) {
      ptr->accum_wtime_usec -= 1000000;
      ptr->accum_wtime_sec  += 1;
      
    } else if (ptr->accum_wtime_usec < -1000000) {
      
      ptr->accum_wtime_usec += 1000000;
      ptr->accum_wtime_sec  -= 1;
    }

    ptr->last_wtime_sec  = tp1.tv_sec;
    ptr->last_wtime_usec = tp1.tv_usec;

    /*
    ** 2nd system timer call is solely for overhead timing
    */

    gettimeofday (&tp2, NULL);
    overhead[mythread] +=       (tp2.tv_sec  - tp1.tv_sec) + 
                          1.e-6*(tp2.tv_usec - tp1.tv_usec);
  }

  if (usrsysenabled) {
    ptr->accum_utime += usr - ptr->last_utime;
    ptr->accum_stime += sys - ptr->last_stime;
    ptr->last_utime   = usr;
    ptr->last_stime   = sys;
  }

  if (ncounter > 0) {
    int n;
    PCL_CNT_TYPE delta;
    int index;

    for (n = 0; n < ncounter; n++) {
      delta = i_pcl_result1[n] - ptr->last_pcl_result[n];

      /*
      ** Accumulate results only for positive delta
      */

      if (delta < 0) 
	printf ("t_stop: negative delta => probable counter overflow. "
		"Skipping accumulation this round\n"
		"%ld - %ld = %ld\n", (long) i_pcl_result1[n], 
		                     (long) ptr->last_pcl_result[n],
		                     (long) delta);
      else
	ptr->accum_pcl_result[n] += delta;

      ptr->last_pcl_result[n] = i_pcl_result1[n];
    }

    /*
    ** Overhead estimate.  Currently no check for negative delta
    */

    ret = PCLread (descr[mythread], i_pcl_result2, fp_pcl_result, ncounter);
    if (ret != PCL_SUCCESS)
      return t_error ("t_stop: error from PCLread: %s\n", t_pclstr (ret));

    if (pcl_cyclesenabled) {
      index = pcl_cyclesindex;
      overhead_pcl[mythread] += i_pcl_result2[index] - i_pcl_result1[index];
    }
  }

  return 0;
}


/************************* New Interfaces ******************************/
/* Error handling is done by intercepting the t_error function.  This 
   allows for the minimal change in the existing timer library.      */

/*--------------------------------------------------------------------------*/
#undef __FUNC__
#define __FUNC__ "ESMC_TimerInit"
int ESMC_TimerInit(char *name, ESMC_TimerOption option1, ...)
{
  /* This function uses var args, so it will have to deal with
     the string length as it picks off args. */ 
  va_list args;
  int ret;

  va_start(args, option1);

  ret = ESMC_TimerInitCV(name, option1, args);
  
  va_end(args);

  return ret;
}

/*--------------------------------------------------------------------------*/
#undef __FUNC__
#define __FUNC__ "ESMC_TimerInitCV"
int ESMC_TimerInitCV(char *name, ESMC_TimerOption option1, va_list args)
{
  int option;
  int iopt;
  static int firstime = 1;
  int ret;

  if (firstime)
    {
      firstime = 0;
    }
  else
    {
      printf("Multiple timers not yet implemented\n");
      return;
    }
  
  /* Repeatedly call t_set_option */
  option = option1;
  while (option != 0)
    {
      switch(option)
	{
	default:
	  iopt = va_arg(args, int);

	  t_setoption((OptionName) option, (Boolean) iopt);
	  break;
	}
      
      /* Get next option */
      iopt = va_arg(args, int);
      if (iopt)
	option = iopt;
      else /* This says that no option can be zero */
	option = 0;
    }

  /* Call the timer libary init */
  t_initialize();

  return ESMC_SUCCESS;
}

/*--------------------------------------------------------------------------*/
#undef __FUNC__
#define __FUNC__ "ESMC_TimerTimerInitV"
int ESMC_TimerInitV(char *name, ESMC_TimerOption option1, va_list args)
{
  ESMC_TimerOption option;
  ESMC_TimerOption *iptr;
  static int firstime = 1;
  int ret;

  if (firstime)
    {
      firstime = 0;
    }
  else
    {
      printf("Multiple timers not yet implemented\n");
      return;
    }
  
  /* Repeatedly call t_set_option */
  option = option1;
  while (option != 0)
    {
      switch(option)
	{
	default:
	  iptr = va_arg(args, ESMC_TimerOption*);

	  t_setoption((OptionName) option, (Boolean) *iptr);
	  break;
	}
      
      /* Get next option */
      iptr = va_arg(args, ESMC_TimerOption*);
      if (iptr)
	option = *iptr;
      else /* This says that no option can be zero */
	option = 0;
    }

  /* Call the timer libary init */
  t_initialize();

  return ESMC_SUCCESS;
}

/*--------------------------------------------------------------------------*/
#undef __FUNC__
#define __FUNC__ "ESMC_TimerStart"
int ESMC_TimerStart(char *name)
{

  printf("nameBuf:<%s>\n", name);
  t_start(name);
  
  return ESMC_SUCCESS;
}

/*--------------------------------------------------------------------------*/
#undef __FUNC__
#define __FUNC__ "ESMC_TimerStop"
int ESMC_TimerStop(char *name)
{
  printf("nameBuf:<%s>\n", name);
  t_stop(name);
  
  return ESMC_SUCCESS;
}

/*--------------------------------------------------------------------------*/
#undef __FUNC__
#define __FUNC__ "ESMC_TimerStamp"
int ESMC_TimerStamp(double *wall, double *user, double *sys)
{
  t_stamp(wall, user, sys);
  return ESMC_SUCCESS;
}

/*--------------------------------------------------------------------------*/
#undef __FUNC__
#define __FUNC__ "ESMC_TimerPrint"
int ESMC_TimerPrint(char *name, ESMC_Log log)
{
  int flag;
  int node, process, thread;
  float tfloat;
 
  ESMC_MachinePInfo(&node, &process, &thread);
  
  if (log)
     t_pr(log, name, process);
  else
     t_pr(STDLog, name, process);

  return ESMC_SUCCESS;
}

/*--------------------------------------------------------------------------*/
#undef __FUNC__
#define __FUNC__ "ESMC_TimerSetSTDLog"
int ESMC_TimerSetSTDLog(ESMC_Log log)
{
  STDLog = log;

  return ESMC_SUCCESS;
}