improve debug output
[ardour.git] / libs / ardour / session_process.cc
1 /*
2  * Copyright (C) 1999-2019 Paul Davis <paul@linuxaudiosystems.com>
3  * Copyright (C) 2006-2007 Jesse Chappell <jesse@essej.net>
4  * Copyright (C) 2006-2014 David Robillard <d@drobilla.net>
5  * Copyright (C) 2007-2012 Carl Hetherington <carl@carlh.net>
6  * Copyright (C) 2008-2009 Hans Baier <hansfbaier@googlemail.com>
7  * Copyright (C) 2012-2019 Robin Gareus <robin@gareus.org>
8  *
9  * This program is free software; you can redistribute it and/or modify
10  * it under the terms of the GNU General Public License as published by
11  * the Free Software Foundation; either version 2 of the License, or
12  * (at your option) any later version.
13  *
14  * This program is distributed in the hope that it will be useful,
15  * but WITHOUT ANY WARRANTY; without even the implied warranty of
16  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
17  * GNU General Public License for more details.
18  *
19  * You should have received a copy of the GNU General Public License along
20  * with this program; if not, write to the Free Software Foundation, Inc.,
21  * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA.
22  */
23
24 #include <cmath>
25 #include <cerrno>
26 #include <algorithm>
27 #include <unistd.h>
28
29 #include <boost/algorithm/string/erase.hpp>
30
31 #include "pbd/i18n.h"
32 #include "pbd/error.h"
33 #include "pbd/enumwriter.h"
34
35 #include <glibmm/threads.h>
36
37 #include "ardour/audioengine.h"
38 #include "ardour/auditioner.h"
39 #include "ardour/butler.h"
40 #include "ardour/cycle_timer.h"
41 #include "ardour/debug.h"
42 #include "ardour/disk_reader.h"
43 #include "ardour/graph.h"
44 #include "ardour/port.h"
45 #include "ardour/process_thread.h"
46 #include "ardour/scene_changer.h"
47 #include "ardour/session.h"
48 #include "ardour/transport_fsm.h"
49 #include "ardour/transport_master.h"
50 #include "ardour/transport_master_manager.h"
51 #include "ardour/ticker.h"
52 #include "ardour/types.h"
53 #include "ardour/vca.h"
54 #include "ardour/vca_manager.h"
55
56 #include "midi++/mmc.h"
57
58 using namespace ARDOUR;
59 using namespace PBD;
60 using namespace std;
61
62 #define TFSM_EVENT(evtype) { _transport_fsm->enqueue (new TransportFSM::Event (evtype)); }
63 #define TFSM_STOP(abort,clear) { _transport_fsm->enqueue (new TransportFSM::Event (TransportFSM::StopTransport,abort,clear)); }
64 #define TFSM_LOCATE(target,roll,flush,loop,force) { _transport_fsm->enqueue (new TransportFSM::Event (TransportFSM::Locate,target,roll,flush,loop,force)); }
65
66
67 /** Called by the audio engine when there is work to be done with JACK.
68  * @param nframes Number of samples to process.
69  */
70
71 void
72 Session::process (pframes_t nframes)
73 {
74         samplepos_t transport_at_start = _transport_sample;
75
76         _silent = false;
77
78         if (processing_blocked()) {
79                 _silent = true;
80                 return;
81         }
82
83         if (non_realtime_work_pending()) {
84                 DEBUG_TRACE (DEBUG::Butler, string_compose ("non-realtime work pending: %1 (%2%3%4)\n", enum_2_string (post_transport_work()), std::hex, post_transport_work(), std::dec));
85                 if (!_butler->transport_work_requested ()) {
86                         DEBUG_TRACE (DEBUG::Butler, string_compose ("done, waiting? %1\n", _transport_fsm->waiting_for_butler()));
87                         butler_completed_transport_work ();
88                 } else {
89                         DEBUG_TRACE (DEBUG::Butler, "doesn't seem to have finished yet (from view of RT thread)\n");
90                 }
91         }
92
93         _engine.main_thread()->get_buffers ();
94
95         (this->*process_function) (nframes);
96
97         /* realtime-safe meter-position and processor-order changes
98          *
99          * ideally this would be done in
100          * Route::process_output_buffers() but various functions
101          * callig it hold a _processor_lock reader-lock
102          */
103         boost::shared_ptr<RouteList> r = routes.reader ();
104         bool one_or_more_routes_declicking = false;
105         for (RouteList::const_iterator i = r->begin(); i != r->end(); ++i) {
106                 if ((*i)->apply_processor_changes_rt()) {
107                         _rt_emit_pending = true;
108                 }
109                 if ((*i)->declick_in_progress()) {
110                         one_or_more_routes_declicking = true;
111                 }
112         }
113
114         if (_rt_emit_pending) {
115                 if (!_rt_thread_active) {
116                         emit_route_signals ();
117                 }
118                 if (pthread_mutex_trylock (&_rt_emit_mutex) == 0) {
119                         pthread_cond_signal (&_rt_emit_cond);
120                         pthread_mutex_unlock (&_rt_emit_mutex);
121                         _rt_emit_pending = false;
122                 }
123         }
124
125         /* We are checking two things here:
126          *
127          * 1) whether or not all tracks have finished a declick out.
128          * 2) is the transport FSM waiting to be told this
129          */
130
131         if (!one_or_more_routes_declicking && declick_in_progress()) {
132                 /* end of the declick has been reached by all routes */
133                 TFSM_EVENT (TransportFSM::DeclickDone);
134         }
135
136         _engine.main_thread()->drop_buffers ();
137
138         /* deliver MIDI clock. Note that we need to use the transport sample
139          * position at the start of process(), not the value at the end of
140          * it. We may already have ticked() because of a transport state
141          * change, for example.
142          */
143
144         try {
145                 if (!_silent && !_engine.freewheeling() && Config->get_send_midi_clock() && (transport_speed() == 1.0f || transport_speed() == 0.0f) && midi_clock->has_midi_port()) {
146                         midi_clock->tick (transport_at_start, nframes);
147                 }
148
149                 _scene_changer->run (transport_at_start, transport_at_start + nframes);
150
151         } catch (...) {
152                 /* don't bother with a message */
153         }
154
155         SendFeedback (); /* EMIT SIGNAL */
156 }
157
158 int
159 Session::fail_roll (pframes_t nframes)
160 {
161         return no_roll (nframes);
162 }
163
164 int
165 Session::no_roll (pframes_t nframes)
166 {
167         PT_TIMING_CHECK (4);
168
169         samplepos_t end_sample = _transport_sample + nframes; // FIXME: varispeed + no_roll ??
170         int ret = 0;
171         boost::shared_ptr<RouteList> r = routes.reader ();
172
173         if (_click_io) {
174                 _click_io->silence (nframes);
175         }
176
177         ltc_tx_send_time_code_for_cycle (_transport_sample, end_sample, _target_transport_speed, _transport_speed, nframes);
178
179         VCAList v = _vca_manager->vcas ();
180         for (VCAList::const_iterator i = v.begin(); i != v.end(); ++i) {
181                 (*i)->automation_run (_transport_sample, nframes);
182         }
183
184         _global_locate_pending = locate_pending ();
185
186         if (_process_graph) {
187                 DEBUG_TRACE(DEBUG::ProcessThreads,"calling graph/no-roll\n");
188                 _process_graph->routes_no_roll( nframes, _transport_sample, end_sample, non_realtime_work_pending());
189         } else {
190                 PT_TIMING_CHECK (10);
191                 for (RouteList::iterator i = r->begin(); i != r->end(); ++i) {
192
193                         if ((*i)->is_auditioner()) {
194                                 continue;
195                         }
196
197                         if ((*i)->no_roll (nframes, _transport_sample, end_sample, non_realtime_work_pending())) {
198                                 error << string_compose(_("Session: error in no roll for %1"), (*i)->name()) << endmsg;
199                                 ret = -1;
200                                 break;
201                         }
202                 }
203                 PT_TIMING_CHECK (11);
204         }
205
206         PT_TIMING_CHECK (5);
207         return ret;
208 }
209
210 /** @param need_butler to be set to true by this method if it needs the butler,
211  *  otherwise it must be left alone.
212  */
213 int
214 Session::process_routes (pframes_t nframes, bool& need_butler)
215 {
216         boost::shared_ptr<RouteList> r = routes.reader ();
217
218         const samplepos_t start_sample = _transport_sample;
219         const samplepos_t end_sample = _transport_sample + floor (nframes * _transport_speed);
220
221         VCAList v = _vca_manager->vcas ();
222         for (VCAList::const_iterator i = v.begin(); i != v.end(); ++i) {
223                 (*i)->automation_run (start_sample, nframes);
224         }
225
226         _global_locate_pending = locate_pending();
227
228         if (_process_graph) {
229                 DEBUG_TRACE(DEBUG::ProcessThreads,"calling graph/process-routes\n");
230                 if (_process_graph->process_routes (nframes, start_sample, end_sample, need_butler) < 0) {
231                         stop_transport ();
232                         return -1;
233                 }
234         } else {
235
236                 for (RouteList::iterator i = r->begin(); i != r->end(); ++i) {
237
238                         int ret;
239
240                         if ((*i)->is_auditioner()) {
241                                 continue;
242                         }
243
244                         bool b = false;
245
246                         if ((ret = (*i)->roll (nframes, start_sample, end_sample, b)) < 0) {
247                                 TFSM_STOP (false, false);
248                                 return -1;
249                         }
250
251                         if (b) {
252                                 DEBUG_TRACE (DEBUG::Butler, string_compose ("%1 rolled and needs butler\n", (*i)->name()));
253                                 need_butler = true;
254                         }
255                 }
256         }
257
258         return 0;
259 }
260
261 void
262 Session::get_track_statistics ()
263 {
264         float pworst = 1.0f;
265         float cworst = 1.0f;
266
267         boost::shared_ptr<RouteList> rl = routes.reader();
268         for (RouteList::iterator i = rl->begin(); i != rl->end(); ++i) {
269
270                 boost::shared_ptr<Track> tr = boost::dynamic_pointer_cast<Track> (*i);
271
272                 if (!tr || tr->is_private_route()) {
273                         continue;
274                 }
275
276                 pworst = min (pworst, tr->playback_buffer_load());
277                 cworst = min (cworst, tr->capture_buffer_load());
278         }
279
280         g_atomic_int_set (&_playback_load, (uint32_t) floor (pworst * 100.0f));
281         g_atomic_int_set (&_capture_load, (uint32_t) floor (cworst * 100.0f));
282
283         if (actively_recording()) {
284                 set_dirty();
285         }
286 }
287
288 bool
289 Session::compute_audible_delta (samplepos_t& pos_and_delta) const
290 {
291         if (_transport_speed == 0.0 || _count_in_samples > 0 || _remaining_latency_preroll > 0) {
292                 /* cannot compute audible delta, because the session is
293                    generating silence that does not correspond to the timeline,
294                    but is instead filling playback buffers to manage latency
295                    alignment.
296                 */
297                 DEBUG_TRACE (DEBUG::Slave, string_compose ("still adjusting for latency (%1) and/or count-in (%2) or stopped %1\n", _remaining_latency_preroll, _count_in_samples, _transport_speed));
298                 return false;
299         }
300
301         pos_and_delta -= _transport_sample;
302         return true;
303 }
304
305 /** Process callback used when the auditioner is not active */
306 void
307 Session::process_with_events (pframes_t nframes)
308 {
309         PT_TIMING_CHECK (3);
310
311         SessionEvent*  ev;
312         pframes_t      this_nframes;
313         samplepos_t     end_sample;
314         bool           session_needs_butler = false;
315         samplecnt_t     samples_moved;
316
317         /* make sure the auditioner is silent */
318
319         if (auditioner) {
320                 auditioner->silence (nframes);
321         }
322
323         /* handle any pending events */
324
325         while (pending_events.read (&ev, 1) == 1) {
326                 merge_event (ev);
327         }
328
329         /* if we are not in the middle of a state change,
330            and there are immediate events queued up,
331            process them.
332         */
333
334         while (!non_realtime_work_pending() && !immediate_events.empty()) {
335                 SessionEvent *ev = immediate_events.front ();
336                 immediate_events.pop_front ();
337                 process_event (ev);
338         }
339         /* only count-in when going to roll at speed 1.0 */
340         if (_transport_speed != 1.0 && _count_in_samples > 0) {
341                 _count_in_samples = 0;
342         }
343         if (_transport_speed == 0.0) {
344                 _remaining_latency_preroll = 0;
345         }
346
347         assert (_count_in_samples == 0 || _remaining_latency_preroll == 0 || _count_in_samples == _remaining_latency_preroll);
348
349         // DEBUG_TRACE (DEBUG::Transport, string_compose ("Running count in/latency preroll of %1 & %2\n", _count_in_samples, _remaining_latency_preroll));
350
351         while (_count_in_samples > 0 || _remaining_latency_preroll > 0) {
352                 samplecnt_t ns;
353
354                 if (_remaining_latency_preroll > 0) {
355                         ns = std::min ((samplecnt_t)nframes, _remaining_latency_preroll);
356                 } else {
357                         ns = std::min ((samplecnt_t)nframes, _count_in_samples);
358                 }
359
360                 boost::shared_ptr<RouteList> r = routes.reader ();
361                 for (RouteList::iterator i = r->begin(); i != r->end(); ++i) {
362                         samplecnt_t route_offset = (*i)->playback_latency ();
363                         if (_remaining_latency_preroll > route_offset + ns) {
364                                 /* route will no-roll for complete pre-roll cycle */
365                                 continue;
366                         }
367                         if (_remaining_latency_preroll > route_offset) {
368                                 /* route may need partial no-roll and partial roll from
369                                 * (_transport_sample - _remaining_latency_preroll) ..  +ns.
370                                 * shorten and split the cycle.
371                                 */
372                                 ns = std::min (ns, (_remaining_latency_preroll - route_offset));
373                         }
374                 }
375
376                 if (_count_in_samples > 0) {
377                         run_click (_transport_sample - _count_in_samples, ns);
378                         assert (_count_in_samples >= ns);
379                         _count_in_samples -= ns;
380                 }
381
382                 if (_remaining_latency_preroll > 0) {
383                         if (_count_in_samples == 0) {
384                                 click (_transport_sample - _remaining_latency_preroll, ns);
385                         }
386                         if (process_routes (ns, session_needs_butler)) {
387                                 fail_roll (ns);
388                         }
389                 } else {
390                         no_roll (ns);
391                 }
392
393                 if (_remaining_latency_preroll > 0) {
394                         assert (_remaining_latency_preroll >= ns);
395                         _remaining_latency_preroll -= ns;
396                 }
397
398                 nframes -= ns;
399
400                 /* process events.. */
401                 if (!events.empty() && next_event != events.end()) {
402                         SessionEvent* this_event = *next_event;
403                         Events::iterator the_next_one = next_event;
404                         ++the_next_one;
405
406                         while (this_event && this_event->action_sample == _transport_sample) {
407                                 process_event (this_event);
408                                 if (the_next_one == events.end()) {
409                                         this_event = 0;
410                                 } else {
411                                         this_event = *the_next_one;
412                                         ++the_next_one;
413                                 }
414                         }
415                         set_next_event ();
416                 }
417
418                 if (nframes == 0) {
419                         return;
420                 } else {
421                         _engine.split_cycle (ns);
422                 }
423         }
424
425         /* Decide on what to do with quarter-frame MTC during this cycle */
426
427         bool const was_sending_qf_mtc = _send_qf_mtc;
428         double const tolerance = Config->get_mtc_qf_speed_tolerance() / 100.0;
429
430         if (_transport_speed != 0) {
431                 _send_qf_mtc = (
432                         Config->get_send_mtc () &&
433                         _transport_speed >= (1 - tolerance) &&
434                         _transport_speed <= (1 + tolerance)
435                         );
436
437                 if (_send_qf_mtc && !was_sending_qf_mtc) {
438                         /* we will re-start quarter-frame MTC this cycle, so send a full update to set things up */
439                         _send_timecode_update = true;
440                 }
441
442                 if (Config->get_send_mtc() && !_send_qf_mtc && _pframes_since_last_mtc > (sample_rate () / 4)) {
443                         /* we're sending MTC, but we're not sending QF MTC at the moment, and it's been
444                            a quarter of a second since we sent anything at all, so send a full MTC update
445                            this cycle.
446                         */
447                         _send_timecode_update = true;
448                 }
449
450                 _pframes_since_last_mtc += nframes;
451         }
452
453         /* Events caused a transport change (or we re-started sending
454          * MTC), so send an MTC Full Frame (Timecode) message.  This
455          * is sent whether rolling or not, to give slaves an idea of
456          * ardour time on locates (and allow slow slaves to position
457          * and prepare for rolling)
458          */
459         if (_send_timecode_update) {
460                 send_full_time_code (_transport_sample, nframes);
461         }
462
463         if (!process_can_proceed()) {
464                 _silent = true;
465                 return;
466         }
467
468         if (events.empty() || next_event == events.end()) {
469                 try_run_lua (nframes); // also during export ?? ->move to process_without_events()
470                 /* lua scripts may inject events */
471                 while (_n_lua_scripts > 0 && pending_events.read (&ev, 1) == 1) {
472                         merge_event (ev);
473                 }
474                 if (events.empty() || next_event == events.end()) {
475                         process_without_events (nframes);
476                         return;
477                 }
478         }
479
480         assert (_transport_speed == 0 || _transport_speed == 1.0 || _transport_speed == -1.0);
481
482         samples_moved = (samplecnt_t) nframes * _transport_speed;
483         DEBUG_TRACE (DEBUG::Transport, string_compose ("plan to move transport by %1 (%2 @ %3)\n", samples_moved, nframes, _transport_speed));
484
485         end_sample = _transport_sample + samples_moved;
486
487         {
488                 SessionEvent* this_event;
489                 Events::iterator the_next_one;
490
491                 if (!process_can_proceed()) {
492                         _silent = true;
493                         return;
494                 }
495
496                 if (!_exporting && config.get_external_sync()) {
497                         if (!follow_transport_master (nframes)) {
498                                 ltc_tx_send_time_code_for_cycle (_transport_sample, end_sample, _target_transport_speed, _transport_speed, nframes);
499                                 return;
500                         }
501                 }
502
503                 if (_transport_speed == 0) {
504                         no_roll (nframes);
505                         return;
506                 }
507
508                 if (!_exporting && !timecode_transmission_suspended()) {
509                         send_midi_time_code_for_cycle (_transport_sample, end_sample, nframes);
510                 }
511
512                 ltc_tx_send_time_code_for_cycle (_transport_sample, end_sample, _target_transport_speed, _transport_speed, nframes);
513
514                 samplepos_t stop_limit = compute_stop_limit ();
515
516                 if (maybe_stop (stop_limit)) {
517                         no_roll (nframes);
518                         return;
519                 }
520
521                 this_event = *next_event;
522                 the_next_one = next_event;
523                 ++the_next_one;
524
525                 /* yes folks, here it is, the actual loop where we really truly
526                    process some audio
527                 */
528
529                 while (nframes) {
530
531                         this_nframes = nframes; /* real (jack) time relative */
532                         samples_moved = (samplecnt_t) floor (_transport_speed * nframes); /* transport relative */
533                         DEBUG_TRACE (DEBUG::Transport, string_compose ("sub-loop plan to move transport by %1 (%2 @ %3)\n", samples_moved, nframes, _transport_speed));
534
535                         /* running an event, position transport precisely to its time */
536                         if (this_event && this_event->action_sample <= end_sample && this_event->action_sample >= _transport_sample) {
537                                 /* this isn't quite right for reverse play */
538                                 samples_moved = (samplecnt_t) (this_event->action_sample - _transport_sample);
539                                 DEBUG_TRACE (DEBUG::Transport, string_compose ("sub-loop2 (for %4)plan to move transport by %1 (%2 @ %3)\n", samples_moved, nframes, _transport_speed, enum_2_string (this_event->type)));
540                                 this_nframes = abs (floor(samples_moved / _transport_speed));
541                         }
542
543                         try_run_lua (this_nframes);
544
545                         if (this_nframes) {
546
547                                 click (_transport_sample, this_nframes);
548
549                                 if (process_routes (this_nframes, session_needs_butler)) {
550                                         fail_roll (nframes);
551                                         return;
552                                 }
553
554                                 get_track_statistics ();
555
556                                 nframes -= this_nframes;
557
558                                 if (samples_moved < 0) {
559                                         decrement_transport_position (-samples_moved);
560                                 } else if (samples_moved) {
561                                         increment_transport_position (samples_moved);
562                                 } else {
563                                         DEBUG_TRACE (DEBUG::Transport, "no transport motion\n");
564                                 }
565
566                                 maybe_stop (stop_limit);
567                         }
568
569                         if (nframes > 0) {
570                                 _engine.split_cycle (this_nframes);
571                         }
572
573                         /* now handle this event and all others scheduled for the same time */
574
575                         while (this_event && this_event->action_sample == _transport_sample) {
576                                 process_event (this_event);
577
578                                 if (the_next_one == events.end()) {
579                                         this_event = 0;
580                                 } else {
581                                         this_event = *the_next_one;
582                                         ++the_next_one;
583                                 }
584                         }
585
586                         /* if an event left our state changing, do the right thing */
587
588                         if (nframes && non_realtime_work_pending()) {
589                                 no_roll (nframes);
590                                 break;
591                         }
592
593                         /* this is necessary to handle the case of seamless looping */
594                         end_sample = _transport_sample + floor (nframes * _transport_speed);
595                 }
596
597                 set_next_event ();
598
599         } /* implicit release of route lock */
600
601         if (session_needs_butler) {
602                 DEBUG_TRACE (DEBUG::Butler, "p-with-events: session needs butler, call it\n");
603                 _butler->summon ();
604         }
605 }
606
607 bool
608 Session::transport_locked () const
609 {
610         if (!locate_pending() && (!config.get_external_sync() || (transport_master()->ok() && transport_master()->locked()))) {
611                 return true;
612         }
613
614         return false;
615 }
616
617 void
618 Session::process_without_events (pframes_t nframes)
619 {
620         bool session_needs_butler = false;
621         samplecnt_t samples_moved;
622
623         if (!process_can_proceed()) {
624                 _silent = true;
625                 return;
626         }
627
628         if (!_exporting && config.get_external_sync()) {
629                 if (!follow_transport_master (nframes)) {
630                         ltc_tx_send_time_code_for_cycle (_transport_sample, _transport_sample, 0, 0 , nframes);
631                         return;
632                 }
633         }
634
635         assert (_transport_speed == 0 || _transport_speed == 1.0 || _transport_speed == -1.0);
636
637         if (_transport_speed == 0) {
638                 no_roll (nframes);
639                 return;
640         } else {
641                 samples_moved = (samplecnt_t) nframes * _transport_speed;
642         }
643
644         if (!_exporting && !timecode_transmission_suspended()) {
645                 send_midi_time_code_for_cycle (_transport_sample, _transport_sample + samples_moved, nframes);
646         }
647
648         ltc_tx_send_time_code_for_cycle (_transport_sample, _transport_sample + samples_moved, _target_transport_speed, _transport_speed, nframes);
649
650         samplepos_t const stop_limit = compute_stop_limit ();
651
652         if (maybe_stop (stop_limit)) {
653                 no_roll (nframes);
654                 return;
655         }
656
657         if (maybe_sync_start (nframes)) {
658                 return;
659         }
660
661         click (_transport_sample, nframes);
662
663         if (process_routes (nframes, session_needs_butler)) {
664                 fail_roll (nframes);
665                 return;
666         }
667
668         get_track_statistics ();
669
670         if (samples_moved < 0) {
671                 decrement_transport_position (-samples_moved);
672                 //DEBUG_TRACE (DEBUG::Transport, string_compose ("DEcrement transport by %1 to %2\n", samples_moved, _transport_sample));
673         } else if (samples_moved) {
674                 increment_transport_position (samples_moved);
675                 //DEBUG_TRACE (DEBUG::Transport, string_compose ("INcrement transport by %1 to %2\n", samples_moved, _transport_sample));
676         } else {
677                 DEBUG_TRACE (DEBUG::Transport, "no transport motion\n");
678         }
679
680         maybe_stop (stop_limit);
681
682         if (session_needs_butler) {
683                 DEBUG_TRACE (DEBUG::Butler, "p-without-events: session needs butler, call it\n");
684                 _butler->summon ();
685         }
686 }
687
688 /** Process callback used when the auditioner is active.
689  * @param nframes number of samples to process.
690  */
691 void
692 Session::process_audition (pframes_t nframes)
693 {
694         SessionEvent* ev;
695         boost::shared_ptr<RouteList> r = routes.reader ();
696
697         for (RouteList::iterator i = r->begin(); i != r->end(); ++i) {
698                 if (!(*i)->is_auditioner()) {
699                         (*i)->silence (nframes);
700                 }
701         }
702
703         /* run the auditioner, and if it says we need butler service, ask for it */
704
705         if (auditioner->play_audition (nframes) > 0) {
706                 DEBUG_TRACE (DEBUG::Butler, "auditioner needs butler, call it\n");
707                 _butler->summon ();
708         }
709
710         /* if using a monitor section, run it because otherwise we don't hear anything */
711
712         if (_monitor_out && auditioner->needs_monitor()) {
713                 _monitor_out->monitor_run (_transport_sample, _transport_sample + nframes, nframes);
714         }
715
716         /* handle pending events */
717
718         while (pending_events.read (&ev, 1) == 1) {
719                 merge_event (ev);
720         }
721
722         /* if we are not in the middle of a state change,
723            and there are immediate events queued up,
724            process them.
725         */
726
727         while (!non_realtime_work_pending() && !immediate_events.empty()) {
728                 SessionEvent *ev = immediate_events.front ();
729                 immediate_events.pop_front ();
730                 process_event (ev);
731         }
732
733         if (!auditioner->auditioning()) {
734                 /* auditioner no longer active, so go back to the normal process callback */
735                 process_function = &Session::process_with_events;
736         }
737 }
738
739 bool
740 Session::maybe_sync_start (pframes_t & nframes)
741 {
742         pframes_t sync_offset;
743
744         if (!waiting_for_sync_offset) {
745                 return false;
746         }
747
748         if (_engine.get_sync_offset (sync_offset) && sync_offset < nframes) {
749
750                 /* generate silence up to the sync point, then
751                    adjust nframes + offset to reflect whatever
752                    is left to do.
753                 */
754
755                 no_roll (sync_offset);
756                 nframes -= sync_offset;
757                 Port::increment_global_port_buffer_offset (sync_offset);
758                 waiting_for_sync_offset = false;
759
760                 if (nframes == 0) {
761                         return true; // done, nothing left to process
762                 }
763
764         } else {
765
766                 /* sync offset point is not within this process()
767                    cycle, so just generate silence. and don't bother
768                    with any fancy stuff here, just the minimal silence.
769                 */
770
771                 _silent = true;
772
773                 if (Config->get_locate_while_waiting_for_sync()) {
774                         DEBUG_TRACE (DEBUG::Transport, "micro-locate while waiting for sync\n");
775                         if (micro_locate (nframes)) {
776                                 /* XXX ERROR !!! XXX */
777                         }
778                 }
779
780                 return true; // done, nothing left to process
781         }
782
783         return false;
784 }
785
786 void
787 Session::queue_event (SessionEvent* ev)
788 {
789         if (deletion_in_progress ()) {
790                 return;
791         } else if (loading ()) {
792                 merge_event (ev);
793         } else {
794                 Glib::Threads::Mutex::Lock lm (rb_write_lock);
795                 pending_events.write (&ev, 1);
796         }
797 }
798
799 void
800 Session::set_next_event ()
801 {
802         if (events.empty()) {
803                 next_event = events.end();
804                 return;
805         }
806
807         if (next_event == events.end()) {
808                 next_event = events.begin();
809         }
810
811         if ((*next_event)->action_sample > _transport_sample) {
812                 next_event = events.begin();
813         }
814
815         for (; next_event != events.end(); ++next_event) {
816                 if ((*next_event)->action_sample >= _transport_sample) {
817                         break;
818                 }
819         }
820 }
821
822 void
823 Session::process_event (SessionEvent* ev)
824 {
825         bool remove = true;
826         bool del = true;
827
828         /* if we're in the middle of a state change (i.e. waiting
829            for the butler thread to complete the non-realtime
830            part of the change), we'll just have to queue this
831            event for a time when the change is complete.
832         */
833
834         if (non_realtime_work_pending()) {
835
836                 /* except locates, which we have the capability to handle */
837
838                 if (ev->type != SessionEvent::Locate) {
839                         immediate_events.insert (immediate_events.end(), ev);
840                         _remove_event (ev);
841                         return;
842                 }
843         }
844
845         DEBUG_TRACE (DEBUG::SessionEvents, string_compose ("Processing event: %1 @ %2\n", enum_2_string (ev->type), _transport_sample));
846
847         switch (ev->type) {
848         case SessionEvent::SetLoop:
849                 set_play_loop (ev->yes_or_no, ev->speed);
850                 break;
851
852         case SessionEvent::AutoLoop:
853                 if (play_loop) {
854                         /* roll after locate, do not flush, set "with loop"
855                            true only if we are seamless looping
856                         */
857                         TFSM_LOCATE (ev->target_sample, true, false, Config->get_seamless_loop(), false);
858                 }
859                 remove = false;
860                 del = false;
861                 break;
862
863         case SessionEvent::Locate:
864                 /* args: do not roll after locate, do flush, not with loop, force */
865                 TFSM_LOCATE (ev->target_sample, false, true, false, ev->yes_or_no);
866                 _send_timecode_update = true;
867                 break;
868
869         case SessionEvent::LocateRoll:
870                 /* args: roll after locate, do flush, not with loop, force */
871                 TFSM_LOCATE (ev->target_sample, true, true, false, ev->yes_or_no);
872                 _send_timecode_update = true;
873                 break;
874
875         case SessionEvent::Skip:
876                 if (Config->get_skip_playback()) {
877                         TFSM_LOCATE (ev->target_sample, true, true, false, false);
878                         _send_timecode_update = true;
879                 }
880                 remove = false;
881                 del = false;
882                 break;
883
884         case SessionEvent::LocateRollLocate:
885                 // locate is handled by ::request_roll_at_and_return()
886                 _requested_return_sample = ev->target_sample;
887                 request_locate (ev->target2_sample, true);
888                 break;
889
890
891         case SessionEvent::SetTransportSpeed:
892                 set_transport_speed (ev->speed, ev->target_sample, ev->yes_or_no, ev->second_yes_or_no, ev->third_yes_or_no);
893                 break;
894
895         case SessionEvent::SetTransportMaster:
896                 TransportMasterManager::instance().set_current (ev->transport_master);
897                 break;
898
899         case SessionEvent::PunchIn:
900                 // cerr << "PunchIN at " << transport_sample() << endl;
901                 if (config.get_punch_in() && record_status() == Enabled) {
902                         enable_record ();
903                 }
904                 remove = false;
905                 del = false;
906                 break;
907
908         case SessionEvent::PunchOut:
909                 // cerr << "PunchOUT at " << transport_sample() << endl;
910                 if (config.get_punch_out()) {
911                         step_back_from_record ();
912                 }
913                 remove = false;
914                 del = false;
915                 break;
916
917         case SessionEvent::RangeStop:
918                 TFSM_STOP (ev->yes_or_no, false);
919                 remove = false;
920                 del = false;
921                 break;
922
923         case SessionEvent::RangeLocate:
924                 /* args: roll after locate, do flush, not with loop */
925                 TFSM_LOCATE (ev->target_sample, true, true, false, false);
926                 remove = false;
927                 del = false;
928                 break;
929
930         case SessionEvent::Overwrite:
931                 overwrite_some_buffers (static_cast<Track*>(ev->ptr));
932                 break;
933
934         case SessionEvent::Audition:
935                 set_audition (ev->region);
936                 // drop reference to region
937                 ev->region.reset ();
938                 break;
939
940         case SessionEvent::SetPlayAudioRange:
941                 set_play_range (ev->audio_range, (ev->speed == 1.0f));
942                 break;
943
944         case SessionEvent::CancelPlayAudioRange:
945                 unset_play_range();
946                 break;
947
948         case SessionEvent::RealTimeOperation:
949                 process_rtop (ev);
950                 del = false; // other side of RT request needs to clean up
951                 break;
952
953         case SessionEvent::AdjustPlaybackBuffering:
954                 schedule_playback_buffering_adjustment ();
955                 break;
956
957         case SessionEvent::AdjustCaptureBuffering:
958                 schedule_capture_buffering_adjustment ();
959                 break;
960
961         case SessionEvent::SetTimecodeTransmission:
962                 g_atomic_int_set (&_suspend_timecode_transmission, ev->yes_or_no ? 0 : 1);
963                 break;
964
965         default:
966           fatal << string_compose(_("Programming error: illegal event type in process_event (%1)"), ev->type) << endmsg;
967                 abort(); /*NOTREACHED*/
968                 break;
969         };
970
971         if (remove) {
972                 del = del && !_remove_event (ev);
973         }
974
975         if (del) {
976                 delete ev;
977         }
978 }
979
980 samplepos_t
981 Session::compute_stop_limit () const
982 {
983         if (!Config->get_stop_at_session_end ()) {
984                 return max_samplepos;
985         }
986
987         if (config.get_external_sync()) {
988                 return max_samplepos;
989         }
990
991         bool const punching_in = (config.get_punch_in () && _locations->auto_punch_location());
992         bool const punching_out = (config.get_punch_out () && _locations->auto_punch_location());
993
994         if (actively_recording ()) {
995                 /* permanently recording */
996                 return max_samplepos;
997         } else if (punching_in && !punching_out) {
998                 /* punching in but never out */
999                 return max_samplepos;
1000         } else if (punching_in && punching_out && _locations->auto_punch_location()->end() > current_end_sample()) {
1001                 /* punching in and punching out after session end */
1002                 return max_samplepos;
1003         }
1004
1005         return current_end_sample ();
1006 }
1007
1008
1009
1010 /* dedicated thread for signal emission.
1011  *
1012  * while sending cross-thread signals from the process thread
1013  * is fine in general, PBD::Signal's use of boost::function and
1014  * boost:bind can produce a vast overhead which is not
1015  * acceptable for low latency.
1016  *
1017  * This works around the issue by moving the boost overhead
1018  * out of the RT thread. The overall load is probably higher but
1019  * the realtime thread remains unaffected.
1020  */
1021
1022 void
1023 Session::emit_route_signals ()
1024 {
1025         // TODO use RAII to allow using these signals in other places
1026         BatchUpdateStart(); /* EMIT SIGNAL */
1027         boost::shared_ptr<RouteList> r = routes.reader ();
1028         for (RouteList::const_iterator ci = r->begin(); ci != r->end(); ++ci) {
1029                 (*ci)->emit_pending_signals ();
1030         }
1031         BatchUpdateEnd(); /* EMIT SIGNAL */
1032 }
1033
1034 void
1035 Session::emit_thread_start ()
1036 {
1037         if (_rt_thread_active) {
1038                 return;
1039         }
1040         _rt_thread_active = true;
1041
1042         if (pthread_create (&_rt_emit_thread, NULL, emit_thread, this)) {
1043                 _rt_thread_active = false;
1044         }
1045 }
1046
1047 void
1048 Session::emit_thread_terminate ()
1049 {
1050         if (!_rt_thread_active) {
1051                 return;
1052         }
1053         _rt_thread_active = false;
1054
1055         if (pthread_mutex_lock (&_rt_emit_mutex) == 0) {
1056                 pthread_cond_signal (&_rt_emit_cond);
1057                 pthread_mutex_unlock (&_rt_emit_mutex);
1058         }
1059
1060         void *status;
1061         pthread_join (_rt_emit_thread, &status);
1062 }
1063
1064 void *
1065 Session::emit_thread (void *arg)
1066 {
1067         Session *s = static_cast<Session *>(arg);
1068         s->emit_thread_run ();
1069         pthread_exit (0);
1070         return 0;
1071 }
1072
1073 void
1074 Session::emit_thread_run ()
1075 {
1076         pthread_mutex_lock (&_rt_emit_mutex);
1077         while (_rt_thread_active) {
1078                 emit_route_signals();
1079                 pthread_cond_wait (&_rt_emit_cond, &_rt_emit_mutex);
1080         }
1081         pthread_mutex_unlock (&_rt_emit_mutex);
1082 }
1083
1084 bool
1085 Session::follow_transport_master (pframes_t nframes)
1086 {
1087         TransportMasterManager& tmm (TransportMasterManager::instance());
1088
1089         double slave_speed;
1090         samplepos_t slave_transport_sample;
1091         sampleoffset_t delta;
1092
1093         if (tmm.master_invalid_this_cycle()) {
1094                 DEBUG_TRACE (DEBUG::Slave, "session told not to use the transport master this cycle\n");
1095                 goto noroll;
1096         }
1097
1098         slave_speed = tmm.get_current_speed_in_process_context();
1099         slave_transport_sample = tmm.get_current_position_in_process_context ();
1100         delta = _transport_sample - slave_transport_sample;
1101
1102         DEBUG_TRACE (DEBUG::Slave, string_compose ("session at %1, master at %2, delta: %3 res: %4\n", _transport_sample, slave_transport_sample, delta, tmm.current()->resolution()));
1103
1104         /* This is a heuristic rather than a strictly provable rule. The idea
1105          * is that if we're "far away" from the master, we should locate to its
1106          * current position, and then varispeed to sync with it.
1107          *
1108          * On the other hand, if we're close to it, just varispeed.
1109          */
1110
1111         if (!actively_recording() && abs (delta) > (5 * current_block_size)) {
1112                 DiskReader::inc_no_disk_output ();
1113                 if (!_transport_fsm->locating()) {
1114                         DEBUG_TRACE (DEBUG::Slave, string_compose ("request locate to master position %1\n", slave_transport_sample));
1115                         TFSM_LOCATE (slave_transport_sample, true, true, false, false);
1116                 }
1117                 return true;
1118         }
1119
1120         if (slave_speed != 0.0) {
1121                 if (_transport_speed == 0.0f) {
1122                         DEBUG_TRACE (DEBUG::Slave, string_compose ("slave starts transport: %1 sample %2 tf %3\n", slave_speed, slave_transport_sample, _transport_sample));
1123                         TFSM_EVENT (TransportFSM::StartTransport);
1124                 }
1125         } else {
1126                 if (_transport_speed != 0.0f) {
1127                         DEBUG_TRACE (DEBUG::Slave, string_compose ("slave stops transport: %1 sample %2 tf %3\n", slave_speed, slave_transport_sample, _transport_sample));
1128                         TFSM_STOP (false, false);
1129                 }
1130         }
1131
1132         /* This is the second part of the "we're not synced yet" code. If we're
1133          * close, but not within the resolution of the master, silence disk
1134          * output but continue to varispeed to get in sync.
1135          */
1136
1137         if (!actively_recording() && abs (delta) > tmm.current()->resolution()) {
1138                 /* just varispeed to chase the master, and be silent till we're synced */
1139                 DiskReader::inc_no_disk_output ();
1140                 return true;
1141         }
1142
1143         /* speed is set, we're locked, and good to go */
1144         DiskReader::dec_no_disk_output ();
1145         return true;
1146
1147   noroll:
1148         /* don't move at all */
1149         DEBUG_TRACE (DEBUG::Slave, "no roll\n")
1150         no_roll (nframes);
1151         return false;
1152 }
1153
1154 void
1155 Session::reset_slave_state ()
1156 {
1157         transport_master_tracking_state = Stopped;
1158         DiskReader::dec_no_disk_output ();
1159 }