From 4b89e89957e54a398e0f3683609d29d2de1e1ddd Mon Sep 17 00:00:00 2001 From: schnetter Date: Tue, 11 Nov 2008 23:14:31 +0000 Subject: Add two features to TimerReport: - Output all timers periodically to a file, in a format that is easy to parse - Output the top N timers periodically to screen git-svn-id: http://svn.cactuscode.org/arrangements/CactusUtils/TimerReport/trunk@20 d0051148-8e13-4bef-be1d-f6c572c85f9f --- param.ccl | 15 +++++ src/Output.c | 188 +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 203 insertions(+) diff --git a/param.ccl b/param.ccl index 3a31f7d..211f5ce 100644 --- a/param.ccl +++ b/param.ccl @@ -29,6 +29,21 @@ BOOLEAN next "On next iteration" STEERABLE=ALWAYS { } "no" +BOOLEAN output_all_timers "Output a separate file containing all the Cactus timers" STEERABLE=ALWAYS +{ +} "no" + +STRING all_timers_clock "Which clock to use for the all timers output" STEERABLE=ALWAYS +{ + ".*" :: "any clock name allowed" +} "gettimeofday" + +INT n_top_timers "How many timers to include in the top timer report" STEERABLE=ALWAYS +{ + 0 :: "Do not print the report" + 1:* :: "Any number of timers" +} 0 + shares: IO USES STRING out_dir diff --git a/src/Output.c b/src/Output.c index 39fe709..ccf226e 100644 --- a/src/Output.c +++ b/src/Output.c @@ -10,6 +10,7 @@ #include #include +#include #include "cctk.h" #include "cctk_Parameters.h" @@ -32,6 +33,8 @@ CCTK_FILEVERSION(CactusUtils_TimerReport_Output_c); ********************************************************************/ static void PrintTimes (CCTK_ARGUMENTS); +static void OutputAllTimers (CCTK_ARGUMENTS); +static void PrintTopTimers (CCTK_ARGUMENTS); /******************************************************************** ********************* Scheduled Routine Prototypes *************** @@ -75,6 +78,12 @@ void TimerReport_Output(CCTK_ARGUMENTS) cctk_iteration, (double)cctk_time); PrintTimes(CCTK_PASS_CTOC); + if (output_all_timers) + OutputAllTimers(CCTK_PASS_CTOC); + + if (n_top_timers > 0) + PrintTopTimers(CCTK_PASS_CTOC); + if (next) { CCTK_ParameterSet("next", CCTK_THORNSTRING, "no"); @@ -159,3 +168,182 @@ static void PrintTimes (CCTK_ARGUMENTS) free(filename); } } + +static void OutputAllTimers (CCTK_ARGUMENTS) +{ + DECLARE_CCTK_ARGUMENTS; + DECLARE_CCTK_PARAMETERS; + + FILE *file; + char *filename; + const char *flags; + static int first_time = 1; + int ntimers = CCTK_NumTimers(); + cTimerData *td = CCTK_TimerCreateData(); + double timer_secs = -1; + static int last_ntimers = -1; + + assert(ntimers >= 0); + + Util_asprintf(&filename, "%s/%s.%04d.txt", + out_dir, "AllTimers", CCTK_MyProc(cctkGH)); + + /* truncate or append */ + flags = first_time && IO_TruncateOutputFiles(cctkGH) ? "w" : "a"; + + file = fopen(filename, flags); + if (file) + { + if (first_time) + { + fprintf(file, "# Clock %s\n", all_timers_clock); + fprintf(file, "# Unit seconds\n"); + } + /* If the number of timers has changed, output the header + * containing the timer names again. It would be better to track + * creation and deletion of timers in the flesh, but this always + * works as long as timers are never deleted. */ + if (first_time || last_ntimers != ntimers) + { + fprintf(file, "# Column 1 iteration\n"); + fprintf(file, "# Column 2 time\n"); + for (int i = 0; i < ntimers; i++) + { + const char *name = CCTK_TimerName(i); + + if (name == NULL) + name = ""; + + fprintf(file, "# Column %d %s\n", i+3, name); + } + } + + fprintf(file, "%d\t%f\t", cctk_iteration, cctk_time); + + for (int i = 0; i < ntimers; i++) + { + CCTK_TimerI(i, td); + + { + const cTimerVal *tv = CCTK_GetClockValue(all_timers_clock, td); + + if (tv != NULL) + { + timer_secs = CCTK_TimerClockSeconds(tv); + } + else + { + CCTK_VWarn(0, __LINE__, __FILE__, CCTK_THORNSTRING, + "Clock \"%s\" not found", all_timers_clock); + } + } + + fprintf(file, "%.15g", timer_secs); + if (i != ntimers - 1) + fprintf(file, "\t"); + } + fprintf(file, "\n"); + fclose(file); + } + else + { + CCTK_VWarn(1, __LINE__, __FILE__, CCTK_THORNSTRING, + "Could not open timer report output file \"%s\"", filename); + } + free(filename); + CCTK_TimerDestroyData(td); + first_time = 0; + last_ntimers = ntimers; + return; +} + +typedef struct +{ + int timer; + double t; +} timer_pair; + +static int compare(const void * a, const void * b) +{ + timer_pair *t1 = (timer_pair *) a; + timer_pair *t2 = (timer_pair *) b; + + double d = t2->t - t1->t; + + if (d > 0) + return 1; + else if (d == 0) + return 0; + else return -1; +} + + +static void PrintTopTimers (CCTK_ARGUMENTS) +{ + DECLARE_CCTK_ARGUMENTS; + DECLARE_CCTK_PARAMETERS; + + int ntimers = CCTK_NumTimers(); + cTimerData *td = CCTK_TimerCreateData(); + double timer_secs = -1; + timer_pair timers[ntimers]; + int topn = n_top_timers; + double total = 0; + + char *sep = "======================================================================"; + + assert(ntimers >= 0); + for (int i = 0; i < ntimers; i++) + { + CCTK_TimerI(i, td); + + { + const cTimerVal *tv = CCTK_GetClockValue(all_timers_clock, td); + + if (tv != NULL) + { + timer_secs = CCTK_TimerClockSeconds(tv); + } + else + { + CCTK_VWarn(0, __LINE__, __FILE__, CCTK_THORNSTRING, + "Clock \"%s\" not found", all_timers_clock); + } + } + + timers[i].timer = i; + timers[i].t = timer_secs; + } + + qsort(timers, ntimers, sizeof(timer_pair), compare); + + CCTK_TimerDestroyData(td); + + CCTK_VInfo(CCTK_THORNSTRING, + "Top timers at iteration %d time %g", + cctk_iteration, (double)cctk_time); + + printf("%s\n", sep); + printf("%% Time/s Timer (%s)\n", all_timers_clock); + printf("%s\n", sep); + + /* This should be the "CCTK total time" timer */ + total = timers[0].t; + + for (int i = 0; i < (ntimers >= topn ? topn : ntimers) ; i++) + { + double percent = 100.0 * timers[i].t / total; + + char percent_string[10]; + char time_string[10]; + + snprintf(percent_string, 6, "%.5f", percent); + snprintf(time_string, 8, "%.7f", timers[i].t); + + printf("%s %s %s\n", percent_string, time_string, + CCTK_TimerName(timers[i].timer)); + } + printf("%s\n", sep); + + return; +} -- cgit v1.2.3