more DEBUG::Butler output, formatting corrections, and a warning on cerr if capture...
[ardour.git] / libs / ardour / butler.cc
1 /*
2     Copyright (C) 1999-2009 Paul Davis
3
4     This program is free software; you can redistribute it and/or modify
5     it under the terms of the GNU General Public License as published by
6     the Free Software Foundation; either version 2 of the License, or
7     (at your option) any later version.
8
9     This program is distributed in the hope that it will be useful,
10     but WITHOUT ANY WARRANTY; without even the implied warranty of
11     MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
12     GNU General Public License for more details.
13
14     You should have received a copy of the GNU General Public License
15     along with this program; if not, write to the Free Software
16     Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA.
17
18 */
19
20 #include <errno.h>
21 #include <fcntl.h>
22 #include <unistd.h>
23
24 #ifndef PLATFORM_WINDOWS
25 #include <poll.h>
26 #endif
27
28 #include "pbd/error.h"
29 #include "pbd/pthread_utils.h"
30 #include "ardour/debug.h"
31 #include "ardour/butler.h"
32 #include "ardour/io.h"
33 #include "ardour/midi_diskstream.h"
34 #include "ardour/session.h"
35 #include "ardour/track.h"
36 #include "ardour/auditioner.h"
37
38 #include "i18n.h"
39
40 using namespace PBD;
41
42 namespace ARDOUR {
43
44 Butler::Butler(Session& s)
45         : SessionHandleRef (s)
46         , thread()
47         , have_thread (false)
48         , audio_dstream_capture_buffer_size(0)
49         , audio_dstream_playback_buffer_size(0)
50         , midi_dstream_buffer_size(0)
51         , pool_trash(16)
52 {
53         g_atomic_int_set(&should_do_transport_work, 0);
54         SessionEvent::pool->set_trash (&pool_trash);
55
56         Config->ParameterChanged.connect_same_thread (*this, boost::bind (&Butler::config_changed, this, _1));
57 }
58
59 Butler::~Butler()
60 {
61         terminate_thread ();
62 }
63
64 void
65 Butler::config_changed (std::string p)
66 {
67         if (p == "playback-buffer-seconds") {
68                 /* size is in Samples, not bytes */
69                 audio_dstream_playback_buffer_size = (uint32_t) floor (Config->get_audio_playback_buffer_seconds() * _session.frame_rate());
70                 _session.adjust_playback_buffering ();
71         } else if (p == "capture-buffer-seconds") {
72                 audio_dstream_capture_buffer_size = (uint32_t) floor (Config->get_audio_capture_buffer_seconds() * _session.frame_rate());
73                 _session.adjust_capture_buffering ();
74         }
75 }
76
77 #ifndef PLATFORM_WINDOWS
78 int
79 Butler::setup_request_pipe ()
80 {
81         if (pipe (request_pipe)) {
82                 error << string_compose(_("Cannot create transport request signal pipe (%1)"),
83                                 strerror (errno)) << endmsg;
84                 return -1;
85         }
86
87         if (fcntl (request_pipe[0], F_SETFL, O_NONBLOCK)) {
88                 error << string_compose(_("UI: cannot set O_NONBLOCK on butler request pipe (%1)"),
89                                 strerror (errno)) << endmsg;
90                 return -1;
91         }
92
93         if (fcntl (request_pipe[1], F_SETFL, O_NONBLOCK)) {
94                 error << string_compose(_("UI: cannot set O_NONBLOCK on butler request pipe (%1)"),
95                                 strerror (errno)) << endmsg;
96                 return -1;
97         }
98         return 0;
99 }
100 #endif
101
102 int
103 Butler::start_thread()
104 {
105         const float rate = (float)_session.frame_rate();
106
107         /* size is in Samples, not bytes */
108         audio_dstream_capture_buffer_size = (uint32_t) floor (Config->get_audio_capture_buffer_seconds() * rate);
109         audio_dstream_playback_buffer_size = (uint32_t) floor (Config->get_audio_playback_buffer_seconds() * rate);
110
111         /* size is in bytes
112          * XXX: Jack needs to tell us the MIDI buffer size
113          * (i.e. how many MIDI bytes we might see in a cycle)
114          */
115         midi_dstream_buffer_size = (uint32_t) floor (Config->get_midi_track_buffer_seconds() * rate);
116
117         MidiDiskstream::set_readahead_frames ((framecnt_t) (Config->get_midi_readahead() * rate));
118
119         should_run = false;
120
121 #ifndef PLATFORM_WINDOWS
122         if (setup_request_pipe() != 0) return -1;
123 #endif
124
125         if (pthread_create_and_store ("disk butler", &thread, _thread_work, this)) {
126                 error << _("Session: could not create butler thread") << endmsg;
127                 return -1;
128         }
129
130         //pthread_detach (thread);
131         have_thread = true;
132         return 0;
133 }
134
135 void
136 Butler::terminate_thread ()
137 {
138         if (have_thread) {
139                 void* status;
140                 DEBUG_TRACE (DEBUG::Butler, string_compose ("%1: ask butler to quit @ %2\n", pthread_self(), g_get_monotonic_time()));
141                 queue_request (Request::Quit);
142                 pthread_join (thread, &status);
143         }
144 }
145
146 void *
147 Butler::_thread_work (void* arg)
148 {
149         SessionEvent::create_per_thread_pool ("butler events", 4096);
150         pthread_set_name (X_("butler"));
151         return ((Butler *) arg)->thread_work ();
152 }
153
154 bool
155 Butler::wait_for_requests ()
156 {
157 #ifndef PLATFORM_WINDOWS
158         struct pollfd pfd[1];
159
160         pfd[0].fd = request_pipe[0];
161         pfd[0].events = POLLIN|POLLERR|POLLHUP;
162
163         while(true) {
164                 if (poll (pfd, 1, -1) < 0) {
165
166                         if (errno == EINTR) {
167                                 continue;
168                         }
169
170                         error << string_compose (_("poll on butler request pipe failed (%1)"),
171                                         strerror (errno))
172                                 << endmsg;
173                         break;
174                 }
175
176                 DEBUG_TRACE (DEBUG::Butler, string_compose ("%1: butler awake at @ %2\n", pthread_self(), g_get_monotonic_time()));
177
178                 if (pfd[0].revents & ~POLLIN) {
179                         error << string_compose (_("Error on butler thread request pipe: fd=%1 err=%2"), pfd[0].fd, pfd[0].revents) << endmsg;
180                         break;
181                 }
182
183                 if (pfd[0].revents & POLLIN) {
184                         return true;
185                 }
186         }
187         return false;
188 #else
189         m_request_sem.wait ();
190         return true;
191 #endif
192 }
193
194 bool
195 Butler::dequeue_request (Request::Type& r)
196 {
197 #ifndef PLATFORM_WINDOWS
198         char req;
199         size_t nread = ::read (request_pipe[0], &req, sizeof (req));
200         if (nread == 1) {
201                 r = (Request::Type) req;
202                 return true;
203         } else if (nread == 0) {
204                 return false;
205         } else if (errno == EAGAIN) {
206                 return false;
207         } else {
208                 fatal << _("Error reading from butler request pipe") << endmsg;
209                 abort(); /*NOTREACHED*/
210         }
211 #else
212         r = (Request::Type) m_request_state.get();
213 #endif
214         return false;
215 }
216
217 void *
218 Butler::thread_work ()
219 {
220         uint32_t err = 0;
221
222         bool disk_work_outstanding = false;
223         RouteList::iterator i;
224
225         while (true) {
226                 DEBUG_TRACE (DEBUG::Butler, string_compose ("%1 butler main loop, disk work outstanding ? %2 @ %3\n", pthread_self(), disk_work_outstanding, g_get_monotonic_time()));
227
228                 if(!disk_work_outstanding) {
229                         DEBUG_TRACE (DEBUG::Butler, string_compose ("%1 butler waits for requests @ %2\n", pthread_self(), g_get_monotonic_time()));
230                         if (wait_for_requests ()) {
231                                 Request::Type req;
232
233                                 /* empty the pipe of all current requests */
234 #ifdef PLATFORM_WINDOWS
235                                 dequeue_request (req);
236 #else
237                                 while (dequeue_request(req)) {
238 #endif
239                                         switch (req) {
240
241                                         case Request::Run:
242                                                 DEBUG_TRACE (DEBUG::Butler, string_compose ("%1: butler asked to run @ %2\n", pthread_self(), g_get_monotonic_time()));
243                                                 should_run = true;
244                                                 break;
245
246                                         case Request::Pause:
247                                                 DEBUG_TRACE (DEBUG::Butler, string_compose ("%1: butler asked to pause @ %2\n", pthread_self(), g_get_monotonic_time()));
248                                                 should_run = false;
249                                                 break;
250
251                                         case Request::Quit:
252                                                 DEBUG_TRACE (DEBUG::Butler, string_compose ("%1: butler asked to quit @ %2\n", pthread_self(), g_get_monotonic_time()));
253                                                 return 0;
254                                                 abort(); /*NOTREACHED*/
255                                                 break;
256
257                                         default:
258                                                 break;
259                                         }
260 #ifndef PLATFORM_WINDOWS
261                                 }
262 #endif
263                         }
264                 }
265
266                 
267           restart:
268                 DEBUG_TRACE (DEBUG::Butler, "at restart for disk work\n");
269                 disk_work_outstanding = false;
270
271                 if (transport_work_requested()) {
272                         DEBUG_TRACE (DEBUG::Butler, string_compose ("do transport work @ %1\n", g_get_monotonic_time()));
273                         _session.butler_transport_work ();
274                         DEBUG_TRACE (DEBUG::Butler, string_compose ("\ttransport work complete @ %1\n", g_get_monotonic_time()));
275                 }
276
277                 frameoffset_t audition_seek;
278                 if (should_run && _session.is_auditioning()
279                                 && (audition_seek = _session.the_auditioner()->seek_frame()) >= 0) {
280                         boost::shared_ptr<Track> tr = boost::dynamic_pointer_cast<Track> (_session.the_auditioner());
281                         DEBUG_TRACE (DEBUG::Butler, "seek the auditioner\n");
282                         tr->seek(audition_seek);
283                         _session.the_auditioner()->seek_response(audition_seek);
284                 }
285
286                 boost::shared_ptr<RouteList> rl = _session.get_routes();
287
288                 RouteList rl_with_auditioner = *rl;
289                 rl_with_auditioner.push_back (_session.the_auditioner());
290
291                 for (i = rl_with_auditioner.begin(); !transport_work_requested() && should_run && i != rl_with_auditioner.end(); ++i) {
292
293                         boost::shared_ptr<Track> tr = boost::dynamic_pointer_cast<Track> (*i);
294
295                         if (!tr) {
296                                 continue;
297                         }
298
299                         boost::shared_ptr<IO> io = tr->input ();
300
301                         if (io && !io->active()) {
302                                 /* don't read inactive tracks */
303                                 DEBUG_TRACE (DEBUG::Butler, string_compose ("butler skips inactive track %1\n", tr->name()));
304                                 continue;
305                         }
306                         DEBUG_TRACE (DEBUG::Butler, string_compose ("butler refills %1, playback load = %2\n", tr->name(), tr->playback_buffer_load()));
307                         switch (tr->do_refill ()) {
308                         case 0:
309                                 DEBUG_TRACE (DEBUG::Butler, string_compose ("\ttrack refill done %1\n", tr->name()));
310                                 break;
311                                 
312                         case 1:
313                                 DEBUG_TRACE (DEBUG::Butler, string_compose ("\ttrack refill unfinished %1\n", tr->name()));
314                                 disk_work_outstanding = true;
315                                 break;
316
317                         default:
318                                 error << string_compose(_("Butler read ahead failure on dstream %1"), (*i)->name()) << endmsg;
319                                 std::cerr << string_compose(_("Butler read ahead failure on dstream %1"), (*i)->name()) << std::endl;
320                                 break;
321                         }
322
323                 }
324
325                 if (i != rl_with_auditioner.begin() && i != rl_with_auditioner.end()) {
326                         /* we didn't get to all the streams */
327                         disk_work_outstanding = true;
328                 }
329
330                 if (!err && transport_work_requested()) {
331                         DEBUG_TRACE (DEBUG::Butler, "transport work requested during refill, back to restart\n");
332                         goto restart;
333                 }
334
335                 for (i = rl->begin(); !transport_work_requested() && should_run && i != rl->end(); ++i) {
336                         // cerr << "write behind for " << (*i)->name () << endl;
337
338                         boost::shared_ptr<Track> tr = boost::dynamic_pointer_cast<Track> (*i);
339
340                         if (!tr) {
341                                 continue;
342                         }
343
344                         /* note that we still try to flush diskstreams attached to inactive routes
345                          */
346
347                         gint64 before, after;
348                         int ret;
349
350                         DEBUG_TRACE (DEBUG::Butler, string_compose ("butler flushes track %1 capture load %2\n", tr->name(), tr->capture_buffer_load()));
351                         before = g_get_monotonic_time ();
352                         ret = tr->do_flush (ButlerContext);
353                         after = g_get_monotonic_time ();
354                         switch (ret) {
355                         case 0:
356                                 DEBUG_TRACE (DEBUG::Butler, string_compose ("\tflush complete for %1, %2 usecs\n", tr->name(), after - before));
357                                 break;
358                                 
359                         case 1:
360                                 DEBUG_TRACE (DEBUG::Butler, string_compose ("\tflush not finished for %1, %2 usecs\n", tr->name(), after - before));
361                                 disk_work_outstanding = true;
362                                 break;
363
364                         default:
365                                 err++;
366                                 error << string_compose(_("Butler write-behind failure on dstream %1"), (*i)->name()) << endmsg;
367                                 std::cerr << string_compose(_("Butler write-behind failure on dstream %1"), (*i)->name()) << std::endl;
368                                 /* don't break - try to flush all streams in case they
369                                    are split across disks.
370                                 */
371                         }
372                 }
373
374                 if (err && _session.actively_recording()) {
375                         /* stop the transport and try to catch as much possible
376                            captured state as we can.
377                         */
378                         DEBUG_TRACE (DEBUG::Butler, "error occurred during recording - stop transport\n");
379                         _session.request_stop ();
380                 }
381
382                 if (i != rl->begin() && i != rl->end()) {
383                         /* we didn't get to all the streams */
384                         DEBUG_TRACE (DEBUG::Butler, "not all tracks processed, will need to go back for more\n");
385                         disk_work_outstanding = true;
386                 }
387
388                 if (!err && transport_work_requested()) {
389                         DEBUG_TRACE (DEBUG::Butler, "transport work requested during flush, back to restart\n");
390                         goto restart;
391                 }
392
393                 if (!disk_work_outstanding) {
394                         _session.refresh_disk_space ();
395                 }
396
397
398                 {
399                         Glib::Threads::Mutex::Lock lm (request_lock);
400
401                         if (should_run && (disk_work_outstanding || transport_work_requested())) {
402                                 DEBUG_TRACE (DEBUG::Butler, string_compose ("at end, should run %1 disk work %2 transport work %3 ... goto restart\n",
403                                                                             should_run, disk_work_outstanding, transport_work_requested()));
404                                 goto restart;
405                         }
406
407                         DEBUG_TRACE (DEBUG::Butler, string_compose ("%1: butler signals pause @ %2\n", pthread_self(), g_get_monotonic_time()));
408                         paused.signal();
409                 }
410
411                 DEBUG_TRACE (DEBUG::Butler, "butler emptying pool trash\n");
412                 empty_pool_trash ();
413         }
414
415         return (0);
416 }
417
418 void
419 Butler::schedule_transport_work ()
420 {
421         g_atomic_int_inc (&should_do_transport_work);
422         summon ();
423 }
424
425 void
426 Butler::queue_request (Request::Type r)
427 {
428 #ifndef PLATFORM_WINDOWS
429         char c = r;
430         (void) ::write (request_pipe[1], &c, 1);
431 #else
432         m_request_state.set (r);
433         m_request_sem.post ();
434 #endif
435 }
436
437 void
438 Butler::summon ()
439 {
440         DEBUG_TRACE (DEBUG::Butler, string_compose ("%1: summon butler to run @ %2\n", pthread_self(), g_get_monotonic_time()));
441         queue_request (Request::Run);
442 }
443
444 void
445 Butler::stop ()
446 {
447         Glib::Threads::Mutex::Lock lm (request_lock);
448         DEBUG_TRACE (DEBUG::Butler, string_compose ("%1: asking butler to stop @ %2\n", pthread_self(), g_get_monotonic_time()));
449         queue_request (Request::Pause);
450         paused.wait(request_lock);
451 }
452
453 void
454 Butler::wait_until_finished ()
455 {
456         Glib::Threads::Mutex::Lock lm (request_lock);
457         DEBUG_TRACE (DEBUG::Butler, string_compose ("%1: waiting for butler to finish @ %2\n", pthread_self(), g_get_monotonic_time()));
458         queue_request (Request::Pause);
459         paused.wait(request_lock);
460 }
461
462 bool
463 Butler::transport_work_requested () const
464 {
465         return g_atomic_int_get(&should_do_transport_work);
466 }
467
468 void
469 Butler::empty_pool_trash ()
470 {
471         /* look in the trash, deleting empty pools until we come to one that is not empty */
472
473         RingBuffer<CrossThreadPool*>::rw_vector vec;
474         pool_trash.get_read_vector (&vec);
475
476         guint deleted = 0;
477
478         for (int i = 0; i < 2; ++i) {
479                 for (guint j = 0; j < vec.len[i]; ++j) {
480                         if (vec.buf[i][j]->empty()) {
481                                 delete vec.buf[i][j];
482                                 ++deleted;
483                         } else {
484                                 /* found a non-empty pool, so stop deleting */
485                                 if (deleted) {
486                                         pool_trash.increment_read_idx (deleted);
487                                 }
488                                 return;
489                         }
490                 }
491         }
492
493         if (deleted) {
494                 pool_trash.increment_read_idx (deleted);
495         }
496 }
497
498 void
499 Butler::drop_references ()
500 {
501         std::cerr << "Butler drops pool trash\n";
502         SessionEvent::pool->set_trash (0);
503 }
504
505
506 } // namespace ARDOUR
507