From 903d730c0c18082576a0267225da739d4805058b Mon Sep 17 00:00:00 2001
From: Dominic Kempf <dominic.kempf@iwr.uni-heidelberg.de>
Date: Wed, 7 Sep 2016 15:19:32 +0200
Subject: [PATCH] Write all timings to a single file instead of std::cout

That allows us to load that file as a pandas frame.
---
 cmake/modules/DunePerftoolMacros.cmake       |  1 +
 cmake/modules/GeneratedSystemtests.cmake     |  2 +-
 dune/perftool/common/timer.hh                | 12 +++-----
 python/dune/perftool/generation/cpp.py       |  7 +++--
 python/dune/perftool/options.py              |  6 ++--
 python/dune/perftool/pdelab/driver.py        | 31 +++++++++++++++-----
 python/dune/perftool/pdelab/localoperator.py | 11 ++++---
 7 files changed, 43 insertions(+), 27 deletions(-)

diff --git a/cmake/modules/DunePerftoolMacros.cmake b/cmake/modules/DunePerftoolMacros.cmake
index e2d7d1f2..cf528aeb 100644
--- a/cmake/modules/DunePerftoolMacros.cmake
+++ b/cmake/modules/DunePerftoolMacros.cmake
@@ -103,6 +103,7 @@ function(add_generated_executable)
 
   add_custom_command(OUTPUT ${GEN_OPERATOR} ${GEN_DRIVER}
                      COMMAND ${CMAKE_BINARY_DIR}/dune-env-2 ufl2pdelab
+                             --project-basedir ${CMAKE_BINARY_DIR}
                              --operator-file ${GEN_OPERATOR}
                              --driver-file ${GEN_DRIVER}
                              ${GEN_FORM_COMPILER_ARGS}
diff --git a/cmake/modules/GeneratedSystemtests.cmake b/cmake/modules/GeneratedSystemtests.cmake
index f9c08544..7f3e1136 100644
--- a/cmake/modules/GeneratedSystemtests.cmake
+++ b/cmake/modules/GeneratedSystemtests.cmake
@@ -49,7 +49,7 @@ function(dune_add_formcompiler_system_test)
 
     add_generated_executable(TARGET ${tname}
                              UFLFILE ${SYSTEMTEST_UFLFILE}
-                             FORM_COMPILER_ARGS --ini-file ${inifile}
+                             FORM_COMPILER_ARGS --ini-file ${inifile} --timer
                              )
 
     # Exclude the target from all
diff --git a/dune/perftool/common/timer.hh b/dune/perftool/common/timer.hh
index 189440c0..dda15b35 100644
--- a/dune/perftool/common/timer.hh
+++ b/dune/perftool/common/timer.hh
@@ -72,13 +72,11 @@
 #ifdef ENABLE_COUNTER
 
 #define DUMP_TIMER(name,os,reset)                       \
-  os << "===== "  #name  " =====" << std::endl; \
-  os << "elapsed: " << HP_TIMER_ELAPSED(name) << std::endl; \
+  os << exec << " " << #name << " " << HP_TIMER_ELAPSED(name) << std::endl; \
   HP_TIMER_OPCOUNTERS(name).reportOperations(os,reset);
 
 #define DUMP_AND_ACCUMULATE_TIMER(name,os,reset,time,ops)  \
-  os << "===== "  #name " =====" << std::endl; \
-  os << "elapsed: " << HP_TIMER_ELAPSED(name) << std::endl; \
+  os << exec << " " << #name << " " << HP_TIMER_ELAPSED(name) << std::endl; \
   time += HP_TIMER_ELAPSED(name); \
   ops += HP_TIMER_OPCOUNTERS(name); \
   HP_TIMER_OPCOUNTERS(name).reportOperations(os,reset);
@@ -86,13 +84,11 @@
 #elif defined ENABLE_HP_TIMERS
 
 #define DUMP_TIMER(name,os,reset)                       \
-  os << "===== "  #name  " =====" << std::endl; \
-  os << "elapsed: " << HP_TIMER_ELAPSED(name) << std::endl; \
+  os << exec << " " << #name << " " << HP_TIMER_ELAPSED(name) << std::endl; \
   if (reset) HP_TIMER_RESET(name);
 
 #define DUMP_AND_ACCUMULATE_TIMER(name,os,reset,time,ops)  \
-  os << "===== "  #name " =====" << std::endl; \
-  os << "elapsed: " << HP_TIMER_ELAPSED(name) << std::endl; \
+  os << exec << " " << #name << " " << HP_TIMER_ELAPSED(name) << std::endl; \
   time += HP_TIMER_ELAPSED(name); \
   if (reset) HP_TIMER_RESET(name);
 
diff --git a/python/dune/perftool/generation/cpp.py b/python/dune/perftool/generation/cpp.py
index 04b53241..06934dfc 100644
--- a/python/dune/perftool/generation/cpp.py
+++ b/python/dune/perftool/generation/cpp.py
@@ -22,10 +22,10 @@ def post_include(post, filetag=None, pre_include=True):
     return gen(post)
 
 
-def include_file(include, filetag=None):
+def include_file(include, filetag=None, system=False):
     assert filetag
     from cgen import Include
-    gen = generator_factory(on_store=lambda i: Include(i), item_tags=("file", filetag, "include"), no_deco=True)
+    gen = generator_factory(on_store=lambda i: Include(i, system=system), item_tags=("file", filetag, "include"), no_deco=True)
     return gen(include)
 
 
@@ -82,7 +82,8 @@ def dump_accumulate_timer(name):
     from dune.perftool.pdelab.localoperator import (name_time_dumper_os,
                                                     name_time_dumper_reset,
                                                     name_time_dumper_t,
-                                                    name_time_dumper_counter)
+                                                    name_time_dumper_counter,
+                                                    name_time_dumper_exec,)
     os = name_time_dumper_os()
     reset = name_time_dumper_reset()
     t = name_time_dumper_t()
diff --git a/python/dune/perftool/options.py b/python/dune/perftool/options.py
index a7c95534..8ae4b6c5 100644
--- a/python/dune/perftool/options.py
+++ b/python/dune/perftool/options.py
@@ -33,9 +33,9 @@ def get_form_compiler_arguments():
     parser.add_argument("--print-transformations", action="store_true", help="print out dot files after ufl tree transformations")
     parser.add_argument("--print-transformations-dir", type=str, help="place where to put dot files (can be omitted)")
     parser.add_argument("--diagonal-transformation-matrix", action="store_true", help="set option if the jacoby of the transformation is diagonal (axiparallel grids)")
-    parser.add_argument("--ini-file", type=str, help="An inifile to use. A generated driver will be hard-coded to it, a [formcompiler] section will be usd as default values to form compiler arguments (use snake case)")
-    # The following option is no-op (because it is set by default), but we may want to remove that default in the future.
-    parser.add_argument("--timer", action="store_true", help="measure times", default=True)
+    parser.add_argument("--ini-file", type=str, help="An inifile to use. A generated driver will be hard-coded to it, a [formcompiler] section will be used as default values to form compiler arguments (use snake case)")
+    parser.add_argument("--timer", action="store_true", help="measure times")
+    parser.add_argument("--project-basedir", type=str, help="The base (build) directory of the dune-perftool project")
 
     # Modify the positional argument to not be a list
     args = vars(parser.parse_args())
diff --git a/python/dune/perftool/pdelab/driver.py b/python/dune/perftool/pdelab/driver.py
index 1fca4361..f413b1f2 100644
--- a/python/dune/perftool/pdelab/driver.py
+++ b/python/dune/perftool/pdelab/driver.py
@@ -1103,6 +1103,24 @@ def name_explicitonestepmethod():
     return "eosm"
 
 
+@preamble
+def define_timing_stream(name):
+    include_file('fstream', filetag='driver', system=True)
+
+    import os
+    tfile = os.path.join(get_option('project_basedir'), 'timings.csv')
+    return ["std::ofstream {};".format(name),
+            "{}.open(\"{}\", std::ios_base::app);".format(name, tfile),
+            ]
+
+
+@symbol
+def name_timing_stream():
+    name = "timestream"
+    define_timing_stream(name)
+    return name
+
+
 @preamble
 def dune_solve():
     # Test if form is linear in ansatzfunction
@@ -1143,17 +1161,14 @@ def dune_solve():
         print_times = []
         for formdata in formdatas:
             lop_name = name_localoperator(formdata)
-            print_times.append("{}.dump_timers(std::cout, true);".format(lop_name))
+            timestream = name_timing_stream()
+            print_times.append("{}.dump_timers({}, argv[0], true);".format(lop_name, timestream))
         solve = ["HP_TIMER_START(total);",
                  "{}".format(solve),
                  "HP_TIMER_STOP(total);",
-                 "",
-                 "// Print timer results",
-                 "std::cout << std::endl;",
-                 "std::cout << \"=== Time for calling solve method ===\" << std::endl;",
-                 "DUMP_TIMER({},{},{});".format('total', 'std::cout', 'true'),
-                 "std::cout << std::endl;"
-                 "std::cout << \"=== {} ===\" << std::endl;".format(lop_name)]
+                 "char* exec = argv[0];"
+                 "DUMP_TIMER(total, {}, true);".format(timestream),
+                 ]
         solve.extend(print_times)
 
     return solve
diff --git a/python/dune/perftool/pdelab/localoperator.py b/python/dune/perftool/pdelab/localoperator.py
index ceab0ba7..2795d330 100644
--- a/python/dune/perftool/pdelab/localoperator.py
+++ b/python/dune/perftool/pdelab/localoperator.py
@@ -306,13 +306,18 @@ def name_time_dumper_counter():
     return "counter"
 
 
+def name_time_dumper_exec():
+    return "exec"
+
+
 class TimerMethod(ClassMember):
     def __init__(self):
         os = name_time_dumper_os()
         reset = name_time_dumper_reset()
         t = name_time_dumper_t()
+        ex = name_time_dumper_exec()
         content = ["template <typename Stream>",
-                   "void dump_timers(Stream& {}, bool {})".format(os, reset),
+                   "void dump_timers(Stream& {}, char* {}, bool {})".format(os, ex, reset),
                    "{",
                    "  double {} = 0.0;".format(t),
                    "#ifdef ENABLE_COUNTERS",
@@ -322,9 +327,7 @@ class TimerMethod(ClassMember):
                    ""]
         dump_timers = [i for i in retrieve_cache_items(condition='dump_timers')]
         content.extend(map(lambda x: '  ' + x, dump_timers))
-        content.extend(["    {} <<\"===== all_kernels =====\" << std::endl".format(os),
-                        "    <<\"elapsed: \" << {} << std::endl;".format(t),
-                        "#ifdef ENABLE_COUNTERS",
+        content.extend(["#ifdef ENABLE_COUNTERS",
                         "  counter.reportOperations({});".format(os),
                         "#endif"])
         content.append("}")
-- 
GitLab