lots of stuff related to capture alignment. things appear to be working now, but require the right alignment setting, which doesn't persist correctly at present

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

13 files changed, 164 insertions, 201 deletions

diff --git a/libs/ardour/ardour/audio_diskstream.h b/libs/ardour/ardour/audio_diskstream.h
index 2bd44d62a6..53dbe5bd9b 100644
--- a/libs/ardour/ardour/audio_diskstream.h
+++ b/libs/ardour/ardour/audio_diskstream.h
@@ -149,8 +149,6 @@ class AudioDiskstream : public Diskstream
 
 	CubicInterpolation interpolation;
 
-	XMLNode* deprecated_io_node;
-
   protected:
 	friend class Session;
 
diff --git a/libs/ardour/ardour/debug.h b/libs/ardour/ardour/debug.h
index c141bf4040..182a3f6017 100644
--- a/libs/ardour/ardour/debug.h
+++ b/libs/ardour/ardour/debug.h
@@ -50,6 +50,7 @@ namespace PBD {
                 extern uint64_t AudioPlayback;
                 extern uint64_t Panning;
                 extern uint64_t LV2;
+                extern uint64_t CaptureAlignment;
 	}
 }
 
diff --git a/libs/ardour/ardour/diskstream.h b/libs/ardour/ardour/diskstream.h
index cd5932b3e5..b0896349b5 100644
--- a/libs/ardour/ardour/diskstream.h
+++ b/libs/ardour/ardour/diskstream.h
@@ -122,8 +122,8 @@ class Diskstream : public SessionObject, public PublicDiskstream
 	static void set_disk_io_chunk_frames (framecnt_t n) { disk_io_chunk_frames = n; }
 
 	/* Stateful */
-	virtual XMLNode& get_state(void) = 0;
-	virtual int      set_state(const XMLNode&, int version) = 0;
+	virtual XMLNode& get_state(void);
+	virtual int      set_state(const XMLNode&, int version);
 
 	virtual void monitor_input (bool) {}
 
@@ -304,6 +304,7 @@ class Diskstream : public SessionObject, public PublicDiskstream
 	PBD::ScopedConnection ic_connection;
 
 	Flag _flags;
+	XMLNode* deprecated_io_node;
 
 	void route_going_away ();
 };
diff --git a/libs/ardour/audio_diskstream.cc b/libs/ardour/audio_diskstream.cc
index f4b27f6e6a..6da9fb6f0a 100644
--- a/libs/ardour/audio_diskstream.cc
+++ b/libs/ardour/audio_diskstream.cc
@@ -74,7 +74,6 @@ gain_t* AudioDiskstream::_gain_buffer          = 0;
 
 AudioDiskstream::AudioDiskstream (Session &sess, const string &name, Diskstream::Flag flag)
 	: Diskstream(sess, name, flag)
-	, deprecated_io_node(NULL)
 	, channels (new ChannelList)
 {
 	/* prevent any write sources from being created */
@@ -86,7 +85,6 @@ AudioDiskstream::AudioDiskstream (Session &sess, const string &name, Diskstream:
 
 AudioDiskstream::AudioDiskstream (Session& sess, const XMLNode& node)
 	: Diskstream(sess, node)
-	, deprecated_io_node(NULL)
 	, channels (new ChannelList)
 {
 	in_set_state = true;
@@ -132,8 +130,6 @@ AudioDiskstream::~AudioDiskstream ()
 	}
 
 	channels.flush ();
-
-	delete deprecated_io_node;
 }
 
 void
@@ -1491,7 +1487,7 @@ AudioDiskstream::transport_stopped_wallclock (struct tm& when, time_t twhen, boo
 
 			RegionFactory::region_name (region_name, whole_file_region_name, false);
 
-			// cerr << _name << ": based on ci of " << (*ci)->start << " for " << (*ci)->frames << " add region " << region_name << endl;
+			cerr << _name << ": based on ci of " << (*ci)->start << " for " << (*ci)->frames << " add region " << region_name << endl;
 
 			try {
 
@@ -1723,25 +1719,14 @@ AudioDiskstream::disengage_record_enable ()
 XMLNode&
 AudioDiskstream::get_state ()
 {
-	XMLNode* node = new XMLNode ("Diskstream");
+	XMLNode& node (Diskstream::get_state());
 	char buf[64] = "";
 	LocaleGuard lg (X_("POSIX"));
-	boost::shared_ptr<ChannelList> c = channels.reader();
-
-	node->add_property ("flags", enum_2_string (_flags));
 
+	boost::shared_ptr<ChannelList> c = channels.reader();
 	snprintf (buf, sizeof(buf), "%zd", c->size());
-	node->add_property ("channels", buf);
-
-	node->add_property ("playlist", _playlist->name());
-
-	snprintf (buf, sizeof(buf), "%.12g", _visible_speed);
-	node->add_property ("speed", buf);
-
-	node->add_property("name", _name);
-	id().print (buf, sizeof (buf));
-	node->add_property("id", buf);
-
+	node.add_property ("channels", buf);
+        
 	if (!capturing_sources.empty() && _session.get_record_enabled()) {
 
 		XMLNode* cs_child = new XMLNode (X_("CapturingSources"));
@@ -1764,18 +1749,14 @@ AudioDiskstream::get_state ()
 		}
 
 		cs_child->add_property (X_("at"), buf);
-		node->add_child_nocopy (*cs_child);
+		node.add_child_nocopy (*cs_child);
 	}
 
-	if (_extra_xml) {
-		node->add_child_copy (*_extra_xml);
-	}
-
-	return* node;
+	return node;
 }
 
 int
-AudioDiskstream::set_state (const XMLNode& node, int /*version*/)
+AudioDiskstream::set_state (const XMLNode& node, int version)
 {
 	const XMLProperty* prop;
 	XMLNodeList nlist = node.children();
@@ -1784,6 +1765,8 @@ AudioDiskstream::set_state (const XMLNode& node, int /*version*/)
 	XMLNode* capture_pending_node = 0;
 	LocaleGuard lg (X_("POSIX"));
 
+	/* prevent write sources from being created */
+
 	in_set_state = true;
 
 	for (niter = nlist.begin(); niter != nlist.end(); ++niter) {
@@ -1796,27 +1779,9 @@ AudioDiskstream::set_state (const XMLNode& node, int /*version*/)
 		}
 	}
 
-	/* prevent write sources from being created */
-
-	in_set_state = true;
-
-	if ((prop = node.property ("name")) != 0) {
-		_name = prop->value();
-	}
-
-	if (deprecated_io_node) {
-		if ((prop = deprecated_io_node->property ("id")) != 0) {
-			_id = prop->value ();
-		}
-	} else {
-		if ((prop = node.property ("id")) != 0) {
-			_id = prop->value ();
-		}
-	}
-
-	if ((prop = node.property ("flags")) != 0) {
-		_flags = Flag (string_2_enum (prop->value(), _flags));
-	}
+        if (Diskstream::set_state (node, version)) {
+                return -1;
+        }
 
 	if ((prop = node.property ("channels")) != 0) {
 		nchans = atoi (prop->value().c_str());
@@ -1837,38 +1802,15 @@ AudioDiskstream::set_state (const XMLNode& node, int /*version*/)
 		remove_channel (_n_channels.n_audio() - nchans);
 	}
 
-	if ((prop = node.property ("playlist")) == 0) {
-		return -1;
-	}
-
-	{
-		bool had_playlist = (_playlist != 0);
-
-		if (find_and_use_playlist (prop->value())) {
-			return -1;
-		}
-
-		if (!had_playlist) {
-			_playlist->set_orig_diskstream_id (id());
-		}
-
-		if (!destructive() && capture_pending_node) {
-			/* destructive streams have one and only one source per channel,
-			   and so they never end up in pending capture in any useful
-			   sense.
-			*/
-			use_pending_capture_data (*capture_pending_node);
-		}
-
-	}
-
-	if ((prop = node.property ("speed")) != 0) {
-		double sp = atof (prop->value().c_str());
 
-		if (realtime_set_speed (sp, false)) {
-			non_realtime_set_speed ();
-		}
-	}
+        
+        if (!destructive() && capture_pending_node) {
+                /* destructive streams have one and only one source per channel,
+                   and so they never end up in pending capture in any useful
+                   sense.
+                */
+                use_pending_capture_data (*capture_pending_node);
+        }
 
 	in_set_state = false;
 
diff --git a/libs/ardour/debug.cc b/libs/ardour/debug.cc
index a8a17a7bc5..367554ff05 100644
--- a/libs/ardour/debug.cc
+++ b/libs/ardour/debug.cc
@@ -47,4 +47,5 @@ uint64_t PBD::DEBUG::Solo = PBD::new_debug_bit ("solo");
 uint64_t PBD::DEBUG::AudioPlayback = PBD::new_debug_bit ("audioplayback");
 uint64_t PBD::DEBUG::Panning = PBD::new_debug_bit ("panning");
 uint64_t PBD::DEBUG::LV2 = PBD::new_debug_bit ("lv2");
+uint64_t PBD::DEBUG::CaptureAlignment = PBD::new_debug_bit ("capturealignment");
 
diff --git a/libs/ardour/diskstream.cc b/libs/ardour/diskstream.cc
index df9d1a9b4d..97780972f8 100644
--- a/libs/ardour/diskstream.cc
+++ b/libs/ardour/diskstream.cc
@@ -113,7 +113,7 @@ Diskstream::Diskstream (Session &sess, const string &name, Flag flag)
         , _persistent_alignment_style (ExistingMaterial)
         , first_input_change (true)
         , _flags (flag)
-
+        , deprecated_io_node (0)
 {
 }
 
@@ -157,6 +157,7 @@ Diskstream::Diskstream (Session& sess, const XMLNode& /*node*/)
         , _persistent_alignment_style (ExistingMaterial)
         , first_input_change (true)
         , _flags (Recordable)
+        , deprecated_io_node (0)
 {
 }
 
@@ -167,6 +168,8 @@ Diskstream::~Diskstream ()
 	if (_playlist) {
 		_playlist->release ();
 	}
+
+        delete deprecated_io_node;
 }
 
 void
@@ -264,6 +267,7 @@ Diskstream::set_capture_offset ()
 	}
 
 	_capture_offset = _io->latency();
+        DEBUG_TRACE (DEBUG::CaptureAlignment, string_compose ("%1: using IO latency, capture offset set to %2\n", name(), _capture_offset));
 }
 
 void
@@ -434,6 +438,78 @@ Diskstream::set_name (const string& str)
 	return true;
 }
 
+XMLNode&
+Diskstream::get_state ()
+{
+	XMLNode* node = new XMLNode ("Diskstream");
+        char buf[64];
+	LocaleGuard lg (X_("POSIX"));
+
+	node->add_property ("flags", enum_2_string (_flags));
+	node->add_property ("playlist", _playlist->name());
+	node->add_property("name", _name);
+	id().print (buf, sizeof (buf));
+	node->add_property("id", buf);
+	snprintf (buf, sizeof(buf), "%f", _visible_speed);
+	node->add_property ("speed", buf);
+
+	if (_extra_xml) {
+		node->add_child_copy (*_extra_xml);
+	}
+        
+        return *node;
+}
+
+int
+Diskstream::set_state (const XMLNode& node, int /*version*/)
+{
+	const XMLProperty* prop;
+
+	if ((prop = node.property ("name")) != 0) {
+		_name = prop->value();
+	}
+
+	if (deprecated_io_node) {
+		if ((prop = deprecated_io_node->property ("id")) != 0) {
+			_id = prop->value ();
+		}
+	} else {
+		if ((prop = node.property ("id")) != 0) {
+			_id = prop->value ();
+		}
+	}
+
+	if ((prop = node.property ("flags")) != 0) {
+		_flags = Flag (string_2_enum (prop->value(), _flags));
+	}
+
+	if ((prop = node.property ("playlist")) == 0) {
+		return -1;
+	}
+
+	{
+		bool had_playlist = (_playlist != 0);
+
+		if (find_and_use_playlist (prop->value())) {
+			return -1;
+		}
+
+		if (!had_playlist) {
+			_playlist->set_orig_diskstream_id (id());
+		}
+	}
+
+	if ((prop = node.property ("speed")) != 0) {
+		double sp = atof (prop->value().c_str());
+
+		if (realtime_set_speed (sp, false)) {
+			non_realtime_set_speed ();
+		}
+	}
+
+        return 0;
+}
+
 void
 Diskstream::playlist_ranges_moved (list< Evoral::RangeMove<framepos_t> > const & movements_frames, bool from_undo)
 {
@@ -545,29 +621,33 @@ Diskstream::check_record_status (framepos_t transport_frame, bool can_record)
 		last_recordable_frame = max_framepos;
 		capture_start_frame = transport_frame;
 
+                DEBUG_TRACE (DEBUG::CaptureAlignment, string_compose ("%1: @ %7 basic FRF = %2 LRF = %3 CSF = %4 CO = %5, WLO = %6\n",
+                                                                      name(), first_recordable_frame, last_recordable_frame, capture_start_frame,
+                                                                      _capture_offset,
+                                                                      _session.worst_output_latency(),
+                                                                      transport_frame));
+
+                
+
                 if (change & transport_rolling) {
 
                         /* transport-change (started rolling) */
                         
 			if (_alignment_style == ExistingMaterial) {
                                 
-                                /* there are two delays happening:
-                                   
-                                   1) inbound, represented by _capture_offset
-                                   2) outbound, represented by _session.worst_output_latency()
-
-                                   the first sample to record occurs when the larger of these
-                                   two has elapsed, since they occur in parallel.
-
-                                   since we've already added _capture_offset, just add the
-                                   difference if _session.worst_output_latency() is larger.
+                                /* audio played by ardour will take (up to) _session.worst_output_latency() ("WOL") to
+                                   appear at the speakers; audio played at the time when it does appear at
+                                   the speakers will take _capture_offset to arrive back here. we've
+                                   already added _capture_offset, so now add WOL.
                                 */
-
-                                if (_capture_offset < _session.worst_output_latency()) {
-                                        first_recordable_frame += (_session.worst_output_latency() - _capture_offset);
-                                } 
+                                
+                                first_recordable_frame += _session.worst_output_latency();
+                                DEBUG_TRACE (DEBUG::CaptureAlignment, string_compose ("\tROLL: shift FRF by delta between WOL %1\n",
+                                                                                      first_recordable_frame));
                         } else {
 				first_recordable_frame += _roll_delay;
+                                DEBUG_TRACE (DEBUG::CaptureAlignment, string_compose ("\tROLL: shift FRF by roll delay of %1 to %2\n",
+                                                                                      _roll_delay, first_recordable_frame));
   			}
                         
                 } else {
@@ -576,29 +656,14 @@ Diskstream::check_record_status (framepos_t transport_frame, bool can_record)
 
 			if (_alignment_style == ExistingMaterial) {
 
-				/* There are two kinds of punch:
-                                   
-                                   manual punch in happens at the correct transport frame
-                                   because the user hit a button. but to get alignment correct 
-                                   we have to back up the position of the new region to the 
-                                   appropriate spot given the roll delay.
-
-                                   autopunch toggles recording at the precise
-				   transport frame, and then the DS waits
-				   to start recording for a time that depends
-				   on the output latency.
-
-                                   XXX: BUT THIS CODE DOESN'T DIFFERENTIATE !!!
-
-				*/
-
-                                if (_capture_offset < _session.worst_output_latency()) {
-                                        /* see comment in ExistingMaterial block above */
-                                        first_recordable_frame += (_session.worst_output_latency() - _capture_offset);
-                                }
-
+                                /* see comment in ExistingMaterial block above */
+                                first_recordable_frame += _session.worst_output_latency();
+                                DEBUG_TRACE (DEBUG::CaptureAlignment, string_compose ("\tMANUAL PUNCH: shift FRF by delta between WOL and CO to %1\n",
+                                                                                      first_recordable_frame));
 			} else {
 				capture_start_frame -= _roll_delay;
+                                DEBUG_TRACE (DEBUG::CaptureAlignment, string_compose ("\tPUNCH: shift CSF by roll delay of %1 to %2\n",
+                                                                                      _roll_delay, capture_start_frame));
 			}
                 }
                 
@@ -619,9 +684,7 @@ Diskstream::check_record_status (framepos_t transport_frame, bool can_record)
                                 last_recordable_frame = transport_frame + _capture_offset;
                                 
                                 if (_alignment_style == ExistingMaterial) {
-                                        if (_session.worst_output_latency() > _capture_offset) {
-                                                last_recordable_frame += (_session.worst_output_latency() - _capture_offset);
-                                        }
+                                        last_recordable_frame += _session.worst_input_latency();
                                 } else {
                                         last_recordable_frame += _roll_delay;
                                 }
diff --git a/libs/ardour/io.cc b/libs/ardour/io.cc
index d6416bca9a..fce6a669f9 100644
--- a/libs/ardour/io.cc
+++ b/libs/ardour/io.cc
@@ -34,6 +34,7 @@
 
 #include "ardour/audioengine.h"
 #include "ardour/buffer.h"
+#include "ardour/debug.h"
 #include "ardour/io.h"
 #include "ardour/route.h"
 #include "ardour/port.h"
@@ -1158,6 +1159,8 @@ IO::latency () const
 		}
 	}
 
+        DEBUG_TRACE (DEBUG::Latency, string_compose ("%1: max latency from %2 ports = %3\n", 
+                                                     name(), _ports.num_ports(), max_latency));
 	return max_latency;
 }
 
diff --git a/libs/ardour/midi_diskstream.cc b/libs/ardour/midi_diskstream.cc
index ce41d5d4ca..0a9b361f35 100644
--- a/libs/ardour/midi_diskstream.cc
+++ b/libs/ardour/midi_diskstream.cc
@@ -1206,26 +1206,13 @@ MidiDiskstream::disengage_record_enable ()
 XMLNode&
 MidiDiskstream::get_state ()
 {
-	XMLNode* node = new XMLNode ("Diskstream");
+	XMLNode& node (Diskstream::get_state());
 	char buf[64];
 	LocaleGuard lg (X_("POSIX"));
 
-	snprintf (buf, sizeof(buf), "0x%x", _flags);
-	node->add_property ("flags", buf);
-
-	node->add_property("channel-mode", enum_2_string(get_channel_mode()));
-
+	node.add_property("channel-mode", enum_2_string(get_channel_mode()));
 	snprintf (buf, sizeof(buf), "0x%x", get_channel_mask());
-	node->add_property("channel-mask", buf);
-
-	node->add_property ("playlist", _playlist->name());
-
-	snprintf (buf, sizeof(buf), "%f", _visible_speed);
-	node->add_property ("speed", buf);
-
-	node->add_property("name", _name);
-	id().print(buf, sizeof(buf));
-	node->add_property("id", buf);
+	node.add_property("channel-mask", buf);
 
 	if (_write_source && _session.get_record_enabled()) {
 
@@ -1247,18 +1234,14 @@ MidiDiskstream::get_state ()
 		}
 
 		cs_child->add_property (X_("at"), buf);
-		node->add_child_nocopy (*cs_child);
+		node.add_child_nocopy (*cs_child);
 	}
 
-	if (_extra_xml) {
-		node->add_child_copy (*_extra_xml);
-	}
-
-	return* node;
+	return node;
 }
 
 int
-MidiDiskstream::set_state (const XMLNode& node, int /*version*/)
+MidiDiskstream::set_state (const XMLNode& node, int version)
 {
 	const XMLProperty* prop;
 	XMLNodeList nlist = node.children();
@@ -1266,12 +1249,11 @@ MidiDiskstream::set_state (const XMLNode& node, int /*version*/)
 	XMLNode* capture_pending_node = 0;
 	LocaleGuard lg (X_("POSIX"));
 
+	/* prevent write sources from being created */
+
 	in_set_state = true;
 
 	for (niter = nlist.begin(); niter != nlist.end(); ++niter) {
-		/*if ((*niter)->name() == IO::state_node_name) {
-			deprecated_io_node = new XMLNode (**niter);
-		}*/
 		assert ((*niter)->name() != IO::state_node_name);
 
 		if ((*niter)->name() == X_("CapturingSources")) {
@@ -1279,21 +1261,9 @@ MidiDiskstream::set_state (const XMLNode& node, int /*version*/)
 		}
 	}
 
-	/* prevent write sources from being created */
-
-	in_set_state = true;
-
-	if ((prop = node.property ("name")) != 0) {
-		_name = prop->value();
-	}
-
-	if ((prop = node.property ("id")) != 0) {
-		_id = prop->value ();
-	}
-
-	if ((prop = node.property ("flags")) != 0) {
-		_flags = Flag (string_2_enum (prop->value(), _flags));
-	}
+        if (Diskstream::set_state (node, version)) {
+                return -1;
+        }
 
 	ChannelMode channel_mode = AllChannels;
 	if ((prop = node.property ("channel-mode")) != 0) {
@@ -1308,36 +1278,12 @@ MidiDiskstream::set_state (const XMLNode& node, int /*version*/)
 		}
 	}
 
-	set_channel_mode(channel_mode, channel_mask);
 
-	if ((prop = node.property ("playlist")) == 0) {
-		return -1;
-	}
-
-	{
-		bool had_playlist = (_playlist != 0);
+        if (capture_pending_node) {
+                use_pending_capture_data (*capture_pending_node);
+        }
 
-		if (find_and_use_playlist (prop->value())) {
-			return -1;
-		}
-
-		if (!had_playlist) {
-			_playlist->set_orig_diskstream_id (id());
-		}
-
-		if (capture_pending_node) {
-			use_pending_capture_data (*capture_pending_node);
-		}
-
-	}
-
-	if ((prop = node.property ("speed")) != 0) {
-		double sp = atof (prop->value().c_str());
-
-		if (realtime_set_speed (sp, false)) {
-			non_realtime_set_speed ();
-		}
-	}
+	set_channel_mode (channel_mode, channel_mask);
 
 	in_set_state = false;
 
diff --git a/libs/ardour/port.cc b/libs/ardour/port.cc
index c965f0a6f4..6165196b9d 100644
--- a/libs/ardour/port.cc
+++ b/libs/ardour/port.cc
@@ -310,7 +310,13 @@ Port::total_latency () const
 
 	return jack_port_get_total_latency (jack, _jack_port);
 #else
-        return 0;
+        jack_latency_range_t r;
+        jack_port_get_latency_range (_jack_port, 
+                                     sends_output() ? JackPlaybackLatency : JackCaptureLatency,
+                                     &r);
+        DEBUG_TRACE (DEBUG::Latency, string_compose ("PORT %1: latency range %2 .. %3\n", 
+                                                     name(), r.min, r.max));
+        return r.max;
 #endif
 }
 
diff --git a/libs/ardour/route.cc b/libs/ardour/route.cc
index be5ba4f80e..535fde2ca0 100644
--- a/libs/ardour/route.cc
+++ b/libs/ardour/route.cc
@@ -3051,7 +3051,7 @@ Route::update_total_latency ()
 		}
 	}
 
-	DEBUG_TRACE (DEBUG::Latency, string_compose ("%1: internal redirect latency = %2\n", _name, own_latency));
+	DEBUG_TRACE (DEBUG::Latency, string_compose ("%1: bus: internal redirect latency = %2\n", _name, own_latency));
 
 	_output->set_port_latency (own_latency);
 
diff --git a/libs/ardour/session.cc b/libs/ardour/session.cc
index a83034d784..759495351a 100644
--- a/libs/ardour/session.cc
+++ b/libs/ardour/session.cc
@@ -328,6 +328,10 @@ Session::destroy ()
 void
 Session::set_worst_io_latencies ()
 {
+        if (_state_of_the_state & InitialConnecting) {
+                return;
+        }
+
 	_worst_output_latency = 0;
 	_worst_input_latency = 0;
 
@@ -341,6 +345,9 @@ Session::set_worst_io_latencies ()
 		_worst_output_latency = max (_worst_output_latency, (*i)->output()->latency());
 		_worst_input_latency = max (_worst_input_latency, (*i)->input()->latency());
 	}
+        
+        DEBUG_TRACE (DEBUG::Latency, string_compose ("Worst output latency: %1 Worst input latency: %2\n",
+                                                     _worst_output_latency, _worst_input_latency));
 }
 
 void
@@ -429,8 +436,6 @@ Session::when_engine_running ()
 
 	BootMessage (_("Compute I/O Latencies"));
 
-	set_worst_io_latencies ();
-
 	if (_clicking) {
 		// XXX HOW TO ALERT UI TO THIS ? DO WE NEED TO?
 	}
@@ -644,7 +649,7 @@ Session::when_engine_running ()
 		}
 	}
 
-	/* catch up on send+insert cnts */
+	set_worst_io_latencies ();
 
 	_state_of_the_state = StateOfTheState (_state_of_the_state & ~(CannotSave|Dirty));
 
diff --git a/libs/ardour/session_transport.cc b/libs/ardour/session_transport.cc
index 8ce16dff5b..dcbf25777a 100644
--- a/libs/ardour/session_transport.cc
+++ b/libs/ardour/session_transport.cc
@@ -1508,7 +1508,7 @@ Session::update_latency_compensation (bool with_stop, bool abort)
 		_engine.update_total_latencies ();
 	}
 
-	DEBUG_TRACE(DEBUG::Latency, string_compose("worst case latency was %1\n", _worst_track_latency));
+	DEBUG_TRACE(DEBUG::Latency, string_compose("worst case route internal latency was %1\n", _worst_track_latency));
 
 	for (RouteList::iterator i = r->begin(); i != r->end(); ++i) {
 		(*i)->set_latency_delay (_worst_track_latency);
diff --git a/libs/ardour/track.cc b/libs/ardour/track.cc
index 44f84ca3dc..be992eaa61 100644
--- a/libs/ardour/track.cc
+++ b/libs/ardour/track.cc
@@ -97,10 +97,7 @@ Track::update_total_latency ()
 		}
 	}
 
-#undef DEBUG_LATENCY
-#ifdef DEBUG_LATENCY
-	cerr << _name << ": internal redirect (final) latency = " << own_latency << endl;
-#endif
+	DEBUG_TRACE (DEBUG::Latency, string_compose ("%1: track: internal redirect latency = %2\n", _name, own_latency));
 
 	_output->set_port_latency (own_latency);