add slave,transport and event debugging traces

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

diff --git a/libs/ardour/ardour/debug.h b/libs/ardour/ardour/debug.h
index d90c82fcbe4317a1104b8b5fec5be011a9b6ed4b..f4170acfeb5afeb8f07755705b33fdfb449d0a0d 100644 (file)
--- a/libs/ardour/ardour/debug.h
+++ b/libs/ardour/ardour/debug.h
@@ -47,7 +47,9 @@ namespace ARDOUR {
                        Graph = 0x80,
                        Destruction = 0x100,
                        MTC = 0x200,
-                       Transport = 0x400
+                       Transport = 0x400,
+                       Slave = 0x800,
+                       SessionEvents = 0x800,
                };
        }
 

diff --git a/libs/ardour/ardour/session.h b/libs/ardour/ardour/session.h
index da985d2ce7d306434aa2563564859857dec445bb..06f6b5e5052a07abb591fef768e595c7c4344406 100644 (file)
--- a/libs/ardour/ardour/session.h
+++ b/libs/ardour/ardour/session.h
@@ -117,6 +117,8 @@ class Source;
 class TempoMap;
 class VSTPlugin;
 
+extern void setup_enum_writer ();
+
 class Session : public PBD::StatefulDestructible, public boost::noncopyable
 {
   private:
@@ -960,14 +962,36 @@ class Session : public PBD::StatefulDestructible, public boost::noncopyable
                return _exporting;
        }
 
+       /* this is a private enum, but setup_enum_writer() needs it,
+          and i can't find a way to give that function
+          friend access. sigh.
+       */
+
+       enum PostTransportWork {
+               PostTransportStop               = 0x1,
+               PostTransportDisableRecord      = 0x2,
+               PostTransportPosition           = 0x8,
+               PostTransportDidRecord          = 0x20,
+               PostTransportDuration           = 0x40,
+               PostTransportLocate             = 0x80,
+               PostTransportRoll               = 0x200,
+               PostTransportAbort              = 0x800,
+               PostTransportOverWrite          = 0x1000,
+               PostTransportSpeed              = 0x2000,
+               PostTransportAudition           = 0x4000,
+               PostTransportScrub              = 0x8000,
+               PostTransportReverse            = 0x10000,
+               PostTransportInputChange        = 0x20000,
+               PostTransportCurveRealloc       = 0x40000,
+               PostTransportClearSubstate      = 0x80000
+       };
+
+
   protected:
        friend class AudioEngine;
        void set_block_size (nframes_t nframes);
        void set_frame_rate (nframes_t nframes);
 
-  protected:
-       friend class Diskstream;
-
   protected:
        friend class Route;
        void schedule_curve_reallocation ();
@@ -1174,6 +1198,7 @@ class Session : public PBD::StatefulDestructible, public boost::noncopyable
 
        Butler* _butler;
 
+#if 0 // these should be here, see comments in their other location above
        enum PostTransportWork {
                PostTransportStop               = 0x1,
                PostTransportDisableRecord      = 0x2,
@@ -1192,7 +1217,7 @@ class Session : public PBD::StatefulDestructible, public boost::noncopyable
                PostTransportCurveRealloc       = 0x40000,
                PostTransportClearSubstate      = 0x80000
        };
-
+#endif
        static const PostTransportWork ProcessCannotProceedMask =
                PostTransportWork (
                                PostTransportInputChange|

diff --git a/libs/ardour/debug.cc b/libs/ardour/debug.cc
index 0e9b7d81828db40fa2e0766732d8a560d5e6ec3b..4677f696ae406bc833e0811ba5a8bf3a10f43455 100644 (file)
--- a/libs/ardour/debug.cc
+++ b/libs/ardour/debug.cc
@@ -84,6 +84,10 @@ ARDOUR::parse_debug_options (const char* str)
                        bits |= ARDOUR::DEBUG::MTC;
                } else if (strncasecmp (p, "transport", strlen (p)) == 0) {
                        bits |= ARDOUR::DEBUG::Transport;
+               } else if (strncasecmp (p, "slave", strlen (p)) == 0) {
+                       bits |= ARDOUR::DEBUG::Transport;
+               } else if (strncasecmp (p, "sessionevents", strlen (p)) == 0) {
+                       bits |= ARDOUR::DEBUG::SessionEvents;
                }
 
                p = strtok_r (0, ",", &sp);
@@ -109,4 +113,6 @@ ARDOUR::list_debug_options ()
        cerr << "\tDestruction" << endl;
        cerr << "\tMTC" << endl;
        cerr << "\tTransport" << endl;
+       cerr << "\tSlave" << endl;
+       cerr << "\tSessionEvents" << endl;
 }

diff --git a/libs/ardour/enums.cc b/libs/ardour/enums.cc
index 72aa5bef55ffd73fe9b8579131494e395ca5d134..870c60eec72ceb25c2aa4ee265ffcd5fce54b719 100644 (file)
--- a/libs/ardour/enums.cc
+++ b/libs/ardour/enums.cc
@@ -114,7 +114,8 @@ setup_enum_writer ()
        WaveformScale _WaveformScale;
        WaveformShape _WaveformShape;
        QuantizeType _QuantizeType;
-
+       Session::PostTransportWork _Session_PostTransportWork;
+               
 #define REGISTER(e) enum_writer->register_distinct (typeid(e).name(), i, s); i.clear(); s.clear()
 #define REGISTER_BITS(e) enum_writer->register_bits (typeid(e).name(), i, s); i.clear(); s.clear()
 #define REGISTER_ENUM(e) i.push_back (e); s.push_back (#e)
@@ -304,6 +305,24 @@ setup_enum_writer ()
        REGISTER_CLASS_ENUM (Session::Event, AutoLoop);
        REGISTER (_Session_Event_Type);
 
+       REGISTER_CLASS_ENUM (Session, PostTransportStop);
+       REGISTER_CLASS_ENUM (Session, PostTransportDisableRecord);
+       REGISTER_CLASS_ENUM (Session, PostTransportPosition);
+       REGISTER_CLASS_ENUM (Session, PostTransportDidRecord);
+       REGISTER_CLASS_ENUM (Session, PostTransportDuration);
+       REGISTER_CLASS_ENUM (Session, PostTransportLocate);
+       REGISTER_CLASS_ENUM (Session, PostTransportRoll);
+       REGISTER_CLASS_ENUM (Session, PostTransportAbort);
+       REGISTER_CLASS_ENUM (Session, PostTransportOverWrite);
+       REGISTER_CLASS_ENUM (Session, PostTransportSpeed);
+       REGISTER_CLASS_ENUM (Session, PostTransportAudition);
+       REGISTER_CLASS_ENUM (Session, PostTransportScrub);
+       REGISTER_CLASS_ENUM (Session, PostTransportReverse);
+       REGISTER_CLASS_ENUM (Session, PostTransportInputChange);
+       REGISTER_CLASS_ENUM (Session, PostTransportCurveRealloc);
+       REGISTER_CLASS_ENUM (Session, PostTransportClearSubstate);
+       REGISTER_BITS (_Session_PostTransportWork);
+
        REGISTER_CLASS_ENUM (Session, Clean);
        REGISTER_CLASS_ENUM (Session, Dirty);
        REGISTER_CLASS_ENUM (Session, CannotSave);

diff --git a/libs/ardour/session_events.cc b/libs/ardour/session_events.cc
index 7304991948a9f62a27ba70e869102e925159045f..b218bbdf85b9f3b5e07b4b8fd95a939f1e1cd2cf 100644 (file)
--- a/libs/ardour/session_events.cc
+++ b/libs/ardour/session_events.cc
@@ -29,6 +29,7 @@
 #include "ardour/ardour.h"
 #include "ardour/audio_diskstream.h"
 #include "ardour/butler.h"
+#include "ardour/debug.h"
 #include "ardour/session.h"
 
 #include "i18n.h"
@@ -296,7 +297,7 @@ Session::process_event (Event* ev)
                }
        }
 
-       //printf("Processing event: %s\n", event_names[ev->type]);
+       DEBUG_TRACE (DEBUG::SessionEvents, string_compose ("Processing event: %1 @ %2\n", enum_2_string (ev->type), _transport_frame));
 
        switch (ev->type) {
        case Event::SetLoop:

diff --git a/libs/ardour/session_process.cc b/libs/ardour/session_process.cc
index 61829274048af8dc7c49feb7ffeaaedb87ffcc38..e277a2dbccf6f17e193d6bd3cde5a07d7c5851fe 100644 (file)
--- a/libs/ardour/session_process.cc
+++ b/libs/ardour/session_process.cc
@@ -31,8 +31,7 @@
 #include "ardour/audioengine.h"
 #include "ardour/auditioner.h"
 #include "ardour/butler.h"
-#include "ardour/cycle_timer.h"
-#include "ardour/cycles.h"
+#include "ardour/debug.h"
 #include "ardour/session.h"
 #include "ardour/slave.h"
 #include "ardour/timestamps.h"
@@ -494,6 +493,8 @@ Session::follow_slave (nframes_t nframes)
 
        _slave->speed_and_position (slave_speed, slave_transport_frame);
 
+       DEBUG_TRACE (DEBUG::Slave, string_compose ("Slave @ %1 speed %2\n", slave_speed, slave_transport_frame));
+
        if (!_slave->locked()) {
                goto noroll;
        }
@@ -561,14 +562,9 @@ Session::follow_slave (nframes_t nframes)
                                request_transport_speed(slave_speed);
                        } else {
                                request_transport_speed(adjusted_speed);
-                               #ifdef DEBUG_SLAVES
-                               cerr << "adjust using " << delta
-                                        << " towards " << adjusted_speed
-                                        << " ratio = " << adjusted_speed / slave_speed
-                                        << " current = " << _transport_speed
-                                        << " slave @ " << slave_speed
-                                        << endl;
-                               #endif
+                               DEBUG_TRACE (DEBUG::Slave, string_compose ("adjust using %1 towards %2 ratio %3 current %4 slave @ %5\n",
+                                                                          delta, adjusted_speed, adjusted_speed/slave_speed, _transport_speed,
+                                                                          slave_speed));
                        }
 
                        if (abs(average_slave_delta) > (long) _slave->resolution()) {
@@ -578,15 +574,17 @@ Session::follow_slave (nframes_t nframes)
                }
        }
 
-       #ifdef DEBUG_SLAVES
-       if (slave_speed != 0.0)
-       cerr << "delta = " << (int) (dir * this_delta)
-                << " speed = " << slave_speed
-                << " ts = " << _transport_speed
-                << " M@ "<< slave_transport_frame << " S@ " << _transport_frame
-                << " avgdelta = " << average_slave_delta
-                << endl;
-       #endif
+#ifndef NDEBUG
+       if (slave_speed != 0.0) {
+               DEBUG_TRACE (DEBUG::Slave, string_compose ("delta = %1 speed = %2 ts = %3 M@%4 S@%5 avgdelta %6\n",
+                                                          (int) (dir * this_delta),
+                                                          slave_speed,
+                                                          _transport_speed,
+                                                          slave_transport_frame, 
+                                                          _transport_frame,
+                                                          average_slave_delta));
+       }
+#endif
 
        if (!starting && !non_realtime_work_pending()) {
                /* speed is set, we're locked, and good to go */
@@ -594,17 +592,12 @@ Session::follow_slave (nframes_t nframes)
        }
 
   silent_motion:
-       #ifdef DEBUG_SLAVES
-       cerr << "reached silent_motion:" <<endl;
-       #endif
-
+       DEBUG_TRACE (DEBUG::Slave, "silent motion\n")
        follow_slave_silently (nframes, slave_speed);
 
   noroll:
        /* don't move at all */
-       #ifdef DEBUG_SLAVES
-       cerr << "reached no_roll:" <<endl;
-       #endif
+       DEBUG_TRACE (DEBUG::Slave, "no roll\n")
        no_roll (nframes);
        return false;
 }
@@ -721,10 +714,7 @@ Session::track_slave_state(
                }
 
                if (slave_state == Running && _transport_speed == 0.0f) {
-
-        #ifdef DEBUG_SLAVES
-                       cerr << "slave starts transport\n";
-        #endif
+                       DEBUG_TRACE (DEBUG::Slave, "slave starts transport\n");
                        start_transport ();
                }
 
@@ -733,19 +723,12 @@ Session::track_slave_state(
                /* slave has stopped */
 
                if (_transport_speed != 0.0f) {
-
-         #ifdef DEBUG_SLAVES
-                       cerr << "slave stops transport: " << slave_speed << " frame: " << slave_transport_frame
-                            << " tf = " << _transport_frame << endl;
-         #endif
-
+                       DEBUG_TRACE (DEBUG::Slave, string_compose ("slave stops transport: %1 frame %2 tf %3\n", slave_speed, slave_transport_frame, _transport_frame));
                        stop_transport();
                }
 
                if (slave_transport_frame != _transport_frame) {
-        #ifdef DEBUG_SLAVES
-                       cerr << "slave stopped, move to " << slave_transport_frame << endl;
-        #endif
+                       DEBUG_TRACE (DEBUG::Slave, string_compose ("slave stopped, move to %1\n", slave_transport_frame));
                        force_locate (slave_transport_frame, false);
                }
 

diff --git a/libs/ardour/session_transport.cc b/libs/ardour/session_transport.cc
index 0eaf8125a4e2085cf90962c80851df330b4f59a3..f0fc5da6a116f5d0054256ef7d53325333b6483f 100644 (file)
--- a/libs/ardour/session_transport.cc
+++ b/libs/ardour/session_transport.cc
@@ -26,10 +26,9 @@
 
 #include "pbd/undo.h"
 #include "pbd/error.h"
-#include <glibmm/thread.h>
+#include "pbd/enumwriter.h"
 #include "pbd/pthread_utils.h"
 #include "pbd/memento_command.h"
-#include "pbd/stacktrace.h"
 
 #include "midi++/mmc.h"
 #include "midi++/port.h"
@@ -39,6 +38,7 @@
 #include "ardour/audioengine.h"
 #include "ardour/auditioner.h"
 #include "ardour/butler.h"
+#include "ardour/debug.h"
 #include "ardour/location.h"
 #include "ardour/session.h"
 #include "ardour/slave.h"
@@ -105,6 +105,7 @@ void
 Session::request_transport_speed (double speed)
 {
        Event* ev = new Event (Event::SetTransportSpeed, Event::Add, Event::Immediate, 0, speed);
+       DEBUG_TRACE (DEBUG::Transport, string_compose ("Request transport speed = %1\n", speed));
        queue_event (ev);
 }
 
@@ -120,6 +121,7 @@ void
 Session::request_stop (bool abort, bool clear_state)
 {
        Event* ev = new Event (Event::SetTransportSpeed, Event::Add, Event::Immediate, 0, 0.0, abort, clear_state);
+       DEBUG_TRACE (DEBUG::Transport, string_compose ("Request transport stop, abort = %1, clear state = %2\n", abort, clear_state));
        queue_event (ev);
 }
 
@@ -127,6 +129,7 @@ void
 Session::request_locate (nframes_t target_frame, bool with_roll)
 {
        Event *ev = new Event (with_roll ? Event::LocateRoll : Event::Locate, Event::Add, Event::Immediate, target_frame, 0, false);
+       DEBUG_TRACE (DEBUG::Transport, string_compose ("Request locate to %1\n", target_frame));
        queue_event (ev);
 }
 
@@ -134,6 +137,7 @@ void
 Session::force_locate (nframes64_t target_frame, bool with_roll)
 {
        Event *ev = new Event (with_roll ? Event::LocateRoll : Event::Locate, Event::Add, Event::Immediate, target_frame, 0, true);
+       DEBUG_TRACE (DEBUG::Transport, string_compose ("Request forced locate to %1\n", target_frame));
        queue_event (ev);
 }
 
@@ -150,6 +154,7 @@ Session::request_play_loop (bool yn, bool leave_rolling)
        }
 
        ev = new Event (Event::SetLoop, Event::Add, Event::Immediate, 0, (leave_rolling ? 1.0 : 0.0), yn);
+       DEBUG_TRACE (DEBUG::Transport, string_compose ("Request set loop = %1, leave rolling ? %2\n", yn, leave_rolling));
        queue_event (ev);
 
        if (!leave_rolling && !yn && Config->get_seamless_loop() && transport_rolling()) {
@@ -168,12 +173,14 @@ Session::request_play_range (list<AudioRange>* range, bool leave_rolling)
        } else {
                ev->audio_range.clear ();
        }
+       DEBUG_TRACE (DEBUG::Transport, string_compose ("Request play range, leave rolling ? %1\n", leave_rolling));
        queue_event (ev);
 }
 
 void
 Session::realtime_stop (bool abort, bool clear_state)
 {
+       DEBUG_TRACE (DEBUG::Transport, "realtime stop\n");
        PostTransportWork todo = PostTransportWork (0);
 
        /* assume that when we start, we'll be moving forwards */
@@ -245,6 +252,9 @@ Session::butler_transport_work ()
        int on_entry = g_atomic_int_get (&_butler->should_do_transport_work);
        finished = true;
        ptw = post_transport_work();
+
+       DEBUG_TRACE (DEBUG::Transport, string_compose ("Butler transport work, todo = %1\n", enum_2_string (ptw)));
+                    
        if (ptw & PostTransportCurveRealloc) {
                for (RouteList::iterator i = r->begin(); i != r->end(); ++i) {
                        (*i)->curve_reallocate();
@@ -873,6 +883,8 @@ Session::locate (nframes64_t target_frame, bool with_roll, bool with_flush, bool
 void
 Session::set_transport_speed (double speed, bool abort, bool clear_state)
 {
+       DEBUG_TRACE (DEBUG::Transport, string_compose ("Set transport speed to %1, abort = %2 clear_state = %3, current = %4\n", speed, abort, clear_state, _transport_speed));
+
        if (_transport_speed == speed) {
                return;
        }