add timer in solver (PaddlePaddle#159)

paddlescience/solver/solver.py

@@ -191,7 +191,7 @@ def __solve_dynamic(self, num_epoch, bs, checkpoint_freq, checkpoint_path):
 
         inputs_labels = inputs + labels  # tmp to one list
 
-        print("Dynamic graph is currently used.")
+        print("Dynamic Graph is Currently in Use.")
         if config.visualdl_enabled() == True:
             writer_loss = LogWriter(logdir=checkpoint_path + 'visualDL/loss')
             writer_eq_loss = LogWriter(
@@ -205,6 +205,10 @@ def __solve_dynamic(self, num_epoch, bs, checkpoint_freq, checkpoint_path):
         # Adam optimizer
         if isinstance(self.opt, paddle.optimizer.AdamW) or isinstance(
                 self.opt, paddle.optimizer.Adam):
+
+            # record time
+            timer = utils.Timer()
+
             for epoch in range(num_epoch):
 
                 # TODO: error out num_epoch==0
@@ -257,6 +261,10 @@ def __solve_dynamic(self, num_epoch, bs, checkpoint_freq, checkpoint_path):
                                 checkpoint_path + 'dynamic_opt_params_' +
                                 str(epoch + 1) + '.pdopt')
 
+            # print time
+            timer.end()
+            timer.print()
+
             for i in range(len(outs)):
                 outs[i] = outs[i].numpy()
 
@@ -458,7 +466,10 @@ def __solve_static(self, num_epoch, bs, checkpoint_freq, checkpoint_path):
             fetches.append(loss_detail.name)
 
         # main loop
-        print("Static graph is currently used.")
+        print("Static Graph is Currently in Use.")
+        if config.prim_enabled():
+            print("Optimized AD is Currently in Use")
+
         if config.visualdl_enabled() == True:
             writer_loss = LogWriter(logdir=checkpoint_path + 'visualDL/loss')
             writer_eq_loss = LogWriter(
@@ -478,6 +489,9 @@ def __solve_static(self, num_epoch, bs, checkpoint_freq, checkpoint_path):
         else:
             compiled_program = self.train_program
 
+        # record time
+        timer = utils.Timer()
+
         for epoch in range(num_epoch):
             rslt = self.exe.run(compiled_program,
                                 feed=feeds,
@@ -515,6 +529,9 @@ def __solve_static(self, num_epoch, bs, checkpoint_freq, checkpoint_path):
                     print('First step cost {} s'.format(first_step_cost))
                     print('{} epoch(10~{}) cost {} s'.format(
                         num_epoch - 10, num_epoch, end - begin))
+        # print time
+        timer.end()
+        timer.print()
 
         # close writer in visual DL
         if config.visualdl_enabled() == True:
@@ -667,10 +684,15 @@ def __solve_static_auto_dist(self, num_epoch, bs, checkpoint_freq):
         for out in self.outs_predict:
             fetches.append(out.name)
 
+        timer = utils.Timer()
+
         rslt = self.engine._executor.run(self.predict_auto_dist_program,
                                          feed=feeds,
                                          fetch_list=fetches)
 
+        timer.end()
+        timer.print()
+
         return rslt
 
     # predict static auto-dist

paddlescience/solver/utils.py

@@ -14,6 +14,7 @@
 
 import six
 import numpy as np
+import time
 import paddle
 from paddle import fluid
 from paddle.fluid import core
@@ -476,3 +477,19 @@ def _compile(program, loss_name):
     optimized_program = cinn_optimize_program(origin_program)
     program_with_fetch = _add_fetch_ops(optimized_program, fetch_list)
     return _compile(program_with_fetch, loss_name)
+
+
+class Timer:
+    def __init__(self):
+        self.tstart = time.time()
+        self.tend = 0.0
+
+    def start(self):
+        self.tstart = time.time()
+
+    def end(self):
+        self.tend = time.time()
+
+    def print(self):
+        elap = self.tend - self.tstart
+        print("Computation time is (sencond): ", elap)