diff --git a/libs/ardour/ardour/cycle_timer.h b/libs/ardour/ardour/cycle_timer.h index e9f20c3501..f4b088abe8 100644 --- a/libs/ardour/ardour/cycle_timer.h +++ b/libs/ardour/ardour/cycle_timer.h @@ -21,6 +21,7 @@ #ifndef __ardour_cycle_timer_h__ #define __ardour_cycle_timer_h__ +#include #include #include #include @@ -68,31 +69,38 @@ class LIBARDOUR_API CycleTimer { class LIBARDOUR_API StoringTimer { public: - StoringTimer (int); + StoringTimer (); void ref (); - void check (int); -#ifndef NDEBUG - void dump (std::string const &); -#endif + void check (char const * const what); + void dump (std::ostream&); -private: + static void dump_all (std::string const &); + static StoringTimer* thread_st(); + static void dump_all (); + + private: cycles_t _current_ref; - int* _point; + + char const * const thread; + char const ** _what; cycles_t* _value; cycles_t* _ref; int _points; - int _max_points; + + static int _max_points; + static StoringTimer* all_timers[2048]; /* size relates to thread count */ + static std::atomic st_cnt; + thread_local static int st_index; }; #ifdef PT_TIMING -extern StoringTimer ST; -#define PT_TIMING_REF ST.ref(); -#define PT_TIMING_CHECK(x) ST.check(x); +#define PT_TIMING_REF StoringTimer::thread_st()->ref(); +#define PT_TIMING_CHECK(w) StoringTimer::thread_st()->check(w); #endif #ifndef PT_TIMING #define PT_TIMING_REF -#define PT_TIMING_CHECK(x) +#define PT_TIMING_CHECK(w) #endif #endif /* __ardour_cycle_timer_h__ */ diff --git a/libs/ardour/audioengine.cc b/libs/ardour/audioengine.cc index 4b4130aac9..8035e750a0 100644 --- a/libs/ardour/audioengine.cc +++ b/libs/ardour/audioengine.cc @@ -232,7 +232,7 @@ AudioEngine::process_callback (pframes_t nframes) Port::set_speed_ratio (1.0); PT_TIMING_REF; - PT_TIMING_CHECK (1); + PT_TIMING_CHECK ("process callback in"); /// The number of samples that will have been processed when we've finished pframes_t next_processed_samples; @@ -588,7 +588,7 @@ AudioEngine::process_callback (pframes_t nframes) _processed_samples = next_processed_samples; - PT_TIMING_CHECK (2); + PT_TIMING_CHECK ("process callback out"); return 0; } diff --git a/libs/ardour/cycle_timer.cc b/libs/ardour/cycle_timer.cc index aa3f79177b..5a5aee74da 100644 --- a/libs/ardour/cycle_timer.cc +++ b/libs/ardour/cycle_timer.cc @@ -21,6 +21,7 @@ #include #include #include "pbd/error.h" +#include "pbd/pthread_utils.h" #include "ardour/cycle_timer.h" #include "ardour/libardour_visibility.h" @@ -78,28 +79,45 @@ get_mhz() return 0.0f; } -StoringTimer::StoringTimer (int N) +int StoringTimer::_max_points = 64 * 1024; +StoringTimer* StoringTimer::all_timers[2048]; +std::atomic StoringTimer::st_cnt; + +thread_local int StoringTimer::st_index = st_cnt.fetch_add (1); + +StoringTimer::StoringTimer () + : thread (strdup (pthread_name())) { - _point = new int[N]; - _value = new cycles_t[N]; - _ref = new cycles_t[N]; - _max_points = N; + _what = new char const *[_max_points]; + _value = new cycles_t[_max_points]; + _ref = new cycles_t[_max_points] ; _points = 0; } -#ifndef NDEBUG void -StoringTimer::dump (string const & file) +StoringTimer::dump_all (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"; + f << "There were " << st_cnt.load() << " thread timers\n"; + + for (size_t i = 0; i < (sizeof (all_timers) / sizeof (all_timers[0])); ++i) { + if (all_timers[i]) { + all_timers[i]->dump (f); + } + } +} + +void +StoringTimer::dump (std::ostream& f) +{ + f << thread << ' ' << _points << "\n"; + + for (int i = 0; i < min (_points, _max_points); ++i) { + f << '\t' << _what[i] << " " << _ref[i] << " " << _value[i] << " delta " << _value[i] - _ref[i] << "\n"; } } -#endif void StoringTimer::ref () @@ -108,8 +126,10 @@ StoringTimer::ref () } void -StoringTimer::check (int p) +StoringTimer::check (char const * const what) { + cerr << pthread_name() << " @ " << pthread_self() << ' ' << thread << " check " << what << " @ " << _points << endl; + if (_points == _max_points) { ++_points; return; @@ -117,15 +137,20 @@ StoringTimer::check (int p) return; } - _point[_points] = p; + _what[_points] = what; _value[_points] = get_cycles (); _ref[_points] = _current_ref; ++_points; } -#ifdef PT_TIMING -StoringTimer ST (64 * 1024); -#endif +StoringTimer* +StoringTimer::thread_st() +{ + if (all_timers[st_index] == 0) { + all_timers[st_index] = new StoringTimer; + } + return all_timers[st_index]; +} diff --git a/libs/ardour/route.cc b/libs/ardour/route.cc index ec672d9c9b..38dfb1c8f2 100644 --- a/libs/ardour/route.cc +++ b/libs/ardour/route.cc @@ -57,6 +57,7 @@ #include "ardour/buffer_set.h" #include "ardour/capturing_processor.h" #include "ardour/debug.h" +#include "ardour/cycle_timer.h" #include "ardour/delivery.h" #include "ardour/disk_reader.h" #include "ardour/disk_writer.h" @@ -345,6 +346,7 @@ Route::process_output_buffers (BufferSet& bufs, samplepos_t start_sample, samplepos_t end_sample, pframes_t nframes, bool gain_automation_ok, bool run_disk_reader) { + PT_TIMING_CHECK ("route-pob-in"); /* Caller must hold process lock */ assert (!AudioEngine::instance()->process_lock().trylock()); diff --git a/libs/ardour/session.cc b/libs/ardour/session.cc index 60d4583c73..ee46921507 100644 --- a/libs/ardour/session.cc +++ b/libs/ardour/session.cc @@ -74,6 +74,7 @@ #include "ardour/butler.h" #include "ardour/click.h" #include "ardour/control_protocol_manager.h" +#include "ardour/cycle_timer.h" #include "ardour/data_type.h" #include "ardour/debug.h" #include "ardour/disk_reader.h" @@ -502,7 +503,7 @@ Session::Session (AudioEngine &eng, Session::~Session () { #ifdef PT_TIMING - ST.dump ("ST.dump"); + StoringTimer::dump_all ("ST.dump"); #endif destroy (); } diff --git a/libs/ardour/session_process.cc b/libs/ardour/session_process.cc index 5087dc7fc8..755d66d67d 100644 --- a/libs/ardour/session_process.cc +++ b/libs/ardour/session_process.cc @@ -165,7 +165,7 @@ Session::fail_roll (pframes_t nframes) int Session::no_roll (pframes_t nframes) { - PT_TIMING_CHECK (4); + PT_TIMING_CHECK ("no roll in"); samplepos_t end_sample = _transport_sample + floor (nframes * _transport_fsm->transport_speed()); int ret = 0; @@ -186,7 +186,7 @@ Session::no_roll (pframes_t nframes) DEBUG_TRACE(DEBUG::ProcessThreads,"calling graph/no-roll\n"); _process_graph->routes_no_roll( nframes, _transport_sample, end_sample, non_realtime_work_pending()); } else { - PT_TIMING_CHECK (10); + PT_TIMING_CHECK ("nograph no roll in"); for (RouteList::iterator i = r->begin(); i != r->end(); ++i) { if ((*i)->is_auditioner()) { @@ -199,10 +199,10 @@ Session::no_roll (pframes_t nframes) break; } } - PT_TIMING_CHECK (11); + PT_TIMING_CHECK ("nograph no roll out"); } - PT_TIMING_CHECK (5); + PT_TIMING_CHECK ("no roll out"); return ret; } @@ -330,7 +330,7 @@ Session::calc_preroll_subcycle (samplecnt_t ns) const void Session::process_with_events (pframes_t nframes) { - PT_TIMING_CHECK (3); + PT_TIMING_CHECK ("p-with-e in"); SessionEvent* ev; pframes_t this_nframes;