changeset 12783:ad9263d965dc

First experimental profiler implementation with flat profile. * profiler.cc: New file. * profiler.h: New file. * Makefile.am: Include new files in build process. * oct-parse.yy (frob_function): Store location of function parsed. * ov-fcn.h (octave_function::profiler_name): New method. * ov-builtin.cc (octave_builtin::do_multi_index_op): Record timings in profiler. * ov-mex-fcn.cc (octave_mex_function::do_multi_index_op): Ditto. * ov-usr-fcn.cc (octave_user_script::do_multi_index_op): Ditto. (octave_user_function::do_multi_index_op): Ditto. (octave_user_function::octave_user_function): Initialize location_line/column. (octave_user_function::profiler_name): New method. * ov-usr-fcn.h (octave_user_function): New variables location_line, location column and new method stash_fcn_location to set them. * pt-fcn-handle.cc (tree_anon_fcn_handle::rvalue1): Store location.
author Daniel Kraft <d@domob.eu>
date Thu, 30 Jun 2011 20:04:34 +0200
parents 0ca5672d5f1a
children c499d54796d6
files src/Makefile.am src/oct-parse.yy src/ov-builtin.cc src/ov-fcn.h src/ov-mex-fcn.cc src/ov-usr-fcn.cc src/ov-usr-fcn.h src/profiler.cc src/profiler.h src/pt-fcn-handle.cc
diffstat 10 files changed, 407 insertions(+), 14 deletions(-) [+]
line wrap: on
line diff
--- a/src/Makefile.am	Thu Jul 07 19:16:14 2011 -0400
+++ b/src/Makefile.am	Thu Jun 30 20:04:34 2011 +0200
@@ -310,6 +310,7 @@
   defaults.h \
   graphics.h \
   oct-conf.h \
+  profiler.h \
   mxarray.h \
   version.h
 
@@ -446,6 +447,7 @@
   pager.cc \
   pr-output.cc \
   procstream.cc \
+  profiler.cc \
   sighandlers.cc \
   siglist.c \
   sparse.cc \
--- a/src/oct-parse.yy	Thu Jul 07 19:16:14 2011 -0400
+++ b/src/oct-parse.yy	Thu Jun 30 20:04:34 2011 +0200
@@ -2900,6 +2900,7 @@
     }
 
   fcn->stash_function_name (id_name);
+  fcn->stash_fcn_location (input_line_number, current_input_column);
 
   if (! help_buf.empty () && current_function_depth == 1
       && ! parsing_subfunctions)
--- a/src/ov-builtin.cc	Thu Jul 07 19:16:14 2011 -0400
+++ b/src/ov-builtin.cc	Thu Jun 30 20:04:34 2011 +0200
@@ -29,6 +29,7 @@
 #include "oct-obj.h"
 #include "ov-builtin.h"
 #include "ov.h"
+#include "profiler.h"
 #include "toplev.h"
 #include "unwind-prot.h"
 
@@ -125,6 +126,8 @@
 
       try
         {
+          profile_data_accumulator::enter pe (profiler, *this);
+
           retval = (*f) (args, nargout);
           // Do not allow null values to be returned from functions.
           // FIXME -- perhaps true builtins should be allowed?
--- a/src/ov-fcn.h	Thu Jul 07 19:16:14 2011 -0400
+++ b/src/ov-fcn.h	Thu Jun 30 20:04:34 2011 +0200
@@ -60,6 +60,9 @@
   virtual bool is_system_fcn_file (void) const { return false; }
 
   virtual std::string fcn_file_name (void) const { return std::string (); }
+  
+  // The name to show in the profiler (also used as map-key).
+  virtual std::string profiler_name (void) const { return name (); }
 
   virtual std::string parent_fcn_name (void) const { return std::string (); }
 
--- a/src/ov-mex-fcn.cc	Thu Jul 07 19:16:14 2011 -0400
+++ b/src/ov-mex-fcn.cc	Thu Jun 30 20:04:34 2011 +0200
@@ -33,6 +33,7 @@
 #include "oct-obj.h"
 #include "ov-mex-fcn.h"
 #include "ov.h"
+#include "profiler.h"
 #include "toplev.h"
 #include "unwind-prot.h"
 
@@ -147,6 +148,7 @@
 
       try
         {
+          profile_data_accumulator::enter pe (profiler, *this);
           retval = call_mex (have_fmex, mex_fcn_ptr, args, nargout, this);
         }
       catch (octave_execution_exception)
--- a/src/ov-usr-fcn.cc	Thu Jul 07 19:16:14 2011 -0400
+++ b/src/ov-usr-fcn.cc	Thu Jun 30 20:04:34 2011 +0200
@@ -24,6 +24,8 @@
 #include <config.h>
 #endif
 
+#include <sstream>
+
 #include "str-vec.h"
 
 #include <defaults.h>
@@ -47,6 +49,7 @@
 #include "unwind-prot.h"
 #include "utils.h"
 #include "parse.h"
+#include "profiler.h"
 #include "variables.h"
 
 // Whether to optimize subsasgn method calls.
@@ -131,7 +134,10 @@
                   frame.protect_var (tree_evaluator::statement_context);
                   tree_evaluator::statement_context = tree_evaluator::script;
 
-                  cmd_list->accept (*current_evaluator);
+                  {
+                    profile_data_accumulator::enter pe (profiler, *this);
+                    cmd_list->accept (*current_evaluator);
+                  }
 
                   if (tree_return_command::returning)
                     tree_return_command::returning = 0;
@@ -176,6 +182,7 @@
   : octave_user_code (std::string (), std::string ()),
     param_list (pl), ret_list (rl), cmd_list (cl),
     lead_comm (), trail_comm (), file_name (),
+    location_line (0), location_column (0),
     parent_name (), t_parsed (static_cast<time_t> (0)),
     t_checked (static_cast<time_t> (0)),
     system_fcn_file (false), call_depth (-1),
@@ -217,6 +224,22 @@
   file_name = nm;
 }
 
+std::string
+octave_user_function::profiler_name (void) const
+{
+  std::ostringstream result;
+
+  if (is_inline_function ())
+    result << "anonymous@" << fcn_file_name ()
+           << ":" << location_line << ":" << location_column;
+  else if (is_subfunction ())
+    result << parent_fcn_name () << ">" << name ();
+  else
+    result << name ();
+
+  return result.str ();
+}
+
 void
 octave_user_function::mark_as_system_fcn_file (void)
 {
@@ -431,22 +454,26 @@
   bool special_expr = (is_inline_function ()
                        || cmd_list->is_anon_function_body ());
 
-  if (special_expr)
-    {
-      assert (cmd_list->length () == 1);
+  {
+    profile_data_accumulator::enter pe (profiler, *this);
 
-      tree_statement *stmt = 0;
+    if (special_expr)
+      {
+        assert (cmd_list->length () == 1);
+
+        tree_statement *stmt = 0;
 
-      if ((stmt = cmd_list->front ())
-          && stmt->is_expression ())
-        {
-          tree_expression *expr = stmt->expression ();
+        if ((stmt = cmd_list->front ())
+            && stmt->is_expression ())
+          {
+            tree_expression *expr = stmt->expression ();
 
-          retval = expr->rvalue (nargout);
-        }
-    }
-  else
-    cmd_list->accept (*current_evaluator);
+            retval = expr->rvalue (nargout);
+          }
+      }
+    else
+      cmd_list->accept (*current_evaluator);
+  }
 
   if (echo_commands)
     print_code_function_trailer ();
--- a/src/ov-usr-fcn.h	Thu Jul 07 19:16:14 2011 -0400
+++ b/src/ov-usr-fcn.h	Thu Jun 30 20:04:34 2011 +0200
@@ -189,6 +189,12 @@
 
   void stash_fcn_file_name (const std::string& nm);
 
+  void stash_fcn_location (int line, int col)
+    {
+      location_line = line;
+      location_column = col;
+    }
+
   void stash_parent_fcn_name (const std::string& p) { parent_name = p; }
 
   void stash_parent_fcn_scope (symbol_table::scope_id ps) { parent_scope = ps; }
@@ -207,6 +213,8 @@
 
   std::string fcn_file_name (void) const { return file_name; }
 
+  std::string profiler_name (void) const;
+
   std::string parent_fcn_name (void) const { return parent_name; }
 
   symbol_table::scope_id parent_fcn_scope (void) const { return parent_scope; }
@@ -344,6 +352,10 @@
   // The name of the file we parsed.
   std::string file_name;
 
+  // Location where this function was defined.
+  int location_line;
+  int location_column;
+
   // The name of the parent function, if any.
   std::string parent_name;
 
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/src/profiler.cc	Thu Jun 30 20:04:34 2011 +0200
@@ -0,0 +1,231 @@
+/*
+
+Copyright (C) 2011 Daniel Kraft
+
+This file is part of Octave.
+
+Octave is free software; you can redistribute it and/or modify it
+under the terms of the GNU General Public License as published by the
+Free Software Foundation; either version 3 of the License, or (at your
+option) any later version.
+
+Octave is distributed in the hope that it will be useful, but WITHOUT
+ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
+for more details.
+
+You should have received a copy of the GNU General Public License
+along with Octave; see the file COPYING.  If not, see
+<http://www.gnu.org/licenses/>.
+
+*/
+
+#ifdef HAVE_CONFIG_H
+#include <config.h>
+#endif
+
+#include <iostream>
+
+#include "Cell.h"
+#include "defun.h"
+#include "oct-time.h"
+#include "ov-fcn.h"
+#include "ov-struct.h"
+#include "pager.h"
+#include "profiler.h"
+
+profile_data_accumulator::enter::enter (profile_data_accumulator& a,
+                                        const octave_function& f)
+  : acc (a)
+{
+  if (acc.is_active ())
+    {
+      fcn = &f;
+      acc.enter_function (*fcn);
+    }
+  else
+    fcn = NULL;
+}
+
+profile_data_accumulator::enter::~enter ()
+{
+  if (fcn)
+    acc.exit_function (*fcn);
+}
+
+profile_data_accumulator::profile_data_accumulator ()
+  : enabled (false), call_stack (), times (), last_time (-1.0)
+{}
+
+void
+profile_data_accumulator::set_active (bool value)
+{
+  // If we enable, clear the call-stack.  This ensures we freshly start
+  // with collecting times now.
+  if (value)
+    {
+      while (!call_stack.empty ())
+        call_stack.pop ();
+    }
+
+  enabled = value;
+}
+
+void
+profile_data_accumulator::enter_function (const octave_function& fcn)
+{
+  // The enter class will check and only call us if the profiler is active.
+  assert (is_active ());
+
+  // If there is already an active function, add to its time before
+  // pushing the new one.
+  if (!call_stack.empty ())
+    add_current_time ();
+
+  call_stack.push (&fcn);
+  last_time = query_time ();
+}
+
+void
+profile_data_accumulator::exit_function (const octave_function& fcn)
+{
+  assert (!call_stack.empty ());
+  assert (&fcn == call_stack.top ());
+
+  // Usually, if we are disabled this function is not even called.  But the
+  // call disabling the profiler is an exception.  So also check here
+  // and only record the time if enabled.
+  if (is_active ())
+    add_current_time ();
+
+  call_stack.pop ();
+
+  // If this was an "inner call", we resume executing the parent function
+  // up the stack.  So note the start-time for this!
+  last_time = query_time ();
+}
+
+void
+profile_data_accumulator::reset (void)
+{
+  if (is_active ())
+    {
+      error ("Can't reset active profiler.");
+      return;
+    }
+
+  times.clear ();
+  last_time = -1.0;
+}
+
+Cell
+profile_data_accumulator::get_data (void) const
+{
+  const int n = times.size ();
+
+  Cell result (1, n);
+  int i = 0;
+  for (timing_map::const_iterator p = times.begin (); p != times.end (); ++p)
+    {
+      octave_scalar_map entry;
+
+      entry.contents ("name") = octave_value (p->first);
+      entry.contents ("time") = octave_value (p->second);
+
+      result (i++) = entry;
+    }
+  assert (i == n);
+
+  return result;
+}
+
+double
+profile_data_accumulator::query_time (void) const
+{
+  octave_time now;
+  return now.double_value ();
+}
+
+void
+profile_data_accumulator::add_current_time (void)
+{
+  const double t = query_time ();
+  assert (last_time >= 0.0 && last_time <= t);
+
+  assert (!call_stack.empty ());
+  const std::string name = call_stack.top ()->profiler_name ();
+
+  // If the key is not yet present in the map, it is constructed
+  // with default value 0.
+  times[name] += t - last_time;
+}
+
+profile_data_accumulator profiler;
+
+DEFUN (profiler_enable, args, nargout,
+  "-*- texinfo -*-\n\
+@deftypefn  {Built-in Function} {} profiler_enable (enabled)\n\
+Enable or disable the profiler data collection.\n\
+@end deftypefn")
+{
+  // If there is an output argument, return current (if we change the old)
+  // status of the profiler.
+  octave_value_list result;
+  if (nargout > 0)
+    {
+      if (nargout > 1)
+        error ("profiler_enable: too many output arguments requested");
+
+      result(0) = profiler.is_active ();
+    }
+
+  // If there is an input argument, set the status.
+  const int nargin = args.length ();
+  if (nargin > 0)
+    {
+      if (nargin > 1)
+        error ("profiler_enable: too many arguments specified");
+
+      profiler.set_active (args(0).bool_value ());
+    }
+
+  return result;
+}
+
+DEFUN (profiler_reset, args, nargout,
+  "-*- texinfo -*-\n\
+@deftypefn  {Built-in Function} {} profiler_reset ()\n\
+Clear all collected profiling data.\n\
+@end deftypefn")
+{
+  octave_value_list result;
+  const int nargin = args.length ();
+
+  if (nargin > 0)
+    error ("profiler_reset: no arguments expected");
+  if (nargout > 0)
+    error ("profiler_reset: no output argument possible");
+
+  profiler.reset ();
+
+  return result;
+}
+
+DEFUN (profiler_data, args, nargout,
+  "-*- texinfo -*-\n\
+@deftypefn  {Built-in Function} {} data = profiler_data ()\n\
+Query the timings collected by the profiler.\n\
+@end deftypefn")
+{
+  octave_value_list result;
+  const int nargin = args.length ();
+
+  if (nargin > 0)
+    error ("profiler_data: no arguments expected");
+  if (nargout != 1)
+    error ("profiler_reset: expected exactly one output argument");
+
+  result(0) = profiler.get_data ();
+
+  return result;
+}
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/src/profiler.h	Thu Jun 30 20:04:34 2011 +0200
@@ -0,0 +1,111 @@
+/*
+
+Copyright (C) 2011 Daniel Kraft
+
+This file is part of Octave.
+
+Octave is free software; you can redistribute it and/or modify it
+under the terms of the GNU General Public License as published by the
+Free Software Foundation; either version 3 of the License, or (at your
+option) any later version.
+
+Octave is distributed in the hope that it will be useful, but WITHOUT
+ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
+for more details.
+
+You should have received a copy of the GNU General Public License
+along with Octave; see the file COPYING.  If not, see
+<http://www.gnu.org/licenses/>.
+
+*/
+
+#if !defined (octave_profiler_h)
+#define octave_profiler_h 1
+
+#include <stack>
+#include <map>
+
+class octave_function;
+class Cell;
+
+class
+OCTAVE_API
+profile_data_accumulator
+{
+public:
+
+  // This is a utility class that can be used to call the enter/exit
+  // functions in a manner protected from stack unwinding.
+  class enter
+  {
+    private:
+
+      profile_data_accumulator& acc;
+
+      const octave_function* fcn;
+
+    public:
+
+      enter (profile_data_accumulator&, const octave_function& fcn);
+
+      virtual ~enter (void);
+
+    private:
+
+      // No copying!
+
+      enter (const enter&);
+
+      enter& operator = (const enter&);
+  };
+
+  profile_data_accumulator (void);
+
+  bool is_active (void) const { return enabled; }
+
+  void set_active (bool);
+
+  void reset (void);
+
+  Cell get_data (void) const;
+
+private:
+
+  bool enabled;
+
+  std::stack<const octave_function*> call_stack;
+
+  typedef std::map<std::string, double> timing_map;
+  timing_map times;
+
+  // Store last timestamp we had, when the currently active function was called.
+  double last_time;
+
+  // These are private as only the unwind-protecting inner class enter
+  // should be allowed to call them.
+  void enter_function (const octave_function&);
+  void exit_function (const octave_function&);
+
+  // Query a timestamp, used for timing calls (obviously).
+  // This is not static because in the future, maybe we want a flag
+  // in the profiler or something to choose between cputime, wall-time
+  // user-time, system-time, ...
+  double query_time () const;
+
+  // Add the time elapsed since last_time to the function on the top
+  // of our call-stack.  This is called from two different positions,
+  // thus it is useful to have it as a seperate function.
+  void add_current_time (void);
+
+  // No copying!
+
+  profile_data_accumulator (const profile_data_accumulator&);
+
+  profile_data_accumulator& operator = (const profile_data_accumulator&);
+};
+
+// The instance used.
+extern profile_data_accumulator profiler;
+
+#endif
--- a/src/pt-fcn-handle.cc	Thu Jul 07 19:16:14 2011 -0400
+++ b/src/pt-fcn-handle.cc	Thu Jun 30 20:04:34 2011 +0200
@@ -127,6 +127,7 @@
     }
 
   uf->mark_as_inline_function ();
+  uf->stash_fcn_location (line (), column ());
 
   octave_value ov_fcn (uf);