From b087721d8aaf9470833414d01a72d826162946ab Mon Sep 17 00:00:00 2001 From: Carl Hetherington Date: Sat, 14 Jan 2012 22:02:59 +0000 Subject: 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 --- libs/ardour/ardour/cycle_timer.h | 31 +++++++++++++++++++++- libs/ardour/audioengine.cc | 8 ++++-- libs/ardour/cycle_timer.cc | 55 +++++++++++++++++++++++++++++++++++++++- libs/ardour/session.cc | 3 +++ libs/ardour/session_process.cc | 10 +++++++- 5 files changed, 102 insertions(+), 5 deletions(-) (limited to 'libs/ardour') diff --git a/libs/ardour/ardour/cycle_timer.h b/libs/ardour/ardour/cycle_timer.h index dc70204e82..35cc2a4c73 100644 --- a/libs/ardour/ardour/cycle_timer.h +++ b/libs/ardour/ardour/cycle_timer.h @@ -22,10 +22,13 @@ #include #include +#include #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 34a79c35f8..06a1637382 100644 --- 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 7a6b1fcab2..02d1abb930 100644 --- a/libs/ardour/cycle_timer.cc +++ b/libs/ardour/cycle_timer.cc @@ -18,17 +18,19 @@ */ #include +#include #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 37349cc5fb..26b3d47b7e 100644 --- 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 4876dc7931..80f922117d 100644 --- 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; -- cgit v1.2.3