diff --git a/libs/ardour/ardour/debug.h b/libs/ardour/ardour/debug.h index 49351e0076..07f8f1a4b2 100644 --- a/libs/ardour/ardour/debug.h +++ b/libs/ardour/ardour/debug.h @@ -97,6 +97,7 @@ namespace PBD { LIBARDOUR_API extern DebugBits TXLTC; LIBARDOUR_API extern DebugBits TempoMap; LIBARDOUR_API extern DebugBits TempoMath; + LIBARDOUR_API extern DebugBits TopologyTiming; LIBARDOUR_API extern DebugBits Transport; LIBARDOUR_API extern DebugBits Triggers; LIBARDOUR_API extern DebugBits US2400; diff --git a/libs/ardour/debug.cc b/libs/ardour/debug.cc index 031c097eba..aead8cbb49 100644 --- a/libs/ardour/debug.cc +++ b/libs/ardour/debug.cc @@ -92,6 +92,7 @@ PBD::DebugBits PBD::DEBUG::TFSMState = PBD::new_debug_bit ("tfsmstate"); PBD::DebugBits PBD::DEBUG::TXLTC = PBD::new_debug_bit ("tx-ltc"); PBD::DebugBits PBD::DEBUG::TempoMap = PBD::new_debug_bit ("tempomap"); PBD::DebugBits PBD::DEBUG::TempoMath = PBD::new_debug_bit ("tempomath"); +PBD::DebugBits PBD::DEBUG::TopologyTiming = PBD::new_debug_bit ("topologytiming"); PBD::DebugBits PBD::DEBUG::Transport = PBD::new_debug_bit ("transport"); PBD::DebugBits PBD::DEBUG::Triggers = PBD::new_debug_bit ("triggers"); PBD::DebugBits PBD::DEBUG::US2400 = PBD::new_debug_bit ("us2400"); diff --git a/libs/ardour/session.cc b/libs/ardour/session.cc index 749144b169..2fb7405d32 100644 --- a/libs/ardour/session.cc +++ b/libs/ardour/session.cc @@ -2200,6 +2200,10 @@ Session::resort_routes () void Session::resort_routes_using (boost::shared_ptr r) { +#ifndef NDEBUG + Timing t; +#endif + GraphNodeList gnl; for (auto const& rt : *r) { gnl.push_back (rt); @@ -2237,9 +2241,15 @@ Session::resort_routes_using (boost::shared_ptr r) } #ifndef NDEBUG - DEBUG_TRACE (DEBUG::Graph, "Routes resorted, order follows:\n"); - for (auto const& i : *r) { - DEBUG_TRACE (DEBUG::Graph, string_compose ("\t%1 (presentation order %2)\n", i->name(), i->presentation_info().order())); + if (DEBUG_ENABLED(DEBUG::TopologyTiming)) { + t.update (); + std::cerr << string_compose ("Session::resort_route took %1ms ; DSP %2 %%\n", + t.elapsed () / 1000., 100.0 * t.elapsed() / _engine.usecs_per_cycle ()); + + DEBUG_TRACE (DEBUG::Graph, "Routes resorted, order follows:\n"); + for (auto const& i : *r) { + DEBUG_TRACE (DEBUG::Graph, string_compose ("\t%1 (presentation order %2)\n", i->name(), i->presentation_info().order())); + } } #endif @@ -6822,6 +6832,10 @@ Session::update_latency (bool playback) return; } +#ifndef NDEBUG + Timing t; +#endif + /* Session::new_midi_track -> Route::add_processors -> Delivery::configure_io * -> IO::ensure_ports -> PortManager::register_output_port * may run currently (adding many ports) while the backend @@ -6920,6 +6934,15 @@ Session::update_latency (bool playback) DEBUG_TRACE (DEBUG::LatencyCompensation, "Engine latency callback: DONE\n"); LatencyUpdated (playback); /* EMIT SIGNAL */ + +#ifndef NDEBUG + if (DEBUG_ENABLED(DEBUG::TopologyTiming)) { + t.update (); + std::cerr << string_compose ("Session::update_latency for %1 took %2ms ; DSP %3 %%\n", + playback ? "playback" : "capture", t.elapsed () / 1000., + 100.0 * t.elapsed () / _engine.usecs_per_cycle ()); + } +#endif } void