Skip to content

timings: added new timing points #4933

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
Mar 25, 2018
Merged

timings: added new timing points #4933

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
19 changes: 14 additions & 5 deletions ompi/runtime/ompi_mpi_init.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -20,7 +20,7 @@
* Copyright (c) 2014-2017 Intel, Inc. All rights reserved.
* Copyright (c) 2014-2016 Research Organization for Information Science
* and Technology (RIST). All rights reserved.
* Copyright (c) 2016 Mellanox Technologies Ltd. All rights reserved.
* Copyright (c) 2016-2018 Mellanox Technologies Ltd. All rights reserved.
*
* Copyright (c) 2016-2017 IBM Corporation. All rights reserved.
* $COPYRIGHT$
Expand Down Expand Up @@ -384,7 +384,7 @@ int ompi_mpi_init(int argc, char **argv, int requested, int *provided)
volatile bool active;
bool background_fence = false;

OMPI_TIMING_INIT(32);
OMPI_TIMING_INIT(64);

ompi_hook_base_mpi_init_top(argc, argv, requested, provided);

Expand Down Expand Up @@ -423,6 +423,7 @@ int ompi_mpi_init(int argc, char **argv, int requested, int *provided)
error = "ompi_mpi_init: opal_init_util failed";
goto error;
}
OMPI_TIMING_IMPORT_OPAL("opal_init_util");

/* If thread support was enabled, then setup OPAL to allow for them. This must be done
* early to prevent a race condition that can occur with orte_init(). */
Expand Down Expand Up @@ -512,8 +513,9 @@ int ompi_mpi_init(int argc, char **argv, int requested, int *provided)
error = "ompi_mpi_init: ompi_rte_init failed";
goto error;
}

OMPI_TIMING_NEXT("rte_init");
OMPI_TIMING_IMPORT_OPAL("orte_ess_base_app_setup");
OMPI_TIMING_IMPORT_OPAL("rte_init");

ompi_rte_initialized = true;

Expand Down Expand Up @@ -643,16 +645,23 @@ int ompi_mpi_init(int argc, char **argv, int requested, int *provided)
}

OMPI_TIMING_IMPORT_OPAL("orte_init");
OMPI_TIMING_IMPORT_OPAL("opal_init_util");
OMPI_TIMING_NEXT("rte_init-commit");


/* exchange connection info - this function may also act as a barrier
* if data exchange is required. The modex occurs solely across procs
* in our job. If a barrier is required, the "modex" function will
* perform it internally */
opal_pmix.commit();
OMPI_TIMING_NEXT("commit");
#if (OPAL_ENABLE_TIMING)
if (OMPI_TIMING_ENABLED && !opal_pmix_base_async_modex &&
opal_pmix_collect_all_data) {
opal_pmix.fence(NULL, 0);
OMPI_TIMING_NEXT("pmix-barrier-1");
opal_pmix.fence(NULL, 0);
OMPI_TIMING_NEXT("pmix-barrier-2");
}
#endif

/* If we have a non-blocking fence:
* if we are doing an async modex, but we are collecting all
Expand Down
58 changes: 52 additions & 6 deletions ompi/util/timings.h
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
/*
* Copyright (c) 2017 Mellanox Technologies Ltd. All rights reserved.
* Copyright (c) 2017-2018 Mellanox Technologies Ltd. All rights reserved.
* Copyright (c) 2017 Intel, Inc. All rights reserved.
* $COPYRIGHT$
*
Expand All @@ -21,6 +21,7 @@ typedef struct {
double ts;
char *file;
char *prefix;
int imported;
} ompi_timing_val_t;

typedef struct {
Expand All @@ -36,11 +37,15 @@ typedef struct ompi_timing_t {
int cnt;
int error;
int enabled;
int import_cnt;
opal_timing_ts_func_t get_ts;
ompi_timing_list_t *timing;
ompi_timing_list_t *cur_timing;
} ompi_timing_t;

#define OMPI_TIMING_ENABLED \
(getenv("OMPI_TIMING_ENABLE") ? atoi(getenv("OMPI_TIMING_ENABLE")) : 0)

#define OMPI_TIMING_INIT(_size) \
ompi_timing_t OMPI_TIMING; \
OMPI_TIMING.prefix = __func__; \
Expand All @@ -50,6 +55,7 @@ typedef struct ompi_timing_t {
OMPI_TIMING.error = 0; \
OMPI_TIMING.ts = OMPI_TIMING.get_ts(); \
OMPI_TIMING.enabled = 0; \
OMPI_TIMING.import_cnt = 0; \
{ \
char *ptr; \
ptr = getenv("OMPI_TIMING_ENABLE"); \
Expand Down Expand Up @@ -94,7 +100,8 @@ typedef struct ompi_timing_t {
#define OMPI_TIMING_NEXT(...) \
do { \
if (!OMPI_TIMING.error && OMPI_TIMING.enabled) { \
char *f = strrchr(__FILE__, '/') + 1; \
char *f = strrchr(__FILE__, '/'); \
f = (f == NULL) ? strdup(__FILE__) : f+1; \
int len = 0; \
if (OMPI_TIMING.cur_timing->use >= OMPI_TIMING.size){ \
OMPI_TIMING_ITEM_EXTEND; \
Expand Down Expand Up @@ -135,10 +142,13 @@ typedef struct ompi_timing_t {
int cnt; \
int i; \
double ts; \
OMPI_TIMING.import_cnt++; \
OPAL_TIMING_ENV_CNT(func, cnt); \
OPAL_TIMING_ENV_ERROR_PREFIX(_prefix, func, OMPI_TIMING.error); \
for(i = 0; i < cnt; i++){ \
char *desc, *filename; \
OMPI_TIMING.cur_timing->val[OMPI_TIMING.cur_timing->use].imported= \
OMPI_TIMING.import_cnt; \
OPAL_TIMING_ENV_GETDESC_PREFIX(_prefix, &filename, func, i, &desc, ts); \
OMPI_TIMING_APPEND(filename, func, desc, ts); \
} \
Expand All @@ -155,6 +165,7 @@ typedef struct ompi_timing_t {
MPI_Comm_size(MPI_COMM_WORLD, &size); \
MPI_Comm_rank(MPI_COMM_WORLD, &rank); \
int error = 0; \
int imported = 0; \
\
MPI_Reduce(&OMPI_TIMING.error, &error, 1, \
MPI_INT, MPI_SUM, 0, MPI_COMM_WORLD); \
Expand All @@ -171,6 +182,7 @@ typedef struct ompi_timing_t {
char **desc = (char**)malloc(sizeof(char*) * OMPI_TIMING.cnt); \
char **prefix = (char**)malloc(sizeof(char*) * OMPI_TIMING.cnt); \
char **file = (char**)malloc(sizeof(char*) * OMPI_TIMING.cnt); \
double total_avg = 0, total_min = 0, total_max = 0; \
\
if( OMPI_TIMING.cnt > 0 ) { \
OMPI_TIMING.ts = OMPI_TIMING.get_ts(); \
Expand All @@ -193,21 +205,53 @@ typedef struct ompi_timing_t {
timing = (ompi_timing_list_t*)timing->next; \
} while (timing != NULL); \
\
if( 0 == rank ){ \
if( 0 == rank ) { \
if (OMPI_TIMING.timing->next) { \
printf("==OMPI_TIMING== warning: added the extra timings allocation that might misrepresent the results.\n" \
"==OMPI_TIMING== Increase the inited size of timings to avoid extra allocation during runtime.\n"); \
} \
\
printf("------------------ %s ------------------\n", \
OMPI_TIMING.prefix); \
OMPI_TIMING.prefix); \
imported = OMPI_TIMING.timing->val[0].imported; \
for(i=0; i< OMPI_TIMING.cnt; i++){ \
bool print_total = 0; \
imported = OMPI_TIMING.timing->val[i].imported; \
avg[i] /= size; \
printf("[%s:%s:%s]: %lf / %lf / %lf\n", \
printf("%s[%s:%s:%s]: %lf / %lf / %lf\n", \
imported ? " -- " : "", \
file[i], prefix[i], desc[i], avg[i], min[i], max[i]); \
if (OMPI_TIMING.timing->val[i].imported) { \
total_avg += avg[i]; \
total_min += min[i]; \
total_max += max[i]; \
} \
if (i == (OMPI_TIMING.cnt-1)) { \
print_total = true; \
} else { \
print_total = imported != OMPI_TIMING.timing->val[i+1].imported; \
} \
if (print_total && OMPI_TIMING.timing->val[i].imported) { \
printf("%s[%s:%s:%s]: %lf / %lf / %lf\n", \
imported ? " !! " : "", \
file[i], prefix[i], "total", \
total_avg, total_min, total_max); \
total_avg = 0; total_min = 0; total_max = 0; \
} \
} \
total_avg = 0; total_min = 0; total_max = 0; \
for(i=0; i< OMPI_TIMING.cnt; i++) { \
if (!OMPI_TIMING.timing->val[i].imported) { \
total_avg += avg[i]; \
total_min += min[i]; \
total_max += max[i]; \
} \
} \
printf("[%s:total] %lf / %lf / %lf\n", \
OMPI_TIMING.prefix, \
total_avg, total_min, total_max); \
printf("[%s:overhead]: %lf \n", OMPI_TIMING.prefix, \
OMPI_TIMING.get_ts() - OMPI_TIMING.ts); \
OMPI_TIMING.get_ts() - OMPI_TIMING.ts); \
} \
} \
free(avg); \
Expand All @@ -233,6 +277,8 @@ typedef struct ompi_timing_t {

#define OMPI_TIMING_FINALIZE

#define OMPI_TIMING_ENABLED 0

#endif

#endif
6 changes: 6 additions & 0 deletions opal/runtime/opal_init.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,8 @@
* and Technology (RIST). All rights reserved.
* Copyright (c) 2017 Amazon.com, Inc. or its affiliates.
* All Rights reserved.
* Copyright (c) 2018 Mellanox Technologies, Inc.
* All rights reserved.
* $COPYRIGHT$
*
* Additional copyrights may follow
Expand Down Expand Up @@ -479,12 +481,16 @@ opal_init_util(int* pargc, char*** pargv)
goto return_error;
}

OPAL_TIMING_ENV_NEXT(otmng, "opal_dss_open");

/* initialize the mca */
if (OPAL_SUCCESS != (ret = mca_base_open())) {
error = "mca_base_open";
goto return_error;
}

OPAL_TIMING_ENV_NEXT(otmng, "mca_base_open");

/* initialize if framework */
if (OPAL_SUCCESS != (ret = mca_base_framework_open(&opal_if_base_framework, 0))) {
fprintf(stderr, "opal_if_base_open() failed -- process will likely abort (%s:%d, returned %d instead of OPAL_SUCCESS)\n",
Expand Down
9 changes: 5 additions & 4 deletions opal/util/timings.h
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
/*
* Copyright (C) 2014 Artem Polyakov <artpol84@gmail.com>
* Copyright (c) 2014-2017 Intel, Inc. All rights reserved.
* Copyright (c) 2017 Mellanox Technologies Ltd. All rights reserved.
* Copyright (c) 2017-2018 Mellanox Technologies Ltd. All rights reserved.
* $COPYRIGHT$
*
* Additional copyrights may follow
Expand Down Expand Up @@ -91,7 +91,7 @@ opal_timing_ts_func_t opal_timing_ts_func(opal_timer_type_t type);
#define OPAL_TIMING_ENV_INIT_PREFIX(prefix, name) \
do { \
opal_timing_env_t name ## _val, *name = &(name ## _val); \
*name = OPAL_TIMING_ENV_START_TYPE(__func__, OPAL_TIMING_AUTOMATIC_TIMER, prefix); \
*name = OPAL_TIMING_ENV_START_TYPE(__func__, name, OPAL_TIMING_AUTOMATIC_TIMER, prefix); \
} while(0)

#define OPAL_TIMING_ENV_NEXT(h, ...) \
Expand Down Expand Up @@ -121,7 +121,8 @@ opal_timing_ts_func_t opal_timing_ts_func(opal_timer_type_t type);
h->error = 1; \
} \
setenv(buf1, buf2, 1); \
filename = strrchr(__FILE__, '/') + 1; \
filename = strrchr(__FILE__, '/'); \
filename = (filename == NULL) ? strdup(__FILE__) : filename+1; \
n = snprintf(buf1, OPAL_TIMING_STR_LEN, "OMPI_TIMING_%s_FILE_%d", h->id, h->cntr); \
if ( n > OPAL_TIMING_STR_LEN ){ \
h->error = 1; \
Expand Down Expand Up @@ -207,7 +208,7 @@ opal_timing_ts_func_t opal_timing_ts_func(opal_timer_type_t type);

#define OPAL_TIMING_ENV_INIT(name)

#define OPAL_TIMING_ENV_INIT_PREFIX(prefix)
#define OPAL_TIMING_ENV_INIT_PREFIX(prefix, name)

#define OPAL_TIMING_ENV_NEXT(h, ... )

Expand Down
20 changes: 20 additions & 0 deletions orte/mca/ess/base/ess_base_std_app.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,8 @@
* Copyright (c) 2014-2016 Research Organization for Information Science
* and Technology (RIST). All rights reserved.
* Copyright (c) 2015 Cisco Systems, Inc. All rights reserved.
* Copyright (c) 2018 Mellanox Technologies, Inc.
* All rights reserved.
* $COPYRIGHT$
*
* Additional copyrights may follow
Expand Down Expand Up @@ -62,6 +64,7 @@
#include "orte/util/session_dir.h"
#include "orte/util/name_fns.h"
#include "orte/util/show_help.h"
#include "opal/util/timings.h"

#include "orte/runtime/orte_globals.h"
#include "orte/runtime/orte_wait.h"
Expand All @@ -74,6 +77,7 @@ int orte_ess_base_app_setup(bool db_restrict_local)
char *error = NULL;
opal_list_t transports;

OPAL_TIMING_ENV_INIT(ess_base_setup);
/*
* stdout/stderr buffering
* If the user requested to override the default setting then do
Expand Down Expand Up @@ -116,13 +120,16 @@ int orte_ess_base_app_setup(bool db_restrict_local)
error = "orte_state_base_select";
goto error;
}
OPAL_TIMING_ENV_NEXT(ess_base_setup, "state_framework_open");

/* open the errmgr */
if (ORTE_SUCCESS != (ret = mca_base_framework_open(&orte_errmgr_base_framework, 0))) {
ORTE_ERROR_LOG(ret);
error = "orte_errmgr_base_open";
goto error;
}
OPAL_TIMING_ENV_NEXT(ess_base_setup, "errmgr_framework_open");

/* setup my session directory */
if (orte_create_session_dirs) {
OPAL_OUTPUT_VERBOSE((2, orte_ess_base_framework.framework_output,
Expand Down Expand Up @@ -157,6 +164,8 @@ int orte_ess_base_app_setup(bool db_restrict_local)
}
}
}
OPAL_TIMING_ENV_NEXT(ess_base_setup, "create_session_dirs");

/* Setup the communication infrastructure */
/* Routed system */
if (ORTE_SUCCESS != (ret = mca_base_framework_open(&orte_routed_base_framework, 0))) {
Expand All @@ -169,6 +178,8 @@ int orte_ess_base_app_setup(bool db_restrict_local)
error = "orte_routed_base_select";
goto error;
}
OPAL_TIMING_ENV_NEXT(ess_base_setup, "routed_framework_open");

/*
* OOB Layer
*/
Expand All @@ -182,6 +193,8 @@ int orte_ess_base_app_setup(bool db_restrict_local)
error = "orte_oob_base_select";
goto error;
}
OPAL_TIMING_ENV_NEXT(ess_base_setup, "oob_framework_open");

/* Runtime Messaging Layer */
if (ORTE_SUCCESS != (ret = mca_base_framework_open(&orte_rml_base_framework, 0))) {
ORTE_ERROR_LOG(ret);
Expand All @@ -193,6 +206,8 @@ int orte_ess_base_app_setup(bool db_restrict_local)
error = "orte_rml_base_select";
goto error;
}
OPAL_TIMING_ENV_NEXT(ess_base_setup, "rml_framework_open");

/* if we have info on the HNP and local daemon, process it */
if (NULL != orte_process_info.my_hnp_uri) {
/* we have to set the HNP's name, even though we won't route messages directly
Expand Down Expand Up @@ -243,6 +258,7 @@ int orte_ess_base_app_setup(bool db_restrict_local)
error = "orte_errmgr_base_select";
goto error;
}
OPAL_TIMING_ENV_NEXT(ess_base_setup, "errmgr_select");

/* get a conduit for our use - we never route IO over fabric */
OBJ_CONSTRUCT(&transports, opal_list_t);
Expand All @@ -264,6 +280,7 @@ int orte_ess_base_app_setup(bool db_restrict_local)
goto error;
}
OPAL_LIST_DESTRUCT(&transports);
OPAL_TIMING_ENV_NEXT(ess_base_setup, "rml_open_conduit");

/*
* Group communications
Expand All @@ -278,6 +295,7 @@ int orte_ess_base_app_setup(bool db_restrict_local)
error = "orte_grpcomm_base_select";
goto error;
}
OPAL_TIMING_ENV_NEXT(ess_base_setup, "grpcomm_framework_open");

/* open the distributed file system */
if (ORTE_SUCCESS != (ret = mca_base_framework_open(&orte_dfs_base_framework, 0))) {
Expand All @@ -290,6 +308,8 @@ int orte_ess_base_app_setup(bool db_restrict_local)
error = "orte_dfs_base_select";
goto error;
}
OPAL_TIMING_ENV_NEXT(ess_base_setup, "dfs_framework_open");

return ORTE_SUCCESS;
error:
orte_show_help("help-orte-runtime.txt",
Expand Down
Loading