new paramter in function, orig_function and pfunc called name. This is the name…

theano/compile/function.py

@@ -10,7 +10,7 @@ from function_module import orig_function
 from pfunc import pfunc
 from numpy import any #for to work in python 2.4
 
-def function(inputs, outputs=None, mode=None, updates=[], givens=[], accept_inplace=False):
+def function(inputs, outputs=None, mode=None, updates=[], givens=[], accept_inplace=False, name = None):
     """
     Return a callable object that will calculate `outputs` from `inputs`.
 
@@ -33,6 +33,8 @@ def function(inputs, outputs=None, mode=None, updates=[], givens=[], accept_inpl
     :param givens: specific substitutions to make in the computation graph (Var2 replaces
     Var1).  
 
+    :param name: an optional name for this fct. If used, the profile mode will print the time spent in this fct.
+
     :rtype: theano.compile.Function
     :returns: a callable object that will compute the outputs (given the inputs)
     and update the implicit function arguments according to the `updates`.
@@ -56,11 +58,11 @@ def function(inputs, outputs=None, mode=None, updates=[], givens=[], accept_inpl
             raise NotImplementedError("In() instances and tuple inputs triggers the old semantics, which disallow using updates and givens")
         return orig_function(inputs, outputs, 
                 mode=mode,
-                accept_inplace=accept_inplace)
+                accept_inplace=accept_inplace, name=name)
     else:
         return pfunc(params=inputs, 
                 outputs=outputs,
                 mode=mode, 
                 updates=updates, 
                 givens=givens,
-                accept_inplace=accept_inplace)
+                accept_inplace=accept_inplace,name=name)

theano/compile/function_module.py

@@ -483,8 +483,8 @@ class Function(object):
         
         dt_call=time.time()-t0
         if hasattr(self.maker.mode,'fct_call_time'):
-          self.maker.mode.fct_call_time += dt_call
-          self.maker.mode.fct_call += 1
+          self.maker.mode.fct_call_time[self.name] += dt_call
+          self.maker.mode.fct_call[self.name] += 1
 
         if self.return_none:
             return None
@@ -837,7 +837,7 @@ def check_equal(x, y):
 def register_checker(checker):
     __checkers.insert(0, checker)
 
-def orig_function(inputs, outputs, mode=None, accept_inplace = False):
+def orig_function(inputs, outputs, mode=None, accept_inplace = False, name=None):
     """
     Return a Function that will calculate the outputs from the inputs.
 
@@ -850,6 +850,8 @@ def orig_function(inputs, outputs, mode=None, accept_inplace = False):
     :param mode: a descriptive string or a Mode instance. (Default of None means to use
     `mode.default_mode` (See below for descriptive string list).
     
+    :param name: an optional name for this fct. If used, the profile mode will print the time spent in this fct.
+
     Currently, the library provides the following mode strings:
 
      - FAST_RUN (default) (optimize without too much time)
@@ -917,6 +919,13 @@ def orig_function(inputs, outputs, mode=None, accept_inplace = False):
     if hasattr(mode, 'compile_time'):
         mode.compile_time+=t2-t1
 
+    fn.name = name
+    
+    if hasattr(mode,'fct_call_time'):
+      mode.fct_call_time.setdefault(name,0)
+    if hasattr(mode,'fct_call'):
+      mode.fct_call.setdefault(name,0)
+      
     return fn
 
 

theano/compile/pfunc.py

@@ -33,7 +33,7 @@ class Param(object):
         self.strict = strict
         self.implicit = implicit
 
-def pfunc(params, outputs=None, mode=None, updates=[], givens=[], accept_inplace=False):
+def pfunc(params, outputs=None, mode=None, updates=[], givens=[], accept_inplace=False, name=None):
     """Function-constructor for graphs with shared variables.
 
     :type params: list of either Variable or Param instances.
@@ -55,6 +55,8 @@ def pfunc(params, outputs=None, mode=None, updates=[], givens=[], accept_inplace
     :param givens: specific substitutions to make in the computation graph (Var2 replaces
     Var1).  
 
+    :param name: an optional name for this fct. If used, the profile mode will print the time spent in this fct.
+
     :rtype: theano.compile.Function
     :returns: a callable object that will compute the outputs (given the inputs)
     and update the implicit function arguments according to the `updates`.
@@ -205,7 +207,7 @@ def pfunc(params, outputs=None, mode=None, updates=[], givens=[], accept_inplace
             in_sv.update = new_val
             in_sv.mutable = True 
 
-    return orig_function(inputs, cloned_outputs, mode, accept_inplace=accept_inplace)
+    return orig_function(inputs, cloned_outputs, mode, accept_inplace=accept_inplace,name=name)
 
 def _pfunc_param_to_in(param):
     if isinstance(param, Constant):

theano/compile/profilemode.py

@@ -18,8 +18,8 @@ class ProfileMode(Mode):
         op_cimpl = {}
         op_call = {}
         compile_time = 0 #time passed in theano.function()
-        fct_call_time = 0#time passed inside theano fct call including op time.
-        fct_call = 0
+        fct_call_time = {}#time passed inside theano fct call including op time.
+        fct_call = {}
 
         self.__setstate__((linker, optimizer, local_time,
                            apply_time, apply_call,
@@ -160,8 +160,8 @@ class ProfileMode(Mode):
 
         local_time = self.local_time[0]-other.local_time[0]
         compile_time = self.compile_time-other.compile_time
-        fct_call_time = self.fct_call_time-other.fct_call_time
-        fct_call = self.fct_call-other.fct_call
+        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)
         apply_call = diff_dict(self.apply_call, other.apply_call)
         op_time = diff_dict(self.op_time, other.op_time)
@@ -262,15 +262,24 @@ class ProfileMode(Mode):
                   sum(t for f, t, a, ci, nb_call in sotimes[n_ops_to_print:]))
 
         print '(*) Op is running a c implementation'
-        print
+            
+
         total_time = time.time() - import_time
+        total_fct_time = sum(fct_call_time.values())
+        total_fct_call = sum(fct_call.values())
         other_time = total_time - local_time - compile_time
+        print
+        print 'Theano fct summary: <% total fct time> <total time> <time per call> <nb call> <fct name>'
+        for key in fct_call.keys():
+            print '   %4.1f%% %.3fs %.2es %d %s'%(fct_call_time[key]/total_fct_time*100 ,fct_call_time[key],
+                                                  fct_call_time[key]/fct_call[key], fct_call[key],key)
+        print
         print 'Time since import %.3fs'%(total_time)
         print 'Compile time: %.3fs %.1f%%'%(compile_time, compile_time/total_time*100)
-        print 'Theano fct call %.3fs %.1f%%'%(fct_call_time,fct_call_time/total_time*100)
-        print '   Theano Op time (included in fct call, Time spent running thunks) %.3fs %.1f%%(of total) %.1f%%(of fct call)'% (local_time,local_time/total_time*100,local_time/fct_call_time*100)
+        print 'Theano fct call %.3fs %.1f%%'%(total_fct_time,total_fct_time/total_time*100)
+        print '   Theano Op time (included in fct call, Time spent running thunks) %.3fs %.1f%%(of total) %.1f%%(of fct call)'% (local_time,local_time/total_time*100,local_time/total_fct_time*100)
         print 'Other time since import %.3fs %.1f%%'%(other_time,other_time/total_time*100)
-        print '%i Theano fct call, %.3fs per call'%(fct_call, fct_call_time/fct_call)
+        print '%i Theano fct call, %.3fs per call'%(total_fct_call, total_fct_time/total_fct_call)
         
         if any([x[2].__name__.startswith("Gpu") for x in sotimes]):
             cpu=[]