more MTC debugging
[ardour.git] / libs / ardour / mtc_slave.cc
index 2fd96b73410ab47991240be5ea471f704ccdadc5..8cc54d577d6d3dec533f041314ccfff35279d1c9 100644 (file)
 #include <poll.h>
 #include <sys/types.h>
 #include <unistd.h>
+
 #include "pbd/error.h"
+#include "pbd/stacktrace.h"
+#include "pbd/enumwriter.h"
 #include "pbd/failed_constructor.h"
 #include "pbd/pthread_utils.h"
 
 #include "ardour/slave.h"
 #include "ardour/session.h"
 #include "ardour/audioengine.h"
-#include "ardour/cycles.h"
+#include "ardour/pi_controller.h"
 
 #include "i18n.h"
 
 using namespace std;
 using namespace ARDOUR;
-using namespace sigc;
 using namespace MIDI;
 using namespace PBD;
 
+/* length (in timecode frames) of the "window" that we consider legal given receipt of
+   a given timecode position. Ardour will try to chase within this window, and will
+   stop+locate+wait+chase if timecode arrives outside of it. The window extends entirely
+   in the current direction of motion, so if any timecode arrives that is before the most
+   recently received position (and without the direction of timecode reversing too), we
+   will stop+locate+wait+chase.
+*/
+
+const int MTC_Slave::frame_tolerance = 2;
+
 MTC_Slave::MTC_Slave (Session& s, MIDI::Port& p)
        : session (s)
 {
        can_notify_on_unknown_rate = true;
        did_reset_tc_format = false;
+
+       pic = new PIChaser();
        
        last_mtc_fps_byte = session.get_mtc_timecode_bits ();
+       mtc_frame = 0;
+
+       speed_accumulator_size = 16;
+       speed_accumulator = new double[speed_accumulator_size];
 
        rebind (p);
        reset ();
@@ -57,63 +75,60 @@ MTC_Slave::~MTC_Slave()
        if (did_reset_tc_format) {
                session.config.set_timecode_format (saved_tc_format);
        }
+
+       delete pic;
+       delete [] speed_accumulator;
+}
+
+bool 
+MTC_Slave::give_slave_full_control_over_transport_speed() const
+{
+       // return true; // for PiC control */
+       return false; // for Session-level computed varispeed
 }
 
 void
 MTC_Slave::rebind (MIDI::Port& p)
 {
-       for (vector<sigc::connection>::iterator i = connections.begin(); i != connections.end(); ++i) {
-               (*i).disconnect ();
-       }
-
+       port_connections.drop_connections ();
+       
        port = &p;
-
-       connections.push_back (port->input()->mtc_time.connect (mem_fun (*this, &MTC_Slave::update_mtc_time)));
-       connections.push_back (port->input()->mtc_qtr.connect (mem_fun (*this, &MTC_Slave::update_mtc_qtr)));
-       connections.push_back (port->input()->mtc_status.connect (mem_fun (*this, &MTC_Slave::update_mtc_status)));
+       
+       port->input()->mtc_time.connect_same_thread (port_connections,  boost::bind (&MTC_Slave::update_mtc_time, this, _1, _2, _3));
+       port->input()->mtc_qtr.connect_same_thread (port_connections, boost::bind (&MTC_Slave::update_mtc_qtr, this, _1, _2, _3));
+       port->input()->mtc_status.connect_same_thread (port_connections, boost::bind (&MTC_Slave::update_mtc_status, this, _1));
 }
 
 void
-MTC_Slave::update_mtc_qtr (Parser& /*p*/, int which_qtr)
+MTC_Slave::update_mtc_qtr (Parser& /*p*/, int which_qtr, nframes_t now)
 {
-       if (qtr_frame_messages_valid_for_time) {
-               
-               nframes64_t now = session.engine().frame_time();
-
-               if (which_qtr != 7) {
+       DEBUG_TRACE (DEBUG::MTC, string_compose ("update MTC qtr does a reset, qtr = %1 now = %2\n", which_qtr, now));
+       maybe_reset ();
 
-                       /* leave position and speed updates for the last
-                          qtr frame message of the 8 to be taken
-                          care of in update_mtc_time(), invoked
-                          by the Parser right after this.
-                       */
-
-                       nframes_t qtr;
-                       
-                       qtr = (long) (session.frames_per_timecode_frame() / 4);
-                       mtc_frame += qtr;
-                       
-                       double speed = compute_apparent_speed (now);
-                       
-                       current.guard1++;
-                       current.position = mtc_frame;
-                       current.timestamp = now;
-                       current.speed = speed;
-                       current.guard2++;
-               }
-
-               last_inbound_frame = now;
-       }
+       DEBUG_TRACE (DEBUG::MTC, string_compose ("qtr frame %1 at %2\n", which_qtr, now));
+       last_inbound_frame = now;
 }
 
 void
-MTC_Slave::update_mtc_time (const byte *msg, bool was_full)
+MTC_Slave::update_mtc_time (const byte *msg, bool was_full, nframes_t now)
 {
-       nframes64_t now = session.engine().frame_time();
+       /* "now" can be zero if this is called from a context where we do not have or do not want
+          to use a timestamp indicating when this MTC time was received. example: when we received
+          a locate command via MMC.
+       */
+
+       if (now) {
+               DEBUG_TRACE (DEBUG::MTC, string_compose ("update MTC time does a reset, was full ? %1 now = %2\n", was_full, now));
+               maybe_reset ();
+       }
+
        Timecode::Time timecode;
        TimecodeFormat tc_format;
        bool reset_tc = true;
+       nframes64_t window_root = -1;
 
+       DEBUG_TRACE (DEBUG::MTC, string_compose ("full mtc time known at %1, full ? %2\n", now, was_full));
+       
        timecode.hours = msg[3];
        timecode.minutes = msg[2];
        timecode.seconds = msg[1];
@@ -169,25 +184,31 @@ MTC_Slave::update_mtc_time (const byte *msg, bool was_full)
 
        DEBUG_TRACE (DEBUG::MTC, string_compose ("MTC time timestamp = %1 TC %2 = frame %3 (from full message ? %4)\n", 
                                                 now, timecode, mtc_frame, was_full));
-
-       if (was_full) {
+       
+       if (was_full || outside_window (mtc_frame)) {
 
                session.timecode_to_sample (timecode, mtc_frame, true, false);
                session.request_locate (mtc_frame, false);
                session.request_transport_speed (0);
-               update_mtc_status (MIDI::Parser::MTC_Stopped);
-
+               DEBUG_TRACE (DEBUG::MTC, string_compose ("reset MTC status to stopped, outside MTC window (%1 .. %2 vs. %3)\n",
+                                                        window_begin, window_end, mtc_frame));
+               update_mtc_status (MIDI::MTC_Stopped);
+               DEBUG_TRACE (DEBUG::MTC, string_compose ("outside, so window root reset to %1\n", mtc_frame));
                reset ();
+               reset_window (mtc_frame);
 
        } else {
-
                        
                /* we've had the first set of 8 qtr frame messages, determine position
-                          and allow continuing qtr frame messages to provide position
-                          and speed information.
+                  and allow continuing qtr frame messages to provide position
+                  and speed information.
                */
                
-               qtr_frame_messages_valid_for_time = true;
+               /* do a careful conversion of the timecode value to a position
+                  so that we take drop/nondrop and all that nonsense into 
+                  consideration.
+               */
+
                session.timecode_to_sample (timecode, mtc_frame, true, false);
                
                /* We received the last quarter frame 7 quarter frames (1.75 mtc
@@ -197,53 +218,102 @@ MTC_Slave::update_mtc_time (const byte *msg, bool was_full)
                */
                
                mtc_frame += (long) (1.75 * session.frames_per_timecode_frame()) + session.worst_output_latency();
-               
-               double speed = compute_apparent_speed (now);
-               
-               current.guard1++;
-               current.position = mtc_frame;
-               current.timestamp = now;
-               current.speed = speed;
-               current.guard2++;
+
+
+               if (now) {
+
+                       if (last_mtc_timestamp == 0) {
+
+                               last_mtc_timestamp = now;
+                               last_mtc_frame = mtc_frame;
+
+                       } else {
+
+                               if (give_slave_full_control_over_transport_speed()) {
+                                       /* PIC 
+                                        * 
+                                        * its not the average, but we will assign it to current.speed below
+                                        */
+
+                                   static nframes64_t last_seen_timestamp = 0; 
+                                   static nframes64_t last_seen_position = 0; 
+
+                                   if ((now - last_seen_timestamp) < 300) {
+                                       mtc_frame = (mtc_frame + last_seen_position)/2;
+                                   }
+
+                                   last_seen_timestamp = now;
+                                   last_seen_position = mtc_frame;
+
+                                       
+                                       
+                               } else {
+
+                                       /* Non-PiC 
+                                        */
+
+                                       nframes64_t time_delta = (now - last_mtc_timestamp);
+                                       
+                                       if (time_delta != 0) {
+                                               double apparent_speed = (mtc_frame - last_mtc_frame) / (double) (time_delta);
+                                               
+                                               process_apparent_speed (apparent_speed);
+                                               DEBUG_TRACE (DEBUG::Slave, string_compose ("apparent speed was %1 average is now %2\n", apparent_speed, average_speed));
+                                       } else {
+                                               DEBUG_TRACE (DEBUG::Slave, string_compose ("no apparent calc, average is %1\n", average_speed));
+                                       }
+                                       
+                                       /* every second, recalibrate the starting point for the speed measurement */
+                                       if (mtc_frame - last_mtc_frame > session.frame_rate()) {
+                                               last_mtc_timestamp = now;
+                                               last_mtc_frame = mtc_frame;
+                                       }
+                               }
+                       }
+
+                       current.guard1++;
+                       current.position = mtc_frame;
+                       current.timestamp = now;
+                       current.speed = average_speed;
+                       current.guard2++;
+                       window_root = mtc_frame;
+               }
        }
 
-       last_inbound_frame = now;
+       if (now) {
+               last_inbound_frame = now;
+       }
+
+       if (window_root >= 0) {
+               DEBUG_TRACE (DEBUG::MTC, string_compose ("window root reset to %1\n", window_root));
+               reset_window (window_root);
+       }
 }
 
-double
-MTC_Slave::compute_apparent_speed (nframes64_t now)
+void
+MTC_Slave::process_apparent_speed (double this_speed)
 {
-       if (current.timestamp != 0) {
-               
-               double speed = (double) ((mtc_frame - current.position) / (double) (now - current.timestamp));
-               DEBUG_TRACE (DEBUG::MTC, string_compose ("instantaneous speed = %1 from %2 - %3 / %4 - %5\n",
-                                                        speed, mtc_frame, current.position, now, current.timestamp));
-               
-               /* crude low pass filter/smoother for speed */
+       DEBUG_TRACE (DEBUG::MTC, string_compose ("speed cnt %1 sz %2 have %3\n", speed_accumulator_cnt, speed_accumulator_size, have_first_speed_accumulator));
 
-               accumulator[accumulator_index++] = speed;
-               
-               if (accumulator_index >= accumulator_size) {
-                       have_first_accumulated_speed = true;
-                       accumulator_index = 0;
-               }
-               
-               if (have_first_accumulated_speed) {
-                       double total = 0;
-                       
-                       for (int32_t i = 0; i < accumulator_size; ++i) {
-                               total += accumulator[i];
-                       }
-                       
-                       speed = total / accumulator_size;
-                       DEBUG_TRACE (DEBUG::MTC, string_compose ("speed smoothed to %1\n", speed));
-               } 
+       /* clamp to an expected range */
 
-               return speed;
-               
-       } else {
-               
-               return 0;
+       if (this_speed > 4.0 || this_speed < -4.0) {
+               this_speed = average_speed;
+       }
+
+       if (speed_accumulator_cnt >= speed_accumulator_size) {
+               have_first_speed_accumulator = true;
+               speed_accumulator_cnt = 0;
+       }
+
+       speed_accumulator[speed_accumulator_cnt++] = this_speed;
+
+       if (have_first_speed_accumulator) {
+               average_speed = 0.0;
+               for (size_t i = 0; i < speed_accumulator_size; ++i) {
+                       average_speed += speed_accumulator[i];
+               }
+               average_speed /= speed_accumulator_size;
        }
 }
 
@@ -258,20 +328,20 @@ MTC_Slave::handle_locate (const MIDI::byte* mmc_tc)
        mtc[1] = mmc_tc[2];
        mtc[0] = mmc_tc[3];
 
-       update_mtc_time (mtc, true);
+       update_mtc_time (mtc, true, 0);
 }
 
 void
-MTC_Slave::update_mtc_status (MIDI::Parser::MTC_Status status)
+MTC_Slave::update_mtc_status (MIDI::MTC_Status status)
 {
        /* XXX !!! thread safety ... called from MIDI I/O context
           and process() context (via ::speed_and_position())
        */
 
+
+       DEBUG_TRACE (DEBUG::MTC, string_compose ("new MTC status %1\n", enum_2_string (status)));
        switch (status) {
        case MTC_Stopped:
-               mtc_frame = 0;
-
                current.guard1++;
                current.position = mtc_frame;
                current.timestamp = 0;
@@ -281,27 +351,22 @@ MTC_Slave::update_mtc_status (MIDI::Parser::MTC_Status status)
                break;
 
        case MTC_Forward:
-               mtc_frame = 0;
-
                current.guard1++;
                current.position = mtc_frame;
                current.timestamp = 0;
                current.speed = 0;
                current.guard2++;
-
                break;
 
        case MTC_Backward:
-               mtc_frame = 0;
-
                current.guard1++;
                current.position = mtc_frame;
                current.timestamp = 0;
                current.speed = 0;
                current.guard2++;
-
                break;
        }
+       
 }
 
 void
@@ -356,14 +421,31 @@ MTC_Slave::speed_and_position (double& speed, nframes64_t& pos)
                pos = last.position;
                session.request_locate (pos, false);
                session.request_transport_speed (0);
-               update_mtc_status (MIDI::Parser::MTC_Stopped);
-               reset();
-               DEBUG_TRACE (DEBUG::MTC, "MTC not seen for 1/4 second - reset\n");
+               queue_reset ();
+               DEBUG_TRACE (DEBUG::MTC, "MTC not seen for 1/4 second - reset pending\n");
                return false;
        }
 
        DEBUG_TRACE (DEBUG::MTC, string_compose ("MTC::speed_and_position %1 %2\n", last.speed, last.position));
 
+       if (give_slave_full_control_over_transport_speed()) {
+           bool in_control = (session.slave_state() == Session::Running);
+           nframes64_t pic_want_locate = 0; 
+           //nframes64_t slave_pos = session.audible_frame();
+           nframes64_t slave_pos = session.transport_frame();
+           static double average_speed = 0;
+
+           average_speed = pic->get_ratio (last.timestamp, last.position, slave_pos, in_control );
+           pic_want_locate = pic->want_locate();
+
+           if (in_control && pic_want_locate) {
+               last.speed = average_speed + (double) (pic_want_locate - session.transport_frame()) / (double)session.get_block_size();
+               std::cout << "locate req " << pic_want_locate << " speed: " << average_speed << "\n"; 
+           } else {
+               last.speed = average_speed;
+           }
+       }
+
        if (last.speed == 0.0f) {
 
                elapsed = 0;
@@ -375,7 +457,7 @@ MTC_Slave::speed_and_position (double& speed, nframes64_t& pos)
                if (last.timestamp && (now > last.timestamp)) {
                        elapsed = (nframes_t) floor (last.speed * (now - last.timestamp));
                        DEBUG_TRACE (DEBUG::MTC, string_compose ("last timecode received @ %1, now = %2, elapsed frames = %3 w/speed= %4\n",
-                                                                last.timestamp, now, elapsed, speed));
+                                                                last.timestamp, now, elapsed, last.speed));
                } else {
                        elapsed = 0; /* XXX is this right? */
                }
@@ -383,7 +465,7 @@ MTC_Slave::speed_and_position (double& speed, nframes64_t& pos)
 
        /* now add the most recent timecode value plus the estimated elapsed interval */
 
-       pos =  elapsed + last.position;
+       pos = last.position + elapsed; 
        speed = last.speed;
 
        DEBUG_TRACE (DEBUG::MTC, string_compose ("MTC::speed_and_position FINAL %1 %2\n", last.speed, pos));
@@ -398,13 +480,33 @@ MTC_Slave::resolution() const
 }
 
 void
-MTC_Slave::reset ()
+MTC_Slave::queue_reset ()
 {
-       /* XXX massive thread safety issue here. MTC could
-          be being updated as we call this. but this
-          supposed to be a realtime-safe call.
-       */
+       DEBUG_TRACE (DEBUG::MTC, "queue reset of MTC slave state\n");
+       PBD::stacktrace (cerr, 35);
+       Glib::Mutex::Lock lm (reset_lock);
+       reset_pending++;
+}
 
+void
+MTC_Slave::maybe_reset ()
+{
+       reset_lock.lock ();
+
+       if (reset_pending) {
+               DEBUG_TRACE (DEBUG::MTC, "actually reset\n");
+               reset ();
+               reset_pending = 0;
+       } 
+
+       reset_lock.unlock ();
+}
+
+void
+MTC_Slave::reset ()
+{
+       DEBUG_TRACE (DEBUG::MTC, "*****************\n\n\n MTC SLAVE reset ********************\n\n\n");
+       PBD::stacktrace (cerr, 35);
        port->input()->reset_mtc_state ();
 
        last_inbound_frame = 0;
@@ -413,7 +515,80 @@ MTC_Slave::reset ()
        current.timestamp = 0;
        current.speed = 0;
        current.guard2++;
-       accumulator_index = 0;
-       have_first_accumulated_speed = false;
-       qtr_frame_messages_valid_for_time = false;
+
+       window_begin = 0;
+       window_end = 0;
+       last_mtc_frame = 0;
+       last_mtc_timestamp = 0;
+
+       average_speed = 0;
+       have_first_speed_accumulator = false;
+       speed_accumulator_cnt = 0;
+
+       pic->reset();
+}
+
+void
+MTC_Slave::reset_window (nframes64_t root)
+{
+       
+       /* if we're waiting for the master to catch us after seeking ahead, keep the window
+          of acceptable MTC frames wide open. otherwise, shrink it down to just 2 video frames
+          ahead of the window root (taking direction into account).
+       */
+
+       DEBUG_TRACE (DEBUG::MTC, string_compose ("trying to reset MTC window with state = %1\n", enum_2_string (port->input()->mtc_running())));
+
+       switch (port->input()->mtc_running()) {
+       case MTC_Forward:
+               DEBUG_TRACE (DEBUG::MTC, "set MTC window while running forward\n");
+               window_begin = root;
+               if (session.slave_state() == Session::Running) {
+                       window_end = root + (session.frames_per_timecode_frame() * frame_tolerance);
+               } else {
+                       window_end = root + seekahead_distance ();
+               }
+               break;
+
+       case MTC_Backward:
+               DEBUG_TRACE (DEBUG::MTC, "set MTC window while running backward\n");
+               if (session.slave_state() == Session::Running) {
+                       nframes_t d = session.frames_per_timecode_frame() * frame_tolerance;
+                       if (root > d) {
+                               window_begin = root - d;
+                               window_end = root;
+                       } else {
+                               window_begin = 0;
+                       }
+               } else {
+                       nframes_t d = seekahead_distance ();
+                       if (root > d) {
+                               window_begin = root - d;
+                       } else {
+                               window_begin = 0;
+                       }
+               }
+               window_end = root;
+               break;
+               
+       default:
+               DEBUG_TRACE (DEBUG::MTC, "not touching MTC window - MTC_Stopped\n");
+               /* do nothing */
+               break;
+       }
+
+       DEBUG_TRACE (DEBUG::MTC, string_compose ("legal MTC window now %1 .. %2\n", window_begin, window_end));
+}
+
+nframes64_t
+MTC_Slave::seekahead_distance () const
+{
+       /* 1 second */
+       return session.frame_rate();
+}
+
+bool
+MTC_Slave::outside_window (nframes64_t pos) const
+{
+       return ((pos < window_begin) || (pos > window_end));
 }