Add some debug code to time things in the process

thread(s).

git-svn-id: svn://localhost/ardour2/branches/3.0@11246 d708f5d6-7413-0410-9779-e7cbd77b26cf

diff --git a/libs/ardour/ardour/cycle_timer.h b/libs/ardour/ardour/cycle_timer.h
index dc70204e82fa1f15072fa96d86004da37a7b59ab..35cc2a4c735238a59c043f1c68a9bc6b881b3e96 100644 (file)
--- a/libs/ardour/ardour/cycle_timer.h
+++ b/libs/ardour/ardour/cycle_timer.h
@@ -22,10 +22,13 @@
 
 #include <string>
 #include <iostream>
+#include <cstdlib>
 
 #include "ardour/cycles.h"
 #include "ardour/debug.h"
 
+float get_mhz ();
+
 class CycleTimer {
   private:
        static float cycles_per_usec;
@@ -56,8 +59,34 @@ class CycleTimer {
                }
 #endif
        }
+};
 
-       static float get_mhz ();
+class StoringTimer
+{
+public:
+       StoringTimer (int);
+       void ref ();
+       void check (int);
+       void dump (std::string const &);
+
+private:
+       cycles_t _current_ref;
+       int* _point;
+       cycles_t* _value;
+       cycles_t* _ref;
+       int _points;
+       int _max_points;
 };
 
+#ifdef PT_TIMING
+extern StoringTimer ST;
+#define PT_TIMING_REF ST.ref();
+#define PT_TIMING_CHECK(x) ST.check(x);
+#endif
+
+#ifndef PT_TIMING
+#define PT_TIMING_REF
+#define PT_TIMING_CHECK(x)
+#endif
+
 #endif /* __ardour_cycle_timer_h__ */

diff --git a/libs/ardour/audioengine.cc b/libs/ardour/audioengine.cc
index 34a79c35f8520dcef3cd8e34c38a6c87e29eeba8..06a1637382ded9ede0c658a5571ad3e0fef8ecd9 100644 (file)
--- a/libs/ardour/audioengine.cc
+++ b/libs/ardour/audioengine.cc
@@ -446,9 +446,11 @@ int
 AudioEngine::process_callback (pframes_t nframes)
 {
        GET_PRIVATE_JACK_POINTER_RET(_jack,0);
-       // CycleTimer ct ("AudioEngine::process");
        Glib::Mutex::Lock tm (_process_lock, Glib::TRY_LOCK);
 
+       PT_TIMING_REF;
+       PT_TIMING_CHECK (1);
+
        /// The number of frames that will have been processed when we've finished
        pframes_t next_processed_frames;
 
@@ -504,7 +506,6 @@ AudioEngine::process_callback (pframes_t nframes)
        } else {
                if (_session) {
                        _session->process (nframes);
-
                }
        }
 
@@ -555,6 +556,9 @@ AudioEngine::process_callback (pframes_t nframes)
        }
 
        _processed_frames = next_processed_frames;
+
+       PT_TIMING_CHECK (2);
+       
        return 0;
 }
 

diff --git a/libs/ardour/cycle_timer.cc b/libs/ardour/cycle_timer.cc
index 7a6b1fcab263225fc011aa6335ad94be1c5e9bff..02d1abb9307b0fde2c29db8b2c6b3aa8511454a6 100644 (file)
--- a/libs/ardour/cycle_timer.cc
+++ b/libs/ardour/cycle_timer.cc
@@ -18,17 +18,19 @@
 */
 
 #include <cstdio>
+#include <fstream>
 #include "pbd/error.h"
 #include "ardour/cycle_timer.h"
 
 #include "i18n.h"
 
+using namespace std;
 using namespace PBD;
 
 float CycleTimer::cycles_per_usec = 0;
 
 float
-CycleTimer::get_mhz()
+get_mhz()
 {
        FILE *f;
 
@@ -72,3 +74,54 @@ CycleTimer::get_mhz()
        /*NOTREACHED*/
        return 0.0f;
 }
+
+StoringTimer::StoringTimer (int N)
+{
+       _point = new int[N];
+       _value = new cycles_t[N];
+       _ref = new cycles_t[N];
+       _max_points = N;
+       _points = 0;
+}
+       
+
+void
+StoringTimer::dump (string const & file)
+{
+       ofstream f (file.c_str ());
+
+       f << min (_points, _max_points) << "\n";
+       f << get_mhz () << "\n";
+       for (int i = 0; i < min (_points, _max_points); ++i) {
+               f << _point[i] << " " << _ref[i] << " " << _value[i] << "\n";
+       }
+}
+
+void
+StoringTimer::ref ()
+{
+       _current_ref = get_cycles ();
+}
+
+void
+StoringTimer::check (int p)
+{
+       if (_points == _max_points) {
+               ++_points;
+               return;
+       } else if (_points > _max_points) {
+               return;
+       }
+       
+       _point[_points] = p;
+       _value[_points] = get_cycles ();
+       _ref[_points] = _current_ref;
+       
+       ++_points;
+}
+
+#ifdef PT_TIMING
+StoringTimer ST (64 * 1024);
+#endif
+
+

diff --git a/libs/ardour/session.cc b/libs/ardour/session.cc
index 37349cc5fb0cc2671f2697d2d94ca6c6c3e95807..26b3d47b7e10fbffbcd1d600e9ac33b9c9d57afc 100644 (file)
--- a/libs/ardour/session.cc
+++ b/libs/ardour/session.cc
@@ -217,6 +217,9 @@ Session::Session (AudioEngine &eng,
 
 Session::~Session ()
 {
+#ifdef PT_TIMING       
+       ST.dump ("ST.dump");
+#endif 
        destroy ();
 }
 

diff --git a/libs/ardour/session_process.cc b/libs/ardour/session_process.cc
index 4876dc7931249953db79fe9b2c5047a3ae642da0..80f922117da4e4bf29deec16f1afc9a155ef4be6 100644 (file)
--- a/libs/ardour/session_process.cc
+++ b/libs/ardour/session_process.cc
@@ -39,6 +39,7 @@
 #include "ardour/graph.h"
 #include "ardour/audio_port.h"
 #include "ardour/tempo.h"
+#include "ardour/cycle_timer.h"
 
 #include "midi++/manager.h"
 #include "midi++/mmc.h"
@@ -103,6 +104,8 @@ Session::fail_roll (pframes_t nframes)
 int
 Session::no_roll (pframes_t nframes)
 {
+       PT_TIMING_CHECK (4);
+       
        framepos_t end_frame = _transport_frame + nframes; // FIXME: varispeed + no_roll ??
        int ret = 0;
        bool declick = get_transport_declick_required();
@@ -112,10 +115,11 @@ Session::no_roll (pframes_t nframes)
                _click_io->silence (nframes);
        }
 
-       if (_process_graph->threads_in_use() > 0) {
+       if (1 || _process_graph->threads_in_use() > 0) {
                DEBUG_TRACE(DEBUG::ProcessThreads,"calling graph/no-roll\n");
                _process_graph->routes_no_roll( nframes, _transport_frame, end_frame, non_realtime_work_pending(), declick);
        } else {
+               PT_TIMING_CHECK (10);
                for (RouteList::iterator i = r->begin(); i != r->end(); ++i) {
 
                        if ((*i)->is_hidden()) {
@@ -130,8 +134,10 @@ Session::no_roll (pframes_t nframes)
                                break;
                        }
                }
+               PT_TIMING_CHECK (11);
        }
 
+       PT_TIMING_CHECK (5);
        return ret;
 }
 
@@ -242,6 +248,8 @@ Session::get_track_statistics ()
 void
 Session::process_with_events (pframes_t nframes)
 {
+       PT_TIMING_CHECK (3);
+       
        SessionEvent*  ev;
        pframes_t      this_nframes;
        framepos_t     end_frame;

diff --git a/wscript b/wscript
index 15690996666df4153c663bbdf55c983702c8923d..4604b1d4bf3f6cbe1077ceaecc8463303a5cbd7b 100644 (file)
--- a/wscript
+++ b/wscript
@@ -391,6 +391,8 @@ def options(opt):
                     help='Build with debugging for the STL')
     opt.add_option('--rt-alloc-debug', action='store_true', default=False, dest='rt_alloc_debug',
                     help='Build with debugging for memory allocation in the real-time thread')
+    opt.add_option('--pt-timing', action='store_true', default=False, dest='pt_timing',
+                    help='Build with logging of timing in the process thread(s)')
     opt.add_option('--denormal-exception', action='store_true', default=False, dest='denormal_exception',
                     help='Raise a floating point exception if a denormal is detected')
     opt.add_option('--test', action='store_true', default=False, dest='build_tests',
@@ -589,6 +591,9 @@ def configure(conf):
     if opts.rt_alloc_debug:
         conf.define('DEBUG_RT_ALLOC', 1)
         conf.env['DEBUG_RT_ALLOC'] = True
+    if opts.pt_timing:
+        conf.define('PT_TIMING', 1)
+        conf.env['PT_TIMING'] = True
     if opts.denormal_exception:
         conf.define('DEBUG_DENORMAL_EXCEPTION', 1)
         conf.env['DEBUG_DENORMAL_EXCEPTION'] = True
@@ -621,6 +626,7 @@ const char* const ardour_config_info = "\\n\\
     write_config_text('Build target',          conf.env['build_target'])
     write_config_text('CoreAudio',             conf.is_defined('HAVE_COREAUDIO'))
     write_config_text('Debug RT allocations',  conf.is_defined('DEBUG_RT_ALLOC'))
+    write_config_text('Process thread timing', conf.is_defined('PT_TIMING'))
     write_config_text('Denormal exceptions',   conf.is_defined('DEBUG_DENORMAL_EXCEPTION'))
     write_config_text('FLAC',                  conf.is_defined('HAVE_FLAC'))
     write_config_text('FPU optimization',      opts.fpu_optimization)