More fixes for errors / crashes / misbehaviour with content changes
[dcpomatic.git] / src / lib / butler.cc
index ef565c02b0607849689ffb8d1fd22da4f373062f..386e7f9db78a90b723bb6b5463f5bed802ab20b9 100644 (file)
 #include "player.h"
 #include "util.h"
 #include "log.h"
+#include "cross.h"
 #include "compose.hpp"
+#include "exceptions.h"
 #include <boost/weak_ptr.hpp>
 #include <boost/shared_ptr.hpp>
 
+#define LOG_TIMING(...)  _log->log (String::compose(__VA_ARGS__), LogEntry::TYPE_TIMING);
+#define LOG_WARNING(...) _log->log (String::compose(__VA_ARGS__), LogEntry::TYPE_WARNING);
+
 using std::cout;
 using std::pair;
 using std::make_pair;
+using std::string;
 using boost::weak_ptr;
 using boost::shared_ptr;
 using boost::bind;
@@ -37,13 +43,11 @@ using boost::optional;
 /** Minimum video readahead in frames */
 #define MINIMUM_VIDEO_READAHEAD 10
 /** Maximum video readahead in frames; should never be reached unless there are bugs in Player */
-#define MAXIMUM_VIDEO_READAHEAD 240
+#define MAXIMUM_VIDEO_READAHEAD 24
 /** Minimum audio readahead in frames */
-#define MINIMUM_AUDIO_READAHEAD (48000*5)
+#define MINIMUM_AUDIO_READAHEAD (48000 * MINIMUM_VIDEO_READAHEAD / 24)
 /** Minimum audio readahead in frames; should never be reached unless there are bugs in Player */
-#define MAXIMUM_AUDIO_READAHEAD (48000*60)
-
-#define LOG_WARNING(...) _log->log (String::compose(__VA_ARGS__), LogEntry::TYPE_WARNING);
+#define MAXIMUM_AUDIO_READAHEAD (48000 * MAXIMUM_VIDEO_READAHEAD / 24)
 
 Butler::Butler (shared_ptr<Player> player, shared_ptr<Log> log, AudioMapping audio_mapping, int audio_channels)
        : _player (player)
@@ -58,13 +62,20 @@ Butler::Butler (shared_ptr<Player> player, shared_ptr<Log> log, AudioMapping aud
        , _disable_audio (false)
 {
        _player_video_connection = _player->Video.connect (bind (&Butler::video, this, _1, _2));
-       _player_audio_connection = _player->Audio.connect (bind (&Butler::audio, this, _1));
-       _player_changed_connection = _player->Changed.connect (bind (&Butler::player_changed, this));
+       _player_audio_connection = _player->Audio.connect (bind (&Butler::audio, this, _1, _2));
+       _player_text_connection = _player->Text.connect (bind (&Butler::text, this, _1, _2, _3));
+       _player_changed_connection = _player->Changed.connect (bind (&Butler::return_seek, this, _2));
+       _player_not_changed_connection = _player->NotChanged.connect (bind (&Butler::return_seek, this, false));
        _thread = new boost::thread (bind (&Butler::thread, this));
+#ifdef DCPOMATIC_LINUX
+       pthread_setname_np (_thread->native_handle(), "butler");
+#endif
 
        /* Create some threads to do work on the PlayerVideos we are creating; at present this is used to
           multi-thread JPEG2000 decoding.
        */
+
+       LOG_TIMING("start-prepare-threads %1", boost::thread::hardware_concurrency());
        for (size_t i = 0; i < boost::thread::hardware_concurrency(); ++i) {
                _prepare_pool.create_thread (bind (&boost::asio::io_service::run, &_prepare_service));
        }
@@ -94,20 +105,38 @@ Butler::~Butler ()
 bool
 Butler::should_run () const
 {
-       if (_video.size() >= MAXIMUM_VIDEO_READAHEAD) {
-               LOG_WARNING ("Butler video buffers reached %1 frames", _video.size());
+       if (_video.size() >= MAXIMUM_VIDEO_READAHEAD * 10) {
+               /* This is way too big */
+               throw ProgrammingError
+                       (__FILE__, __LINE__, String::compose ("Butler video buffers reached %1 frames (audio is %2)", _video.size(), _audio.size()));
+       }
+
+       if (_audio.size() >= MAXIMUM_AUDIO_READAHEAD * 10) {
+               /* This is way too big */
+               throw ProgrammingError
+                       (__FILE__, __LINE__, String::compose ("Butler audio buffers reached %1 frames (video is %2)", _audio.size(), _video.size()));
+       }
+
+       if (_video.size() >= MAXIMUM_VIDEO_READAHEAD * 2) {
+               LOG_WARNING ("Butler video buffers reached %1 frames (audio is %2)", _video.size(), _audio.size());
        }
 
-       if (_audio.size() >= MAXIMUM_AUDIO_READAHEAD) {
-               LOG_WARNING ("Butler audio buffers reached %1 frames", _audio.size());
+       if (_audio.size() >= MAXIMUM_AUDIO_READAHEAD * 2) {
+               LOG_WARNING ("Butler audio buffers reached %1 frames (video is %2)", _audio.size(), _video.size());
        }
 
-       return (_video.size() < MINIMUM_VIDEO_READAHEAD || (!_disable_audio && _audio.size() < MINIMUM_AUDIO_READAHEAD))
-               && (_video.size() < MAXIMUM_VIDEO_READAHEAD)
-               && (_audio.size() < MAXIMUM_AUDIO_READAHEAD)
-               && !_stop_thread
-               && !_finished
-               && !_died;
+       if (_stop_thread || _finished || _died) {
+               /* Definitely do not run */
+               return false;
+       }
+
+       if (_video.size() < MINIMUM_VIDEO_READAHEAD || (!_disable_audio && _audio.size() < MINIMUM_AUDIO_READAHEAD)) {
+               /* Definitely do run: we need data */
+               return true;
+       }
+
+       /* Run if we aren't full of video or audio */
+       return (_video.size() < MAXIMUM_VIDEO_READAHEAD) && (_audio.size() < MAXIMUM_AUDIO_READAHEAD);
 }
 
 void
@@ -176,19 +205,38 @@ Butler::get_video ()
        return r;
 }
 
+optional<pair<PlayerText, DCPTimePeriod> >
+Butler::get_closed_caption ()
+{
+       boost::mutex::scoped_lock lm (_mutex);
+       return _closed_caption.get ();
+}
+
 void
 Butler::seek (DCPTime position, bool accurate)
 {
        boost::mutex::scoped_lock lm (_mutex);
+       seek_unlocked (position, accurate);
+}
+
+void
+Butler::seek_unlocked (DCPTime position, bool accurate)
+{
        if (_died) {
                return;
        }
 
-       _video.clear ();
-       _audio.clear ();
        _finished = false;
        _pending_seek_position = position;
        _pending_seek_accurate = accurate;
+
+       {
+               boost::mutex::scoped_lock lm (_buffers_mutex);
+               _video.clear ();
+               _audio.clear ();
+               _closed_caption.clear ();
+       }
+
        _summon.notify_all ();
 }
 
@@ -198,27 +246,30 @@ Butler::prepare (weak_ptr<PlayerVideo> weak_video) const
        shared_ptr<PlayerVideo> video = weak_video.lock ();
        /* If the weak_ptr cannot be locked the video obviously no longer requires any work */
        if (video) {
+               LOG_TIMING("start-prepare in %1", thread_id());
                video->prepare ();
+               LOG_TIMING("finish-prepare in %1", thread_id());
        }
 }
 
 void
 Butler::video (shared_ptr<PlayerVideo> video, DCPTime time)
 {
-       {
-               boost::mutex::scoped_lock lm (_mutex);
-               if (_pending_seek_position) {
-                       /* Don't store any video while a seek is pending */
-                       return;
-               }
+       boost::mutex::scoped_lock lm (_mutex);
+
+       if (_pending_seek_position) {
+               /* Don't store any video while a seek is pending */
+               return;
        }
 
        _prepare_service.post (bind (&Butler::prepare, this, weak_ptr<PlayerVideo>(video)));
+
+       boost::mutex::scoped_lock lm2 (_buffers_mutex);
        _video.put (video, time);
 }
 
 void
-Butler::audio (shared_ptr<AudioBuffers> audio)
+Butler::audio (shared_ptr<AudioBuffers> audio, DCPTime time)
 {
        {
                boost::mutex::scoped_lock lm (_mutex);
@@ -228,37 +279,20 @@ Butler::audio (shared_ptr<AudioBuffers> audio)
                }
        }
 
-       _audio.put (remap (audio, _audio_channels, _audio_mapping));
-}
-
-void
-Butler::player_changed ()
-{
-       optional<DCPTime> t;
-
-       {
-               boost::mutex::scoped_lock lm (_mutex);
-               t = _video.earliest ();
-       }
-
-       if (t) {
-               seek (*t, true);
-       } else {
-               _video.clear ();
-               _audio.clear ();
-       }
+       boost::mutex::scoped_lock lm2 (_buffers_mutex);
+       _audio.put (remap (audio, _audio_channels, _audio_mapping), time);
 }
 
 /** Try to get `frames' frames of audio and copy it into `out'.  Silence
  *  will be filled if no audio is available.
- *  @return true if there was a buffer underrun, otherwise false.
+ *  @return time of this audio, or unset if there was a buffer underrun.
  */
-bool
+optional<DCPTime>
 Butler::get_audio (float* out, Frame frames)
 {
-       bool const underrun = _audio.get (out, _audio_channels, frames);
+       optional<DCPTime> t = _audio.get (out, _audio_channels, frames);
        _summon.notify_all ();
-       return underrun;
+       return t;
 }
 
 void
@@ -267,3 +301,44 @@ Butler::disable_audio ()
        boost::mutex::scoped_lock lm (_mutex);
        _disable_audio = true;
 }
+
+pair<size_t, string>
+Butler::memory_used () const
+{
+       /* XXX: should also look at _audio.memory_used() */
+       return _video.memory_used();
+}
+
+void
+Butler::return_seek (bool frequent)
+{
+       boost::mutex::scoped_lock lm (_mutex);
+       if (_died || _pending_seek_position || frequent) {
+               return;
+       }
+
+       DCPTime seek_to;
+       DCPTime next = _video.get().second;
+       if (_awaiting && _awaiting > next) {
+               /* We have recently done a player_changed seek and our buffers haven't been refilled yet,
+                  so assume that we're seeking to the same place as last time.
+               */
+               seek_to = *_awaiting;
+       } else {
+               seek_to = next;
+       }
+
+       seek_unlocked (seek_to, true);
+       _awaiting = seek_to;
+}
+
+void
+Butler::text (PlayerText pt, TextType type, DCPTimePeriod period)
+{
+       if (type != TEXT_CLOSED_CAPTION) {
+               return;
+       }
+
+       boost::mutex::scoped_lock lm2 (_buffers_mutex);
+       _closed_caption.put (make_pair(pt, period));
+}