From 0dddd75429c082ead097f8d4c1bb0ae39a538e41 Mon Sep 17 00:00:00 2001 From: Paul Davis Date: Sun, 6 Jun 2021 18:59:22 -0600 Subject: [PATCH] change StoringTimer to be thread safe and use fixed char strings to identify timing points This may not be at all useful, but the existing implementation was completely useless because of a lack of thread safety --- libs/ardour/ardour/cycle_timer.h | 32 +++++++++++------- libs/ardour/audioengine.cc | 4 +-- libs/ardour/cycle_timer.cc | 57 +++++++++++++++++++++++--------- libs/ardour/route.cc | 2 ++ libs/ardour/session.cc | 3 +- libs/ardour/session_process.cc | 10 +++--- 6 files changed, 72 insertions(+), 36 deletions(-) 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;