esmc_timer.c

CCSM Research Tools: Community Atmosphere Model (CAM)

/* $Id: ESMC_Timer.c,v 1.1.6.1 2002/04/24 03:25:54 erik Exp $ */

#include <stdio.h>
#include <stdlib.h>
#include <unistd.h>
#include <sys/types.h>
#include <time.h>
#include <sys/times.h>
#include <sys/time.h>
#include <stdarg.h>

#include <string.h>

#include "conf.h"

#include "ESMC_Timer.h"
#include "ESMC_Error.h"



static ESMC_Log STDLog = 0;
int ESMC_TimerInitV(char *name, ESMC_TimerOption option1, va_list args);
int ESMC_TimerInitCV(char *name, ESMC_TimerOption option1, va_list args);


#ifdef ESMC_HAVE_MPI
#include <mpi.h>
#endif


/*
** Required OMP calls not available on AIX so use PTHREADS
*/


/* Translate the ESMF defines into Rosinski's defines */

#ifdef ESMC_HAVE_OMP_THREADS
#define THREADED_OMP
#endif

#ifdef ESMC_HAVE_PTHREADS
#define THREADED_PTHREADS
#endif

#ifdef ESMC_HAVE_PCL
#define HAVE_PCL
#endif

/*
** Threading currently doesn't work on SUN so don't enable pthreads or omp
*/

#if ( defined THREADED_OMP )
#include <omp.h>
#elif ( defined THREADED_PTHREADS )
#include <pthread.h>
#endif

#ifdef HAVE_PCL
#include <pcl.h>
#else

/*
** Dummy up pcl stuff if library unavailable
*/   

typedef int PCL_CNT_TYPE;
typedef int PCL_FP_CNT_TYPE;
typedef int PCL_DESCR_TYPE;
#define PCL_MODE_USER       -1
#define PCL_L1DCACHE_MISS   -1
#define PCL_L2CACHE_MISS    -1
#define PCL_CYCLES          -1
#define PCL_ELAPSED_CYCLES  -1
#define PCL_FP_INSTR        -1
#define PCL_LOADSTORE_INSTR -1
#define PCL_INSTR           -1
#define PCL_STALL           -1
#define PCL_COUNTER_MAX      1
#define PCL_SUCCESS          0
#endif

#ifndef MIN
#define MIN(X,Y) ((X) < (Y) ? (X) : (Y))
#endif

#ifndef MAX
#define MAX(X,Y) ((X) > (Y) ? (X) : (Y))
#endif

#define STRMATCH(X,Y) (strcmp((X),(Y)) == 0)

#define AMBIGUOUS -1
#define MAX_THREADS 128

typedef enum {false = 0, true = 1} Boolean;

/*
** User specifiable options.  The values must match their counterparts in header.inc
** Also, we must have pcl_start < all valid pcl values < pcl_end.
** To add a new PCL counter: 
** 1) add the new entry to OptionName below.
** 2) add the appropriate array entry for possible_event[] to t_initialize.c.
** 3) add the appropriate code to the "switch" construct in t_initialize.c
*/

typedef enum {
  usrsys               = 1,
  wall                 = 2,
  pcl_start            = 3,   /* bogus entry delimits start of PCL stuff */
#ifdef HAVE_PCL
  pcl_l1dcache_miss    = 4,
  pcl_l2cache_miss     = 5,
  pcl_cycles           = 6,
  pcl_elapsed_cycles   = 7,
  pcl_fp_instr         = 8,
  pcl_loadstore_instr  = 9,
  pcl_instr            = 10,
  pcl_stall            = 11,
#endif
  pcl_end              = 12   /* bogus entry delimits end of PCL stuff */
} OptionName;

struct Event {
  OptionName name;
  char string[9];
  int index;
};

struct PossibleEvent {
  OptionName name;
  Boolean enabled;
  char string[10];
};

struct node {
  char name[ESMC_PROFILER_MAX_CHARS+1];
  
  int indent_level;        /* indentation level of timer */

  long last_utime;         /* user time from most recent call */
  long last_stime;         /* system time from most recent call */
  long last_wtime_sec;     /* wallclock seconds from most recent call */
  long last_wtime_usec;    /* wallclock microseconds from most recent call */

  long accum_utime;        /* accumulated user time */
  long accum_stime;        /* accumulated system time */
  long accum_wtime_sec;    /* accumulated wallclock seconds */
  long accum_wtime_usec;   /* accumulated wallclock microseconds */

  float max_wtime;         /* maximum wallclock time for each start-stop */
  float min_wtime;         /* minimum wallclock time for each start-stop */

  PCL_CNT_TYPE last_pcl_result[PCL_COUNTER_MAX];
  PCL_CNT_TYPE accum_pcl_result[PCL_COUNTER_MAX];

  Boolean onflg;           /* true => timer is currently on */
  long count;              /* number of calls to t_start for this timer */

  struct node *next;       /* next timer in the linked list */
};

/*
** Globals
*/

extern struct node **timers;
extern struct node **last;
extern struct Options options;
extern long ticks_per_sec;
extern int numthreads;
extern int *max_indent_level;
extern float *overhead;
extern PCL_CNT_TYPE *overhead_pcl;
extern Boolean t_initialized;
extern Boolean wallenabled;
extern Boolean usrsysenabled;
extern struct PossibleEvent possible_event[];

/*
** Needed by PCL library: otherwise unused
*/

extern int counter_list[PCL_COUNTER_MAX];
extern int ncounter;     /* number of counters */
extern int cycles;       /* index of cycle counter */
extern int instr;        /* index of instruction counter */
extern int fp_instr;     /* index of fp instruction counter */
extern int l2cache_miss; /* index of l2cache miss */
extern int jump;
extern PCL_DESCR_TYPE *descr;
extern int nevent;
extern struct Event **event;
extern Boolean pclenabled;
extern Boolean pcl_cyclesenabled;
extern int pcl_cyclesindex;
extern int npossible;


static int max_seen_thread = 0;


struct Stats {		   
  float usr;	   /* user CPU time */
  float sys;	   /* system CPU time */
  float usrsys;	   /* usr + sys */
  float elapse;	   /* elapsed time */
  float max_wtime; /* max elapsed wallclock time per call */
  float min_wtime; /* min elapsed wallclock time per call */

  long count;	   /* number of invocations of this timer */

  PCL_CNT_TYPE pcl_result[PCL_COUNTER_MAX];
};


/* Function prototypes (make static to avoid polluting namespace */

static int t_error (const char *fmt, ...);
static int get_cpustamp (long *usr, long *sys);
static int get_thread_num ();
static int lock_mutex ();
static int unlock_mutex ();
static int t_initialize ();
static char *t_pclstr (int code);
static int t_pr (ESMC_Log log, char *name, int procid);
static void fillstats (struct Stats *stats, struct node *ptr);
static void print_stats_line (ESMC_Log log, struct Stats *stats);
static void print_header (ESMC_Log log, int indent_level);
static int t_reset ();
static int t_setoption (OptionName option, Boolean val);
static int t_stamp (double *wall, double *usr, double *sys);
static int t_start (char *name);
static int t_stop (char *name);

#ifndef HAVE_PCL
static int PCLread (PCL_DESCR_TYPE descr, PCL_CNT_TYPE *i, PCL_CNT_TYPE *j, int k);
#endif


/*
** t_error: error return routine to print a message and return a failure
** value.
**
** Input arguments:
**   fmt: format string
**   variable list of additional arguments for vfprintf
**
** Return value: -1 (failure)
*/

/*--------------------------------------------------------------------------*/
#undef __FUNC__
#define __FUNC__ "t_error"
static int t_error (const char *fmt, ...)
{
  va_list args;
  char buf[1024];

  buf[0] ='\0';
#if ( ! defined DISABLE_TIMERS )
  va_start (args, fmt);

  if (fmt != NULL)
    (void) vsprintf (buf, fmt, args);

  va_end (args);

#endif
  
  ESMC_ERRA(ESMC_ERR_LIB, 0, buf);
}


/*
** get_cpustamp: Invoke the proper system timer and return stats.
**
** Output arguments:
**   usr: user time (usec if USE_GETRUSAGE is defined, ticks otherwise)
**   sys: system time (usec if USE_GETRUSAGE is defined, ticks otherwise)
**
** Return value: 0 (success)
*/

static int get_cpustamp (long *usr, long *sys)
{
  struct tms buf;

  /*
  ** Throw away the wallclock time from times: use gettimeofday instead
  */
  
  (void) times (&buf);
  *usr = buf.tms_utime;
  *sys = buf.tms_stime;

  return 0;
}


/*
** get_thread_num: Obtain logical thread number of calling thread.  If new
** thread, adjust global variables.
*/

static int get_thread_num ()
{
  int mythread = 0 ;  /* return value: default zero for non-threaded case */

  int proc, thread, node;

  ESMC_MachinePInfo(&node, &proc, &thread);

  mythread = thread;

  if (thread > max_seen_thread)
    max_seen_thread = thread;
  
  return mythread;
}

/*
** lock_mutex: lock a mutex for entry into a critical region
*/

/* 
** Array (1 per thread) of linked lists of timers, and last timer in each list
*/

struct node **timers = NULL;
struct node **last = NULL;

long ticks_per_sec;

/*
** Define lock arrays depending upon the type of threading done
*/

float *overhead;                   /* wallclock estimate of timer overhead */
int *max_indent_level;             /* maximum indentation level */
int numthreads            = 1;     /* number of threads.  1 is for no threading */
Boolean t_initialized     = false; /* whether t_initialize has been called */
Boolean wallenabled       = false; /* wallclock timer stats enabled */
Boolean usrsysenabled     = false; /* usr & sys timer stats enabled */
Boolean pclenabled        = false; /* enable PCL library */     
Boolean pcl_cyclesenabled = false; /* enable PCL cycle count */
int pcl_cyclesindex       = -1;    /* index for PCL cycle count */

struct PossibleEvent possible_event[] = {
  {usrsys,               true,  "Usr Sys   "},
  {wall,                 true,  "Wallclock "},
#ifdef HAVE_PCL
  {pcl_start,            false, "          "},  /* bracket PCL entries */
  {pcl_l1dcache_miss,    false, "l1 D miss "},
  {pcl_l2cache_miss,     false, "L2 miss   "},
  {pcl_cycles,           false, "Cycles    "},
  {pcl_elapsed_cycles,   false, "E-Cycles  "},
  {pcl_fp_instr,         false, "FP instr  "},
  {pcl_loadstore_instr,  false, "L/S instr "},
  {pcl_instr,            false, "Instruct  "},
  {pcl_stall,            false, "Stall     "},
  {pcl_end,              false, "          "},  /* bracket PCL entries */
#endif
};

struct Event **event = NULL;
int nevent = 0;
int npossible = sizeof (possible_event) / sizeof (struct PossibleEvent);

/*
** Needed by PCL library: otherwise unused
*/

PCL_DESCR_TYPE *descr;
int counter_list[PCL_COUNTER_MAX];
int ncounter = 0;                  /* number of PCL counters */
PCL_CNT_TYPE *overhead_pcl;        /* overhead counter (cycles) */




/*
** t_initialize (): Initialization routine must be called from single-threaded
**   region before any other timing routines may be called.  The need for this
**   routine could be eliminated if not targetting timing library for threaded
**   capability. 
**
** return value: 0 (success) or -1 (failure)
*/

static int t_initialize ()
{
  int n;             /* index */
  int nbytes;        /* number of bytes for malloc */
  int ret;           /* return code */

/*
** Determine number of ticks per second for conversion use by other t_pr(), t_stamp()
*/

  if ((ticks_per_sec = sysconf (_SC_CLK_TCK)) == -1)
    return t_error ("t_initialize: token _SC_CLK_TCK is not defined\n");

#if ( ! defined DISABLE_TIMERS )

  if (t_initialized)
    return t_error ("t_initialize has already been called\n");

  /*
  ** Allocate space for global arrays
  */

#if ( defined THREADED_OMP )
  numthreads = omp_get_max_threads();
#elif ( defined THREADED_PTHREADS )
  numthreads = MAX_THREADS;
#endif
  
  nbytes = numthreads * sizeof (struct node *);
  if ((timers = (struct node **) malloc (nbytes)) == 0)
    return t_error ("malloc failure: %d items\n", numthreads);

  if ((last = (struct node **) malloc (nbytes)) == 0)
    return t_error ("malloc failure: %d items\n", numthreads);

  nbytes = numthreads * sizeof (float);
  if ((overhead = (float *) malloc (nbytes)) == 0)
    return t_error ("malloc failure: %d items\n", numthreads);

  nbytes = numthreads * sizeof (PCL_CNT_TYPE);
  if ((overhead_pcl = (PCL_CNT_TYPE *) malloc (nbytes)) == 0)
    return t_error ("malloc failure: %d items\n", numthreads);

  nbytes = numthreads * sizeof (int);
  if ((max_indent_level = (int *) malloc (nbytes)) == 0)
    return t_error ("malloc failure for %d items\n", numthreads);

  /*
  ** Initialize array values
  */

  for (n = 0; n < numthreads; n++) {
    timers[n] = 0;
    last[n] = 0;
    overhead[n] = 0.;
    overhead_pcl[n] = 0;
    max_indent_level[n] = 0;
  }



  if (get_thread_num () > 0) 
    return t_error ("t_initialize: should only be called by master thread\n");

  for (n = 0; n < npossible; n++) {
    if (possible_event[n].enabled) {
      if (possible_event[n].name == usrsys)
	usrsysenabled = true;

      if (possible_event[n].name == wall)
	wallenabled = true;

      if ((event = realloc (event, (nevent+1) * sizeof (struct Event *))) == NULL)
	return t_error ("realloc failure\n");

      if ((event[nevent] = malloc (sizeof (struct Event))) == NULL)
	return t_error ("realloc failure\n");

      event[nevent]->name = possible_event[n].name;
      strcpy (event[nevent]->string, possible_event[n].string);

#ifdef HAVE_PCL

      /*
      ** Set up PCL stuff based on what t_setoption has provided.
      */

      if (event[nevent]->name > pcl_start && event[nevent]->name < pcl_end) {
	pclenabled = true;
	event[nevent]->index = ncounter;

	switch (possible_event[n].name) {

	case pcl_l1dcache_miss:
	  counter_list[ncounter++] = PCL_L1DCACHE_MISS;
	  break;
	  
	case pcl_l2cache_miss: 
	  counter_list[ncounter++] = PCL_L2CACHE_MISS;
	  break;
	  
	case pcl_cycles: 
	  pcl_cyclesindex = ncounter;
	  pcl_cyclesenabled = true;
	  counter_list[ncounter++] = PCL_CYCLES;
	  break;

	case pcl_elapsed_cycles: 
	  counter_list[ncounter++] = PCL_ELAPSED_CYCLES;
	  break;

	case pcl_fp_instr: 
	  counter_list[ncounter++] = PCL_FP_INSTR;
	  break;

	case pcl_loadstore_instr: 
	  counter_list[ncounter++] = PCL_LOADSTORE_INSTR;
	  break;

	case pcl_instr: 
	  counter_list[ncounter++] = PCL_INSTR;
	  break;

	case pcl_stall: 
	  counter_list[ncounter++] = PCL_STALL;