lowered profiler overhead

theano/compile/profilemode.py

@@ -31,16 +31,13 @@ class Profile_Maker(FunctionMaker):
 
 class ProfileMode(Mode):
     def __init__(self, linker=config.linker, optimizer=config.optimizer):
-        local_time = [0.0]
         apply_time = {}
         op_cimpl = {}
         compile_time = 0 #time passed in theano.function()
         fct_call_time = {}#time passed inside theano fct call including op time.
         fct_call = {}
 
-        self.__setstate__((linker, optimizer, local_time,
-                           apply_time,
-                           op_cimpl,
+        self.__setstate__((linker, optimizer, apply_time, op_cimpl,
                            compile_time, fct_call_time, fct_call))
 
     def function_maker(self, i,o,m, *args, **kwargs):
@@ -51,16 +48,12 @@ class ProfileMode(Mode):
 
     def __getstate__(self):
         #print "__getstate__",self.provided_linker,self.provided_optimizer
-        return (self.provided_linker, self.provided_optimizer, self.local_time,
-                self.apply_time,
+        return (self.provided_linker, self.provided_optimizer, self.apply_time,
                 self.op_cimpl, self.compile_time, self.fct_call_time, self.fct_call)
 
-    def __setstate__(self, (linker, optimizer, local_time,
-                            apply_time,
-                            op_cimpl,
+    def __setstate__(self, (linker, optimizer, apply_time, op_cimpl,
                             compile_time, fct_call_time, fct_call)):
         
-        self.local_time = local_time
         self.apply_time = apply_time
         self.op_cimpl = op_cimpl
         self.compile_time = compile_time
@@ -83,7 +76,6 @@ class ProfileMode(Mode):
                 th()
                 dt = time.time() - t0
 
-            local_time[0] += dt
             apply_time[(i,node)] += dt
 
         
@@ -115,14 +107,13 @@ class ProfileMode(Mode):
         :param n_ops_to_print: the number of ops to print. Default 20, or n_apply_to_print flag.
         """
 
-        local_time = self.local_time[0]
         compile_time = self.compile_time
         fct_call_time = self.fct_call_time
         fct_call = self.fct_call
         apply_time = self.apply_time
         op_cimpl = self.op_cimpl
 
-        self.print_summary_("print_summary",local_time, compile_time, fct_call_time, fct_call,
+        self.print_summary_("print_summary", compile_time, fct_call_time, fct_call,
                             apply_time, op_cimpl,
                             n_apply_to_print, n_ops_to_print)
 
@@ -153,20 +144,19 @@ class ProfileMode(Mode):
                 r[a]+=t
             return r
         
-        local_time = self.local_time[0]-other.local_time[0]
         compile_time = self.compile_time-other.compile_time
         fct_call_time = diff_dict(self.fct_call_time,other.fct_call_time)
         fct_call = diff_dict(self.fct_call,other.fct_call)
         apply_time = diff_dict(self.apply_time, other.apply_time)
         op_cimpl = self.op_cimpl and other.op_cimpl
 
-        self.print_summary_("print_diff_summary",local_time, compile_time, fct_call_time, fct_call,
+        self.print_summary_("print_diff_summary", compile_time, fct_call_time, fct_call,
                             apply_time, op_cimpl,
                             n_apply_to_print=n_apply_to_print,
                             n_ops_to_print=n_ops_to_print, print_apply=False)
 
     @staticmethod
-    def print_summary_(fct_name, local_time, compile_time, fct_call_time, fct_call,
+    def print_summary_(fct_name, compile_time, fct_call_time, fct_call,
                        apply_time, op_cimpl,
                        n_apply_to_print=15, n_ops_to_print=20, print_apply=True):
         """
@@ -177,6 +167,8 @@ class ProfileMode(Mode):
         param: n_ops_to_print the number of ops to print. Default 20.
         """
 
+        local_time = sum(apply_time.values())
+
         print ''
         print 'ProfileMode.%s()'%(fct_name)
         print '---------------------------'
@@ -354,7 +346,7 @@ def atexit_print_default_profile_mode():
     config.mode=PROFILE_MODE
     """
     for prof_mode in prof_mode_instance_to_print:
-        if prof_mode.local_time[0]>0:
+        if sum(prof_mode.apply_time.values())>0:
             prof_mode.print_summary()
 
 #Register atexit_print_default_profile_mode to have the summary of the