opal/timing: remove old framework
Signed-off-by: Artem Polyakov <artpol84@gmail.com>
Этот коммит содержится в:
родитель
1063c0d567
Коммит
88ed79ea25
@ -272,34 +272,6 @@ int opal_register_params(void)
|
||||
true);
|
||||
}
|
||||
|
||||
#if OPAL_ENABLE_TIMING
|
||||
opal_timing_sync_file = NULL;
|
||||
(void) mca_base_var_register ("opal", "opal", NULL, "timing_sync_file",
|
||||
"Clock synchronisation information generated by mpisync tool. You don't need to touch this if you use mpirun_prof tool.",
|
||||
MCA_BASE_VAR_TYPE_STRING, NULL, 0, 0,
|
||||
OPAL_INFO_LVL_9, MCA_BASE_VAR_SCOPE_ALL,
|
||||
&opal_timing_sync_file);
|
||||
if( opal_timing_clocksync_read(opal_timing_sync_file) ){
|
||||
opal_output(0, "Cannot read file %s containing clock synchronisation information\n", opal_timing_sync_file);
|
||||
}
|
||||
|
||||
opal_timing_output = NULL;
|
||||
(void) mca_base_var_register ("opal", "opal", NULL, "timing_output",
|
||||
"The name of output file for timing information. If this parameter is not set then output will be directed into OPAL debug channel.",
|
||||
MCA_BASE_VAR_TYPE_STRING, NULL, 0, 0,
|
||||
OPAL_INFO_LVL_9, MCA_BASE_VAR_SCOPE_ALL,
|
||||
&opal_timing_output);
|
||||
|
||||
opal_timing_overhead = true;
|
||||
(void) mca_base_var_register ("opal", "opal", NULL, "timing_overhead",
|
||||
"Timing framework introduce additional overhead (malloc's mostly)."
|
||||
" The time spend in such costly routines is measured and may be accounted"
|
||||
" (subtracted from timestamps). 'true' means consider overhead, 'false' - ignore (default: true).",
|
||||
MCA_BASE_VAR_TYPE_BOOL, NULL, 0, 0,
|
||||
OPAL_INFO_LVL_9, MCA_BASE_VAR_SCOPE_ALL,
|
||||
&opal_timing_overhead);
|
||||
#endif
|
||||
|
||||
opal_warn_on_fork = true;
|
||||
(void) mca_base_var_register("ompi", "mpi", NULL, "warn_on_fork",
|
||||
"If nonzero, issue a warning if program forks under conditions that could cause system errors",
|
||||
|
@ -41,107 +41,7 @@
|
||||
|
||||
#include MCA_timer_IMPLEMENTATION_HEADER
|
||||
|
||||
#define DELTAS_SANE_LIMIT (10*1024*1024)
|
||||
|
||||
/*
|
||||
static void debug_hang(int i)
|
||||
{
|
||||
while( i ){
|
||||
sleep(1);
|
||||
}
|
||||
}
|
||||
*/
|
||||
|
||||
struct interval_descr{
|
||||
opal_timing_event_t *descr_ev, *begin_ev;
|
||||
double interval, overhead;
|
||||
};
|
||||
|
||||
static OBJ_CLASS_INSTANCE(opal_timing_event_t, opal_list_item_t, NULL, NULL);
|
||||
|
||||
|
||||
opal_mutex_t tm_lock;
|
||||
static char *nodename = NULL;
|
||||
static char *jobid = "";
|
||||
static double hnp_offs = 0;
|
||||
static double hnp_rtt = 0;
|
||||
|
||||
int opal_timing_clocksync_read(char *fname)
|
||||
{
|
||||
int rc = 0;
|
||||
FILE *fp = NULL;
|
||||
char *line = NULL;
|
||||
size_t n;
|
||||
bool found = false;
|
||||
char *ptr = NULL;
|
||||
|
||||
char hname[OPAL_MAXHOSTNAMELEN] = "NA";
|
||||
if( gethostname(hname, sizeof(hname)) ){
|
||||
opal_output(0, "opal_timing_clocksync_read(%s): Cannot gethostname",
|
||||
fname);
|
||||
}
|
||||
nodename = strdup(hname);
|
||||
// Strip domain name
|
||||
ptr = strchr(nodename,'.');
|
||||
if( ptr != NULL ){
|
||||
*ptr = '\0';
|
||||
}
|
||||
|
||||
if( fname == NULL ){
|
||||
return 0;
|
||||
}
|
||||
|
||||
fp = fopen(fname,"r");
|
||||
if( fp == NULL ){
|
||||
opal_output(0, "opal_timing_clocksync_read(%s): Cannot open the file",fname);
|
||||
return OPAL_ERROR;
|
||||
}
|
||||
|
||||
while( getline(&line,&n,fp) > 0 ){
|
||||
ptr = strchr(line,' ');
|
||||
if( ptr == NULL ){
|
||||
rc = -1;
|
||||
goto err_exit;
|
||||
}
|
||||
*ptr = '\0';
|
||||
ptr++;
|
||||
if( strcmp(line, hname) == 0 ){
|
||||
if( sscanf(ptr,"%lf %lf", &hnp_rtt, &hnp_offs) != 2 ){
|
||||
rc = -1;
|
||||
goto err_exit;
|
||||
}
|
||||
found = true;
|
||||
break;
|
||||
}
|
||||
}
|
||||
|
||||
if( !found ){
|
||||
opal_output(0,"opal_timing_clocksync_read: Can't find my host %s in %s", hname, fname);
|
||||
rc = OPAL_ERROR;
|
||||
}
|
||||
|
||||
err_exit:
|
||||
|
||||
if( line != NULL ){
|
||||
free(line);
|
||||
}
|
||||
|
||||
if( fp != NULL ){
|
||||
fclose(fp);
|
||||
}
|
||||
return rc;
|
||||
}
|
||||
|
||||
int opal_timing_set_jobid(char *jid)
|
||||
{
|
||||
jobid = strdup(jid);
|
||||
if( jobid == NULL ){
|
||||
return OPAL_ERROR;
|
||||
}
|
||||
return 0;
|
||||
}
|
||||
|
||||
/* Get current timestamp. Derived from MPI_Wtime */
|
||||
static opal_mutex_t tm_lock;
|
||||
|
||||
static double get_ts_gettimeofday(void)
|
||||
{
|
||||
@ -168,7 +68,7 @@ static double get_ts_usec(void)
|
||||
}
|
||||
#endif
|
||||
|
||||
static get_ts_t _init_timestamping(opal_timer_type_t type)
|
||||
opal_timing_ts_func_t opal_timing_ts_func(opal_timer_type_t type)
|
||||
{
|
||||
switch (type) {
|
||||
case OPAL_TIMING_GET_TIME_OF_DAY:
|
||||
@ -199,563 +99,3 @@ static get_ts_t _init_timestamping(opal_timer_type_t type)
|
||||
}
|
||||
}
|
||||
|
||||
static opal_timing_event_t *opal_timing_event_alloc(opal_timing_t *t)
|
||||
{
|
||||
if( t->buffer_offset >= t->buffer_size ){
|
||||
// notch timings overhead
|
||||
double alloc_begin = t->get_ts();
|
||||
|
||||
t->buffer = malloc(sizeof(opal_timing_event_t)*t->buffer_size);
|
||||
if( t->buffer == NULL ){
|
||||
return NULL;
|
||||
}
|
||||
memset(t->buffer, 0, sizeof(opal_timing_event_t)*t->buffer_size);
|
||||
|
||||
double alloc_end = t->get_ts();
|
||||
|
||||
t->buffer_offset = 0;
|
||||
t->buffer[0].fib = 1;
|
||||
t->buffer[0].ts_ovh = alloc_end - alloc_begin;
|
||||
}
|
||||
int tmp = t->buffer_offset;
|
||||
(t->buffer_offset)++;
|
||||
return t->buffer + tmp;
|
||||
}
|
||||
|
||||
int opal_timing_init(opal_timing_t *t, opal_timer_type_t type)
|
||||
{
|
||||
memset(t,0,sizeof(*t));
|
||||
|
||||
t->next_id_cntr = 0;
|
||||
t->current_id = -1;
|
||||
/* initialize events list */
|
||||
t->events = OBJ_NEW(opal_list_t);
|
||||
/* Set buffer size */
|
||||
t->buffer_size = OPAL_TIMING_BUFSIZE;
|
||||
/* Set buffer_offset = buffer_size so new buffer
|
||||
* will be allocated at first event report */
|
||||
t->buffer_offset = t->buffer_size;
|
||||
/* initialize gettime function */
|
||||
t->get_ts = _init_timestamping(type);
|
||||
if (NULL == t->get_ts) {
|
||||
return OPAL_ERR_BAD_PARAM;
|
||||
}
|
||||
return OPAL_SUCCESS;
|
||||
}
|
||||
|
||||
opal_timing_prep_t opal_timing_prep_ev(opal_timing_t *t, const char *fmt, ...)
|
||||
{
|
||||
opal_timing_event_t *ev = opal_timing_event_alloc(t);
|
||||
if( ev == NULL ){
|
||||
opal_timing_prep_t p = { t, NULL, OPAL_ERR_OUT_OF_RESOURCE };
|
||||
return p;
|
||||
}
|
||||
OBJ_CONSTRUCT(ev, opal_timing_event_t);
|
||||
ev->ts = t->get_ts();
|
||||
va_list args;
|
||||
va_start( args, fmt );
|
||||
vsnprintf(ev->descr, OPAL_TIMING_DESCR_MAX - 1, fmt, args);
|
||||
ev->descr[OPAL_TIMING_DESCR_MAX-1] = '\0';
|
||||
va_end( args );
|
||||
opal_timing_prep_t p = { t, ev, 0 };
|
||||
return p;
|
||||
}
|
||||
|
||||
opal_timing_prep_t opal_timing_prep_ev_end(opal_timing_t *t, const char *fmt, ...)
|
||||
{
|
||||
opal_timing_prep_t p = { t, NULL, 0 };
|
||||
|
||||
if( t->current_id >= 0 ){
|
||||
opal_timing_event_t *ev = opal_timing_event_alloc(t);
|
||||
if( ev == NULL ){
|
||||
opal_timing_prep_t p = { t, NULL, OPAL_ERR_OUT_OF_RESOURCE };
|
||||
return p;
|
||||
}
|
||||
OBJ_CONSTRUCT(ev, opal_timing_event_t);
|
||||
ev->ts = t->get_ts();
|
||||
p.ev = ev;
|
||||
}
|
||||
return p;
|
||||
}
|
||||
|
||||
void opal_timing_add_step(opal_timing_prep_t p,
|
||||
const char *func, const char *file, int line)
|
||||
{
|
||||
if( !p.errcode ) {
|
||||
p.ev->func = func;
|
||||
p.ev->file = file;
|
||||
p.ev->line = line;
|
||||
p.ev->type = OPAL_TIMING_TRACE;
|
||||
opal_list_append(p.t->events, (opal_list_item_t*)p.ev);
|
||||
}
|
||||
}
|
||||
|
||||
/* Add description of the interval */
|
||||
int opal_timing_descr(opal_timing_prep_t p,
|
||||
const char *func, const char *file, int line)
|
||||
{
|
||||
if( !p.errcode ){
|
||||
p.ev->func = func;
|
||||
p.ev->file = file;
|
||||
p.ev->line = line;
|
||||
p.ev->type = OPAL_TIMING_INTDESCR;
|
||||
p.ev->id = p.t->next_id_cntr;
|
||||
(p.t->next_id_cntr)++;
|
||||
opal_list_append(p.t->events, (opal_list_item_t*)p.ev);
|
||||
return p.ev->id;
|
||||
}
|
||||
return -1;
|
||||
}
|
||||
|
||||
void opal_timing_start_id(opal_timing_t *t, int id, const char *func, const char *file, int line)
|
||||
{
|
||||
/* No description is needed. If everything is OK
|
||||
* it'll be included in opal_timing_start_init */
|
||||
opal_timing_event_t *ev = opal_timing_event_alloc(t);
|
||||
if( ev == NULL ){
|
||||
return;
|
||||
}
|
||||
OBJ_CONSTRUCT(ev, opal_timing_event_t);
|
||||
|
||||
t->current_id = id;
|
||||
ev->ts = t->get_ts();
|
||||
ev->func = func;
|
||||
ev->file = file;
|
||||
ev->line = line;
|
||||
ev->type = OPAL_TIMING_INTBEGIN;
|
||||
ev->id = id;
|
||||
opal_list_append(t->events, (opal_list_item_t*)ev);
|
||||
}
|
||||
|
||||
void opal_timing_end(opal_timing_t *t, int id, const char *func, const char *file, int line )
|
||||
{
|
||||
/* No description is needed. If everything is OK
|
||||
* it'll be included in opal_timing_start_init */
|
||||
opal_timing_event_t *ev = opal_timing_event_alloc(t);
|
||||
if( ev == NULL ){
|
||||
return;
|
||||
}
|
||||
OBJ_CONSTRUCT(ev, opal_timing_event_t);
|
||||
|
||||
if( id < 0 ){
|
||||
ev->id = t->current_id;
|
||||
t->current_id = -1;
|
||||
} else {
|
||||
if( t->current_id == id ){
|
||||
t->current_id = -1;
|
||||
}
|
||||
ev->id = id;
|
||||
}
|
||||
ev->ts = t->get_ts();
|
||||
ev->func = func;
|
||||
ev->file = file;
|
||||
ev->line = line;
|
||||
ev->type = OPAL_TIMING_INTEND;
|
||||
opal_list_append(t->events, (opal_list_item_t*)ev);
|
||||
}
|
||||
|
||||
void opal_timing_end_prep(opal_timing_prep_t p,
|
||||
const char *func, const char *file, int line)
|
||||
{
|
||||
opal_timing_event_t *ev = p.ev;
|
||||
|
||||
if( !p.errcode && ( NULL != ev ) ){
|
||||
assert( p.t->current_id >=0 );
|
||||
ev->id = p.t->current_id;
|
||||
p.t->current_id = -1;
|
||||
ev->func = func;
|
||||
ev->file = file;
|
||||
ev->line = line;
|
||||
ev->type = OPAL_TIMING_INTEND;
|
||||
opal_list_append(p.t->events, (opal_list_item_t*)ev);
|
||||
}
|
||||
}
|
||||
|
||||
static int _prepare_descriptions(opal_timing_t *t, struct interval_descr **__descr)
|
||||
{
|
||||
struct interval_descr *descr;
|
||||
opal_timing_event_t *ev, *next;
|
||||
|
||||
if( t->next_id_cntr == 0 ){
|
||||
return 0;
|
||||
}
|
||||
|
||||
*__descr = malloc(sizeof(struct interval_descr) * t->next_id_cntr);
|
||||
descr = *__descr;
|
||||
memset(descr, 0, sizeof(struct interval_descr) * t->next_id_cntr);
|
||||
|
||||
OPAL_LIST_FOREACH_SAFE(ev, next, t->events, opal_timing_event_t){
|
||||
|
||||
/* opal_output(0,"EVENT: type = %d, id=%d, ts = %.12le, ovh = %.12le %s",
|
||||
ev->type, ev->id, ev->ts, ev->ts_ovh,
|
||||
ev->descr );
|
||||
*/
|
||||
switch(ev->type){
|
||||
case OPAL_TIMING_INTDESCR:{
|
||||
if( ev->id >= t->next_id_cntr){
|
||||
char *file = opal_basename(ev->file);
|
||||
opal_output(0,"opal_timing: bad event id at %s:%d:%s, ignore and remove",
|
||||
file, ev->line, ev->func);
|
||||
free(file);
|
||||
opal_list_remove_item(t->events, (opal_list_item_t *)ev);
|
||||
continue;
|
||||
}
|
||||
if( NULL != descr[ev->id].descr_ev ){
|
||||
opal_timing_event_t *prev = descr[ev->id].descr_ev;
|
||||
char *file = opal_basename(ev->file);
|
||||
char *file_prev = opal_basename(prev->file);
|
||||
opal_output(0,"opal_timing: duplicated description at %s:%d:%s, "
|
||||
"previous: %s:%d:%s, ignore and remove", file, ev->line, ev->func,
|
||||
file_prev, prev->line, prev->func);
|
||||
free(file);
|
||||
free(file_prev);
|
||||
opal_list_remove_item(t->events, (opal_list_item_t *)ev);
|
||||
continue;
|
||||
}
|
||||
|
||||
descr[ev->id].descr_ev = ev;
|
||||
descr[ev->id].begin_ev = NULL;
|
||||
descr[ev->id].interval = 0;
|
||||
descr[ev->id].overhead = 0;
|
||||
break;
|
||||
}
|
||||
case OPAL_TIMING_INTBEGIN:
|
||||
case OPAL_TIMING_INTEND:{
|
||||
if( ev->id >= t->next_id_cntr || (NULL == descr[ev->id].descr_ev ) ){
|
||||
char *file = opal_basename(ev->file);
|
||||
opal_output(0,"opal_timing: bad event id at %s:%d:%s, ignore and remove",
|
||||
file, ev->line, ev->func);
|
||||
free(file);
|
||||
opal_list_remove_item(t->events, (opal_list_item_t *)ev);
|
||||
continue;
|
||||
}
|
||||
break;
|
||||
}
|
||||
case OPAL_TIMING_TRACE:
|
||||
break;
|
||||
}
|
||||
}
|
||||
return t->next_id_cntr;
|
||||
}
|
||||
|
||||
/* Output lines in portions that doesn't
|
||||
* exceed OPAL_TIMING_OUTBUF_SIZE for later automatic processing */
|
||||
int opal_timing_report(opal_timing_t *t, char *fname)
|
||||
{
|
||||
opal_timing_event_t *ev;
|
||||
FILE *fp = NULL;
|
||||
char *buf = NULL;
|
||||
int buf_size = 0;
|
||||
struct interval_descr *descr = NULL;
|
||||
int rc = OPAL_SUCCESS;
|
||||
|
||||
if( fname != NULL ){
|
||||
fp = fopen(fname,"a");
|
||||
if( fp == NULL ){
|
||||
opal_output(0, "opal_timing_report: Cannot open %s file"
|
||||
" for writing timing information!",fname);
|
||||
rc = OPAL_ERROR;
|
||||
goto err_exit;
|
||||
}
|
||||
}
|
||||
|
||||
_prepare_descriptions(t, &descr);
|
||||
|
||||
buf = malloc(OPAL_TIMING_OUTBUF_SIZE+1);
|
||||
if( buf == NULL ){
|
||||
rc = OPAL_ERR_OUT_OF_RESOURCE;
|
||||
goto err_exit;
|
||||
}
|
||||
buf[0] = '\0';
|
||||
|
||||
double overhead = 0;
|
||||
OPAL_LIST_FOREACH(ev, t->events, opal_timing_event_t){
|
||||
char *line, *file;
|
||||
if( ev->fib && opal_timing_overhead ){
|
||||
overhead += ev->ts_ovh;
|
||||
}
|
||||
file = opal_basename(ev->file);
|
||||
switch( ev->type ){
|
||||
case OPAL_TIMING_INTDESCR:
|
||||
// Service event, skip it.
|
||||
continue;
|
||||
case OPAL_TIMING_TRACE:
|
||||
rc = asprintf(&line,"[%s:%d] %s \"%s\" [OPAL_TRACE] %s:%d %.10lf\n",
|
||||
nodename, getpid(), jobid, ev->descr, file, ev->line,
|
||||
ev->ts + hnp_offs + overhead);
|
||||
break;
|
||||
case OPAL_TIMING_INTBEGIN:
|
||||
rc = asprintf(&line,"[%s:%d] %s \"%s [start]\" [OPAL_TRACE] %s:%d %.10lf\n",
|
||||
nodename, getpid(), jobid, descr[ev->id].descr_ev->descr,
|
||||
file, ev->line, ev->ts + hnp_offs + overhead);
|
||||
break;
|
||||
case OPAL_TIMING_INTEND:
|
||||
rc = asprintf(&line,"[%s:%d] %s \"%s [stop]\" [OPAL_TRACE] %s:%d %.10lf\n",
|
||||
nodename, getpid(), jobid, descr[ev->id].descr_ev->descr,
|
||||
file, ev->line, ev->ts + hnp_offs + overhead);
|
||||
break;
|
||||
}
|
||||
free(file);
|
||||
|
||||
if( rc < 0 ){
|
||||
rc = OPAL_ERR_OUT_OF_RESOURCE;
|
||||
goto err_exit;
|
||||
}
|
||||
rc = 0;
|
||||
|
||||
/* Sanity check: this shouldn't happen since description
|
||||
* is event only 1KB long and other fields should never
|
||||
* exceed 9KB */
|
||||
assert( strlen(line) <= OPAL_TIMING_OUTBUF_SIZE );
|
||||
|
||||
|
||||
if( buf_size + strlen(line) > OPAL_TIMING_OUTBUF_SIZE ){
|
||||
// flush buffer to the file
|
||||
if( fp != NULL ){
|
||||
fprintf(fp,"%s", buf);
|
||||
fprintf(fp,"\n");
|
||||
} else {
|
||||
opal_output(0,"\n%s", buf);
|
||||
}
|
||||
buf[0] = '\0';
|
||||
buf_size = 0;
|
||||
}
|
||||
sprintf(buf,"%s%s", buf, line);
|
||||
buf_size += strlen(line);
|
||||
free(line);
|
||||
}
|
||||
|
||||
if( buf_size > 0 ){
|
||||
// flush buffer to the file
|
||||
if( fp != NULL ){
|
||||
fprintf(fp,"%s", buf);
|
||||
fprintf(fp,"\n");
|
||||
} else {
|
||||
opal_output(0,"\n%s", buf);
|
||||
}
|
||||
buf[0] = '\0';
|
||||
buf_size = 0;
|
||||
}
|
||||
|
||||
err_exit:
|
||||
if( NULL != descr ){
|
||||
free(descr);
|
||||
}
|
||||
if( buf != NULL ){
|
||||
free(buf);
|
||||
}
|
||||
if( fp != NULL ){
|
||||
fflush(fp);
|
||||
fclose(fp);
|
||||
}
|
||||
return rc;
|
||||
}
|
||||
|
||||
/* Output events as one buffer so the data won't be mixed
|
||||
* with other output. This function is supposed to be human readable.
|
||||
* The output goes only to stdout. */
|
||||
int opal_timing_deltas(opal_timing_t *t, char *fname)
|
||||
{
|
||||
opal_timing_event_t *ev;
|
||||
FILE *fp = NULL;
|
||||
char *buf = NULL;
|
||||
struct interval_descr *descr = NULL;
|
||||
int i, rc = OPAL_SUCCESS;
|
||||
size_t buf_size = 0, buf_used = 0;
|
||||
|
||||
if( fname != NULL ){
|
||||
fp = fopen(fname,"a");
|
||||
if( fp == NULL ){
|
||||
opal_output(0, "opal_timing_report: Cannot open %s file"
|
||||
" for writing timing information!",fname);
|
||||
rc = OPAL_ERROR;
|
||||
goto err_exit;
|
||||
}
|
||||
}
|
||||
|
||||
_prepare_descriptions(t, &descr);
|
||||
|
||||
OPAL_LIST_FOREACH(ev, t->events, opal_timing_event_t){
|
||||
int id;
|
||||
if( ev->fib ){
|
||||
/* this event caused buffered memory allocation
|
||||
* for events. Account the overhead for all active
|
||||
* intervals. */
|
||||
int i;
|
||||
for( i = 0; i < t->next_id_cntr; i++){
|
||||
if( (NULL != descr[i].descr_ev) && (NULL != descr[i].begin_ev) ){
|
||||
if( opal_timing_overhead ){
|
||||
descr[i].overhead += ev->ts_ovh;
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
/* we already process all OPAL_TIMING_DESCR events
|
||||
* and we ignore OPAL_TIMING_EVENT */
|
||||
if( ev->type == OPAL_TIMING_INTDESCR ||
|
||||
ev->type == OPAL_TIMING_TRACE){
|
||||
/* skip */
|
||||
continue;
|
||||
}
|
||||
|
||||
id = ev->id;
|
||||
if( id < 0 || id >= t->next_id_cntr ){
|
||||
char *file = opal_basename(ev->file);
|
||||
opal_output(0,"opal_timing_deltas: bad interval event id: %d at %s:%d:%s (maxid=%d)",
|
||||
id, file, ev->line, ev->func, t->next_id_cntr - 1 );
|
||||
free(file);
|
||||
/* skip */
|
||||
continue;
|
||||
}
|
||||
|
||||
/* id's assigned auomatically. Ther shouldn't be any gaps in descr[] */
|
||||
assert( NULL != descr[id].descr_ev);
|
||||
|
||||
if( ev->type == OPAL_TIMING_INTBEGIN ){
|
||||
if( NULL != descr[id].begin_ev ){
|
||||
/* the measurement on this interval was already
|
||||
* started! */
|
||||
opal_timing_event_t *prev = descr[ev->id].begin_ev;
|
||||
char *file = opal_basename(ev->file);
|
||||
char *file_prev = opal_basename(prev->file);
|
||||
opal_output(0,"opal_timing_deltas: duplicated start statement at %s:%d:%s, "
|
||||
"previous: %s:%d:%s", file, ev->line, ev->func,
|
||||
file_prev, prev->line, prev->func);
|
||||
free(file);
|
||||
free(file_prev);
|
||||
} else {
|
||||
/* save pointer to the start of measurement event */
|
||||
descr[id].begin_ev = ev;
|
||||
}
|
||||
/* done, go to the next event */
|
||||
continue;
|
||||
}
|
||||
|
||||
if( ev->type == OPAL_TIMING_INTEND ){
|
||||
if( NULL == descr[id].begin_ev ){
|
||||
/* the measurement on this interval wasn't started! */
|
||||
char *file = opal_basename(ev->file);
|
||||
opal_output(0,"opal_timing_deltas: inteval end without start at %s:%d:%s",
|
||||
file, ev->line, ev->func );
|
||||
free(file);
|
||||
} else {
|
||||
descr[id].interval += ev->ts - descr[id].begin_ev->ts;
|
||||
descr[id].begin_ev = NULL;
|
||||
if( ev->fib ){
|
||||
descr[id].overhead += ev->ts_ovh;
|
||||
}
|
||||
}
|
||||
continue;
|
||||
}
|
||||
|
||||
/* shouldn't ever get here: bad ev->type */
|
||||
opal_output(0, "opal_timing_deltas: bad event type %d", ev->type);
|
||||
assert(0);
|
||||
}
|
||||
|
||||
buf = malloc(OPAL_TIMING_OUTBUF_SIZE + 1);
|
||||
if( buf == NULL ){
|
||||
rc = OPAL_ERR_OUT_OF_RESOURCE;
|
||||
goto err_exit;
|
||||
}
|
||||
buf[0] = '\0';
|
||||
buf_size = OPAL_TIMING_OUTBUF_SIZE + 1;
|
||||
buf_used = 0;
|
||||
for(i = 0; i < t->next_id_cntr; i++){
|
||||
char *line = NULL;
|
||||
size_t line_size;
|
||||
rc = asprintf(&line,"[%s:%d] %s \"%s\" [OPAL_OVHD] %le\n",
|
||||
nodename, getpid(), jobid, descr[i].descr_ev->descr,
|
||||
descr[i].interval - descr[i].overhead);
|
||||
if( rc < 0 ){
|
||||
rc = OPAL_ERR_OUT_OF_RESOURCE;
|
||||
goto err_exit;
|
||||
}
|
||||
rc = 0;
|
||||
line_size = strlen(line);
|
||||
|
||||
/* Sanity check: this shouldn't happen since description
|
||||
* is event only 1KB long and other fields should never
|
||||
* exceed 9KB */
|
||||
assert( line_size <= OPAL_TIMING_OUTBUF_SIZE );
|
||||
|
||||
if( buf_used + strlen(line) > buf_size ){
|
||||
// Increase output buffer
|
||||
while( buf_used + line_size > buf_size && buf_size < DELTAS_SANE_LIMIT){
|
||||
buf_size += OPAL_TIMING_OUTBUF_SIZE + 1;
|
||||
}
|
||||
if( buf_size > DELTAS_SANE_LIMIT ){
|
||||
opal_output(0, "opal_timing_report: delta sane limit overflow (%u > %u)!\n",
|
||||
(unsigned int)buf_size, DELTAS_SANE_LIMIT);
|
||||
free(line);
|
||||
rc = OPAL_ERR_OUT_OF_RESOURCE;
|
||||
goto err_exit;
|
||||
}
|
||||
buf = realloc(buf, buf_size);
|
||||
if( buf == NULL ){
|
||||
opal_output(0, "opal_timing_deltas: Out of memory!\n");
|
||||
rc = OPAL_ERR_OUT_OF_RESOURCE;
|
||||
goto err_exit;
|
||||
}
|
||||
}
|
||||
sprintf(buf,"%s%s", buf, line);
|
||||
buf_used += line_size;
|
||||
free(line);
|
||||
}
|
||||
|
||||
|
||||
if( buf_used > 0 ){
|
||||
// flush buffer to the file
|
||||
if( fp != NULL ){
|
||||
fprintf(fp,"%s", buf);
|
||||
fprintf(fp,"\n");
|
||||
} else {
|
||||
opal_output(0,"\n%s", buf);
|
||||
}
|
||||
buf[0] = '\0';
|
||||
buf_size = 0;
|
||||
}
|
||||
|
||||
err_exit:
|
||||
if( NULL != descr ){
|
||||
free(descr);
|
||||
}
|
||||
if( NULL != buf ){
|
||||
free(buf);
|
||||
}
|
||||
if( fp != NULL ){
|
||||
fflush(fp);
|
||||
fclose(fp);
|
||||
}
|
||||
return rc;
|
||||
}
|
||||
|
||||
void opal_timing_release(opal_timing_t *t)
|
||||
{
|
||||
int cnt = opal_list_get_size(t->events);
|
||||
|
||||
if( cnt > 0 ){
|
||||
opal_list_t *tmp = OBJ_NEW(opal_list_t);
|
||||
int i;
|
||||
for(i=0; i<cnt; i++){
|
||||
opal_timing_event_t *ev = (opal_timing_event_t *)opal_list_remove_first(t->events);
|
||||
if( ev->fib ){
|
||||
opal_list_append(tmp,(opal_list_item_t*)ev);
|
||||
}
|
||||
}
|
||||
|
||||
cnt = opal_list_get_size(tmp);
|
||||
for(i=0; i<cnt; i++){
|
||||
opal_timing_event_t *ev = (opal_timing_event_t *)opal_list_remove_first(tmp);
|
||||
free(ev);
|
||||
}
|
||||
OBJ_RELEASE(tmp);
|
||||
} else {
|
||||
// Error case. At list one event was inserted at initialization.
|
||||
|
||||
}
|
||||
|
||||
OBJ_RELEASE(t->events);
|
||||
t->events = NULL;
|
||||
}
|
||||
|
@ -25,426 +25,7 @@ typedef enum {
|
||||
|
||||
#if OPAL_ENABLE_TIMING
|
||||
|
||||
#define OPAL_TIMING_DESCR_MAX 1024
|
||||
#define OPAL_TIMING_BUFSIZE 32
|
||||
#define OPAL_TIMING_OUTBUF_SIZE (10*1024)
|
||||
|
||||
typedef enum {
|
||||
OPAL_TIMING_TRACE,
|
||||
OPAL_TIMING_INTDESCR,
|
||||
OPAL_TIMING_INTBEGIN,
|
||||
OPAL_TIMING_INTEND
|
||||
} opal_event_type_t;
|
||||
|
||||
typedef struct {
|
||||
opal_list_item_t super;
|
||||
int fib;
|
||||
opal_event_type_t type;
|
||||
const char *func;
|
||||
const char *file;
|
||||
int line;
|
||||
double ts, ts_ovh;
|
||||
char descr[OPAL_TIMING_DESCR_MAX];
|
||||
int id;
|
||||
} opal_timing_event_t;
|
||||
|
||||
typedef double (*get_ts_t)(void);
|
||||
|
||||
typedef struct opal_timing_t
|
||||
{
|
||||
int next_id_cntr;
|
||||
// not thread safe!
|
||||
// The whole implementation is not thread safe now
|
||||
// since it is supposed to be used in orte service
|
||||
// thread only. Fix in the future or now?
|
||||
int current_id;
|
||||
opal_list_t *events;
|
||||
opal_timing_event_t *buffer;
|
||||
size_t buffer_offset, buffer_size;
|
||||
get_ts_t get_ts;
|
||||
} opal_timing_t;
|
||||
|
||||
typedef struct {
|
||||
opal_timing_t *t;
|
||||
opal_timing_event_t *ev;
|
||||
int errcode;
|
||||
} opal_timing_prep_t;
|
||||
|
||||
/**
|
||||
* Read synchronisation information from the file
|
||||
* provided through the MCA parameter.
|
||||
* Should not be directly used, for service purposes.
|
||||
*
|
||||
* @param sync_file Name of the file to read
|
||||
*
|
||||
* @retval OPAL_SUCCESS On success
|
||||
* @retval OPAL_ERROR On failure
|
||||
*/
|
||||
int opal_timing_clocksync_read(char *sync_file);
|
||||
|
||||
/**
|
||||
* Pass string representation of ORTE job ID down to the OPAL.
|
||||
* Should not be directly used, for service purposes.
|
||||
*
|
||||
* @param jid job id
|
||||
*
|
||||
* @retval OPAL_SUCCESS On success
|
||||
* @retval OPAL_ERROR On failure
|
||||
*/
|
||||
int opal_timing_set_jobid(char *jid);
|
||||
|
||||
/**
|
||||
* Initialize timing structure.
|
||||
*
|
||||
* @param t pointer to the timing handler structure
|
||||
*
|
||||
* @retval OPAL_SUCCESS On success
|
||||
* @retval OPAL_ERROR On failure
|
||||
*/
|
||||
int opal_timing_init(opal_timing_t *t, opal_timer_type_t type);
|
||||
|
||||
/**
|
||||
* Prepare timing event, do all printf-like processing.
|
||||
* Should not be directly used - for service purposes only.
|
||||
*
|
||||
* @param t pointer to the timing handler structure
|
||||
* @param fmt printf-like format
|
||||
* @param ... other parameters that should be converted to string representation
|
||||
*
|
||||
* @retval partly filled opal_timing_prep_t structure
|
||||
*/
|
||||
opal_timing_prep_t opal_timing_prep_ev(opal_timing_t *t, const char *fmt, ...);
|
||||
|
||||
/**
|
||||
* Prepare timing event, ignore printf-like processing.
|
||||
* Should not be directly used - for service purposes only.
|
||||
*
|
||||
* @param t pointer to the timing handler structure
|
||||
* @param fmt printf-like format
|
||||
* @param ... other parameters that should be converted to string representation
|
||||
*
|
||||
* @retval partly filled opal_timing_prep_t structure
|
||||
*/
|
||||
opal_timing_prep_t opal_timing_prep_ev_end(opal_timing_t *t, const char *fmt, ...);
|
||||
|
||||
/**
|
||||
* Enqueue timing event into the list of events in handler 't'.
|
||||
*
|
||||
* @param p result of opal_timing_prep_ev
|
||||
* @param func function name where event occurs
|
||||
* @param file file name where event occurs
|
||||
* @param line line number in the file
|
||||
*
|
||||
* @retval
|
||||
*/
|
||||
void opal_timing_add_step(opal_timing_prep_t p, const char *func,
|
||||
const char *file, int line);
|
||||
|
||||
/**
|
||||
* Enqueue the description of the interval into a list of events
|
||||
* in handler 't'.
|
||||
*
|
||||
* @param p result of opal_timing_prep_ev
|
||||
* @param func function name where event occurs
|
||||
* @param file file name where event occurs
|
||||
* @param line line number in the file
|
||||
*
|
||||
* @retval id of event interval
|
||||
*/
|
||||
int opal_timing_descr(opal_timing_prep_t p, const char *func,
|
||||
const char *file, int line);
|
||||
|
||||
/**
|
||||
* Enqueue the beginning of timing interval that already has the
|
||||
* description and assigned id into the list of events
|
||||
* in handler 't'.
|
||||
*
|
||||
* @param p result of opal_timing_prep_ev
|
||||
* @param func function name where event occurs
|
||||
* @param file file name where event occurs
|
||||
* @param line line number in the file
|
||||
*
|
||||
* @retval
|
||||
*/
|
||||
void opal_timing_start_id(opal_timing_t *t, int id, const char *func,
|
||||
const char *file, int line);
|
||||
|
||||
/**
|
||||
* Enqueue the end of timing interval that already has
|
||||
* description and assigned id into the list of events
|
||||
* in handler 't'.
|
||||
*
|
||||
* @param p result of opal_timing_prep_ev
|
||||
* @param func function name where event occurs
|
||||
* @param file file name where event occurs
|
||||
* @param line line number in the file
|
||||
*
|
||||
* @retval
|
||||
*/
|
||||
void opal_timing_end(opal_timing_t *t, int id, const char *func,
|
||||
const char *file, int line );
|
||||
|
||||
/**
|
||||
* Enqueue both description and start of timing interval
|
||||
* into the list of events and assign its id.
|
||||
*
|
||||
* @param p result of opal_timing_prep_ev
|
||||
* @param func function name where event occurs
|
||||
* @param file file name where event occurs
|
||||
* @param line line number in the file
|
||||
*
|
||||
* @retval interval id
|
||||
*/
|
||||
static inline int opal_timing_start_init(opal_timing_prep_t p,
|
||||
const char *func, const char *file, int line)
|
||||
{
|
||||
int id = opal_timing_descr(p, func, file, line);
|
||||
if( id < 0 )
|
||||
return id;
|
||||
opal_timing_start_id(p.t, id, func, file, line);
|
||||
return id;
|
||||
}
|
||||
|
||||
/**
|
||||
* The wrapper that is used to stop last measurement in OPAL_TIMING_MNEXT.
|
||||
*
|
||||
* @param p result of opal_timing_prep_ev
|
||||
* @param func function name where event occurs
|
||||
* @param file file name where event occurs
|
||||
* @param line line number in the file
|
||||
*
|
||||
* @retval interval id
|
||||
*/
|
||||
void opal_timing_end_prep(opal_timing_prep_t p,
|
||||
const char *func, const char *file, int line);
|
||||
|
||||
/**
|
||||
* Report all events that were enqueued in the timing handler 't'.
|
||||
* - if fname == NULL the output will be done using opal_output and
|
||||
* each line will be prefixed with "prefix" to ease grep'ing.
|
||||
* - otherwise the corresponding file will be used for output in "append" mode
|
||||
* WARRNING: not all filesystems provide enough support for that feature, some records may
|
||||
* disappear.
|
||||
*
|
||||
* @param t timing handler
|
||||
* @param account_overhead consider malloc overhead introduced by timing code
|
||||
* @param prefix prefix to use when no fname was specifyed to ease grep'ing
|
||||
* @param fname name of the output file (may be NULL)
|
||||
*
|
||||
* @retval OPAL_SUCCESS On success
|
||||
* @retval OPAL_ERROR or OPAL_ERR_OUT_OF_RESOURCE On failure
|
||||
*/
|
||||
int opal_timing_report(opal_timing_t *t, char *fname);
|
||||
|
||||
/**
|
||||
* Report all intervals that were enqueued in the timing handler 't'.
|
||||
* - if fname == NULL the output will be done using opal_output and
|
||||
* each line will be prefixed with "prefix" to ease grep'ing.
|
||||
* - otherwise the corresponding file will be used for output in "append" mode
|
||||
* WARRNING: not all filesystems provide enough support for that feature, some records may
|
||||
* disappear.
|
||||
*
|
||||
* @param t timing handler
|
||||
* @param account_overhead consider malloc overhead introduced by timing code
|
||||
* @param fname name of the output file (may be NULL)
|
||||
*
|
||||
* @retval OPAL_SUCCESS On success
|
||||
* @retval OPAL_ERROR or OPAL_ERR_OUT_OF_RESOURCE On failure
|
||||
*/
|
||||
int opal_timing_deltas(opal_timing_t *t, char *fname);
|
||||
|
||||
/**
|
||||
* Release all memory allocated for the timing handler 't'.
|
||||
*
|
||||
* @param t timing handler
|
||||
*
|
||||
* @retval
|
||||
*/
|
||||
void opal_timing_release(opal_timing_t *t);
|
||||
|
||||
/**
|
||||
* Main macro for use in declaring opal timing handler;
|
||||
* will be "compiled out" when OPAL is configured without
|
||||
* --enable-timing.
|
||||
*
|
||||
*/
|
||||
#define OPAL_TIMING_DECLARE(t) opal_timing_t t; /* need semicolon here to avoid warnings when not enabled */
|
||||
|
||||
/**
|
||||
* Main macro for use in declaring external opal timing handler;
|
||||
* will be "compiled out" when OPAL is configured without
|
||||
* --enable-timing.
|
||||
*
|
||||
*/
|
||||
#define OPAL_TIMING_DECLARE_EXT(x, t) x extern opal_timing_t t; /* need semicolon here to avoid warnings when not enabled */
|
||||
|
||||
/**
|
||||
* Main macro for use in initializing opal timing handler;
|
||||
* will be "compiled out" when OPAL is configured without
|
||||
* --enable-timing.
|
||||
*
|
||||
* @see opal_timing_init()
|
||||
*/
|
||||
#define OPAL_TIMING_INIT(t) opal_timing_init(t, OPAL_TIMING_AUTOMATIC_TIMER)
|
||||
|
||||
/**
|
||||
* Main macro for use in initializing opal timing handler;
|
||||
* will be "compiled out" when OPAL is configured without
|
||||
* --enable-timing.
|
||||
*
|
||||
* @see opal_timing_init()
|
||||
*/
|
||||
#define OPAL_TIMING_INIT_EXT(t, type) opal_timing_init(t, type)
|
||||
|
||||
/**
|
||||
* Macro that enqueues event with its description to the specified
|
||||
* timing handler;
|
||||
* will be "compiled out" when OPAL is configured without
|
||||
* --enable-timing.
|
||||
*
|
||||
* @see opal_timing_add_step()
|
||||
*/
|
||||
#define OPAL_TIMING_EVENT(x) opal_timing_add_step( opal_timing_prep_ev x, __FUNCTION__, __FILE__, __LINE__)
|
||||
|
||||
/**
|
||||
* MDESCR: Measurement DESCRiption
|
||||
* Introduce new timing measurement with string description for the specified
|
||||
* timing handler;
|
||||
* will be "compiled out" when OPAL is configured without
|
||||
* --enable-timing.
|
||||
*
|
||||
* @see opal_timing_descr()
|
||||
*/
|
||||
#define OPAL_TIMING_MDESCR(x) opal_timing_descr( opal_timing_prep_ev x, __FUNCTION__, __FILE__, __LINE__)
|
||||
|
||||
/**
|
||||
* MSTART_ID: Measurement START by ID.
|
||||
* Marks the beginning of the measurement with ID=id on the
|
||||
* specified timing handler;
|
||||
* will be "compiled out" when OPAL is configured without
|
||||
* --enable-timing.
|
||||
*
|
||||
* @see opal_timing_start_id()
|
||||
*/
|
||||
#define OPAL_TIMING_MSTART_ID(t, id) opal_timing_start_id(t, id, __FUNCTION__, __FILE__, __LINE__)
|
||||
|
||||
/**
|
||||
* MSTART: Measurement START
|
||||
* Introduce new timing measurement conjuncted with its start
|
||||
* on the specifyed timing handler;
|
||||
* will be "compiled out" when OPAL is configured without
|
||||
* --enable-timing.
|
||||
*
|
||||
* @see opal_timing_start_init()
|
||||
*/
|
||||
#define OPAL_TIMING_MSTART(x) opal_timing_start_init( opal_timing_prep_ev x, __FUNCTION__, __FILE__, __LINE__)
|
||||
|
||||
/**
|
||||
* MSTOP: STOP Measurement
|
||||
* Finishes the most recent measurement on the specifyed timing handler;
|
||||
* will be "compiled out" when OPAL is configured without
|
||||
* --enable-timing.
|
||||
*
|
||||
* @see opal_timing_end()
|
||||
*/
|
||||
#define OPAL_TIMING_MSTOP(t) opal_timing_end(t, -1, __FUNCTION__, __FILE__, __LINE__)
|
||||
|
||||
/**
|
||||
* MSTOP_ID: STOP Measurement with ID=id.
|
||||
* Finishes the measurement with give ID on the specifyed timing handler;
|
||||
* will be "compiled out" when OPAL is configured without
|
||||
* --enable-timing.
|
||||
*
|
||||
* @see opal_timing_end()
|
||||
*/
|
||||
#define OPAL_TIMING_MSTOP_ID(t, id) opal_timing_end(t, id, __FUNCTION__, __FILE__, __LINE__)
|
||||
|
||||
/**
|
||||
* MNEXT: start NEXT Measurement
|
||||
* Convinient macro, may be implemented with the sequence of three previously
|
||||
* defined macroses:
|
||||
* - finish current measurement (OPAL_TIMING_MSTOP);
|
||||
* - introduce new timing measurement (OPAL_TIMING_MDESCR);
|
||||
* - starts next measurement (OPAL_TIMING_MSTART_ID)
|
||||
* on the specifyed timing handler;
|
||||
* will be "compiled out" when OPAL is configured without
|
||||
* --enable-timing.
|
||||
*
|
||||
* @see opal_timing_start_init()
|
||||
*/
|
||||
#define OPAL_TIMING_MNEXT(x) ( \
|
||||
opal_timing_end_prep(opal_timing_prep_ev_end x, \
|
||||
__FUNCTION__, __FILE__, __LINE__ ), \
|
||||
opal_timing_start_init( opal_timing_prep_ev x, \
|
||||
__FUNCTION__, __FILE__, __LINE__) \
|
||||
)
|
||||
|
||||
/**
|
||||
* The macro for use in reporting collected events with absolute values;
|
||||
* will be "compiled out" when OPAL is configured without
|
||||
* --enable-timing.
|
||||
*
|
||||
* @param enable flag that enables/disables reporting. Used for fine-grained timing.
|
||||
* @see opal_timing_report()
|
||||
*/
|
||||
#define OPAL_TIMING_REPORT(enable, t) { \
|
||||
if( enable ) { \
|
||||
opal_timing_report(t, opal_timing_output); \
|
||||
} \
|
||||
}
|
||||
|
||||
/**
|
||||
* The macro for use in reporting collected events with relative times;
|
||||
* will be "compiled out" when OPAL is configured without
|
||||
* --enable-timing.
|
||||
*
|
||||
* @param enable flag that enables/disables reporting. Used for fine-grained timing.
|
||||
* @see opal_timing_deltas()
|
||||
*/
|
||||
#define OPAL_TIMING_DELTAS(enable, t) { \
|
||||
if( enable ) { \
|
||||
opal_timing_deltas(t, opal_timing_output); \
|
||||
} \
|
||||
}
|
||||
|
||||
/**
|
||||
* Main macro for use in releasing allocated resources;
|
||||
* will be "compiled out" when OPAL is configured without
|
||||
* --enable-timing.
|
||||
*
|
||||
* @see opal_timing_release()
|
||||
*/
|
||||
#define OPAL_TIMING_RELEASE(t) opal_timing_release(t)
|
||||
|
||||
#else
|
||||
|
||||
#define OPAL_TIMING_DECLARE(t)
|
||||
|
||||
#define OPAL_TIMING_DECLARE_EXT(x, t)
|
||||
|
||||
#define OPAL_TIMING_INIT(t)
|
||||
|
||||
#define OPAL_TIMING_INIT_EXT(t, type)
|
||||
|
||||
#define OPAL_TIMING_EVENT(x)
|
||||
|
||||
#define OPAL_TIMING_MDESCR(x)
|
||||
|
||||
#define OPAL_TIMING_MSTART_ID(t, id)
|
||||
|
||||
#define OPAL_TIMING_MSTART(x)
|
||||
|
||||
#define OPAL_TIMING_MSTOP(t)
|
||||
|
||||
#define OPAL_TIMING_MSTOP_ID(t, id)
|
||||
|
||||
#define OPAL_TIMING_MNEXT(x)
|
||||
|
||||
#define OPAL_TIMING_REPORT(enable, t)
|
||||
|
||||
#define OPAL_TIMING_DELTAS(enable, t)
|
||||
|
||||
#define OPAL_TIMING_RELEASE(t)
|
||||
typedef double (*opal_timing_ts_func_t)(void);
|
||||
|
||||
#endif
|
||||
|
||||
|
@ -255,10 +255,6 @@ int orte_init(int* pargc, char*** pargv, orte_proc_type_t flags)
|
||||
opal_process_info.my_local_rank = (int32_t)orte_process_info.my_local_rank;
|
||||
opal_process_info.cpuset = orte_process_info.cpuset;
|
||||
|
||||
#if OPAL_ENABLE_TIMING
|
||||
opal_timing_set_jobid(ORTE_NAME_PRINT(ORTE_PROC_MY_NAME));
|
||||
#endif
|
||||
|
||||
if (ORTE_PROC_IS_HNP || ORTE_PROC_IS_DAEMON) {
|
||||
/* start listening - will be ignored if no listeners
|
||||
* were registered */
|
||||
|
Загрузка…
x
Ссылка в новой задаче
Block a user