#define LOG_GENERAL_NC(...) _film->log()->log (__VA_ARGS__, LogEntry::TYPE_GENERAL);
#define LOG_ERROR(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_ERROR);
#define LOG_TIMING(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_TIMING);
+#define LOG_DEBUG_ENCODE(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_DEBUG_ENCODE);
using std::list;
using std::cout;
using boost::optional;
using dcp::Data;
-int const Encoder::_history_size = 25;
-
-/** @param f Film that we are encoding */
+/** @param film Film that we are encoding.
+ * @param writer Writer that we are using.
+ */
Encoder::Encoder (shared_ptr<const Film> film, shared_ptr<Writer> writer)
: _film (film)
- , _position (0)
+ , _history (200)
, _writer (writer)
{
servers_list_changed ();
Encoder::~Encoder ()
{
- terminate_threads ();
+ try {
+ terminate_threads ();
+ } catch (...) {
+ /* Destructors must not throw exceptions; anything bad
+ happening now is too late to worry about anyway,
+ I think.
+ */
+ }
}
void
Encoder::begin ()
{
- if (!EncodeServerFinder::instance()->disabled ()) {
- _server_found_connection = EncodeServerFinder::instance()->ServersListChanged.connect (boost::bind (&Encoder::servers_list_changed, this));
+ weak_ptr<Encoder> wp = shared_from_this ();
+ _server_found_connection = EncodeServerFinder::instance()->ServersListChanged.connect (
+ boost::bind (&Encoder::call_servers_list_changed, wp)
+ );
+}
+
+/* We don't want the servers-list-changed callback trying to do things
+ during destruction of Encoder, and I think this is the neatest way
+ to achieve that.
+*/
+void
+Encoder::call_servers_list_changed (weak_ptr<Encoder> encoder)
+{
+ shared_ptr<Encoder> e = encoder.lock ();
+ if (e) {
+ e->servers_list_changed ();
}
}
float
Encoder::current_encoding_rate () const
{
- boost::mutex::scoped_lock lock (_state_mutex);
- if (int (_time_history.size()) < _history_size) {
- return 0;
- }
-
- struct timeval now;
- gettimeofday (&now, 0);
-
- return _history_size / (seconds (now) - seconds (_time_history.back ()));
+ return _history.rate ();
}
-/** @return Number of video frames that have been sent out */
+/** @return Number of video frames that have been queued for encoding */
int
-Encoder::video_frames_out () const
+Encoder::video_frames_enqueued () const
{
- boost::mutex::scoped_lock (_state_mutex);
- return _position;
+ if (!_last_player_video_time) {
+ return 0;
+ }
+
+ return _last_player_video_time->frames_floor (_film->video_frame_rate ());
}
-/** Should be called when a frame has been encoded successfully.
- * @param n Source frame index.
- */
+/** Should be called when a frame has been encoded successfully */
void
Encoder::frame_done ()
{
- boost::mutex::scoped_lock lock (_state_mutex);
-
- struct timeval tv;
- gettimeofday (&tv, 0);
- _time_history.push_front (tv);
- if (int (_time_history.size()) > _history_size) {
- _time_history.pop_back ();
- }
+ _history.event ();
}
-/** Called to start encoding of the next video frame in the DCP. This is called in order,
+/** Called to request encoding of the next video frame in the DCP. This is called in order,
* so each time the supplied frame is the one after the previous one.
* pv represents one video frame, and could be empty if there is nothing to encode
* for this DCP frame.
+ *
+ * @param pv PlayerVideo to encode.
+ * @param time Time of \p pv within the DCP.
*/
void
-Encoder::encode (list<shared_ptr<PlayerVideo> > pv)
-{
- BOOST_FOREACH (shared_ptr<PlayerVideo> i, pv) {
- enqueue (i);
- }
- ++_position;
-}
-
-void
-Encoder::enqueue (shared_ptr<PlayerVideo> pv)
+Encoder::encode (shared_ptr<PlayerVideo> pv, DCPTime time)
{
_waker.nudge ();
boost::mutex::scoped_lock queue_lock (_queue_mutex);
- /* XXX: discard 3D here if required */
-
- /* Wait until the queue has gone down a bit */
- while (_queue.size() >= threads * 2) {
- LOG_TIMING ("decoder-sleep queue=%1", _queue.size());
+ /* Wait until the queue has gone down a bit. Allow one thing in the queue even
+ when there are no threads.
+ */
+ while (_queue.size() >= (threads * 2) + 1) {
+ LOG_TIMING ("decoder-sleep queue=%1 threads=%2", _queue.size(), threads);
_full_condition.wait (queue_lock);
- LOG_TIMING ("decoder-wake queue=%1", _queue.size());
+ LOG_TIMING ("decoder-wake queue=%1 threads=%2", _queue.size(), threads);
}
_writer->rethrow ();
*/
rethrow ();
- if (_writer->can_fake_write (_position)) {
+ Frame const position = time.frames_floor(_film->video_frame_rate());
+
+ if (_writer->can_fake_write (position)) {
/* We can fake-write this frame */
- _writer->fake_write (_position, pv->eyes ());
+ LOG_DEBUG_ENCODE("Frame @ %1 FAKE", to_string(time));
+ _writer->fake_write (position, pv->eyes ());
frame_done ();
} else if (pv->has_j2k ()) {
+ LOG_DEBUG_ENCODE("Frame @ %1 J2K", to_string(time));
/* This frame already has JPEG2000 data, so just write it */
- _writer->write (pv->j2k(), _position, pv->eyes ());
- } else if (_last_player_video && _writer->can_repeat(_position) && pv->same (_last_player_video)) {
- _writer->repeat (_position, pv->eyes ());
+ _writer->write (pv->j2k(), position, pv->eyes ());
+ } else if (_last_player_video && _writer->can_repeat(position) && pv->same (_last_player_video)) {
+ LOG_DEBUG_ENCODE("Frame @ %1 REPEAT", to_string(time));
+ _writer->repeat (position, pv->eyes ());
} else {
+ LOG_DEBUG_ENCODE("Frame @ %1 ENCODE", to_string(time));
/* Queue this new frame for encoding */
LOG_TIMING ("add-frame-to-queue queue=%1", _queue.size ());
_queue.push_back (shared_ptr<DCPVideo> (
new DCPVideo (
pv,
- _position,
+ position,
_film->video_frame_rate(),
_film->j2k_bandwidth(),
_film->resolution(),
}
_last_player_video = pv;
+ _last_player_video_time = time;
}
void
LOG_GENERAL ("Terminating thread %1 of %2", n + 1, _threads.size ());
(*i)->interrupt ();
DCPOMATIC_ASSERT ((*i)->joinable ());
- (*i)->join ();
+ try {
+ (*i)->join ();
+ } catch (boost::thread_interrupted& e) {
+ /* This is to be expected */
+ }
delete *i;
LOG_GENERAL_NC ("Thread terminated");
++n;
try
{
if (server) {
- LOG_TIMING ("start-encoder-thread thread=%1 server=%2", boost::this_thread::get_id (), server->host_name ());
+ LOG_TIMING ("start-encoder-thread thread=%1 server=%2", thread_id (), server->host_name ());
} else {
- LOG_TIMING ("start-encoder-thread thread=%1 server=localhost", boost::this_thread::get_id ());
+ LOG_TIMING ("start-encoder-thread thread=%1 server=localhost", thread_id ());
}
/* Number of seconds that we currently wait between attempts
while (true) {
- LOG_TIMING ("encoder-sleep thread=%1", boost::this_thread::get_id());
+ LOG_TIMING ("encoder-sleep thread=%1", thread_id ());
boost::mutex::scoped_lock lock (_queue_mutex);
while (_queue.empty ()) {
_empty_condition.wait (lock);
}
- LOG_TIMING ("encoder-wake thread=%1 queue=%2", boost::this_thread::get_id(), _queue.size());
+ LOG_TIMING ("encoder-wake thread=%1 queue=%2", thread_id(), _queue.size());
shared_ptr<DCPVideo> vf = _queue.front ();
- LOG_TIMING ("encoder-pop thread=%1 frame=%2 eyes=%3", boost::this_thread::get_id(), vf->index(), vf->eyes ());
- _queue.pop_front ();
- lock.unlock ();
+ /* We're about to commit to either encoding this frame or putting it back onto the queue,
+ so we must not be interrupted until one or other of these things have happened. This
+ block has thread interruption disabled.
+ */
+ {
+ boost::this_thread::disable_interruption dis;
- optional<Data> encoded;
+ LOG_TIMING ("encoder-pop thread=%1 frame=%2 eyes=%3", thread_id(), vf->index(), (int) vf->eyes ());
+ _queue.pop_front ();
- /* We need to encode this input */
- if (server) {
- try {
- encoded = vf->encode_remotely (server.get ());
+ lock.unlock ();
- if (remote_backoff > 0) {
- LOG_GENERAL ("%1 was lost, but now she is found; removing backoff", server->host_name ());
+ optional<Data> encoded;
+
+ /* We need to encode this input */
+ if (server) {
+ try {
+ encoded = vf->encode_remotely (server.get ());
+
+ if (remote_backoff > 0) {
+ LOG_GENERAL ("%1 was lost, but now she is found; removing backoff", server->host_name ());
+ }
+
+ /* This job succeeded, so remove any backoff */
+ remote_backoff = 0;
+
+ } catch (std::exception& e) {
+ if (remote_backoff < 60) {
+ /* back off more */
+ remote_backoff += 10;
+ }
+ LOG_ERROR (
+ N_("Remote encode of %1 on %2 failed (%3); thread sleeping for %4s"),
+ vf->index(), server->host_name(), e.what(), remote_backoff
+ );
}
- /* This job succeeded, so remove any backoff */
- remote_backoff = 0;
-
- } catch (std::exception& e) {
- if (remote_backoff < 60) {
- /* back off more */
- remote_backoff += 10;
+ } else {
+ try {
+ LOG_TIMING ("start-local-encode thread=%1 frame=%2", thread_id(), vf->index());
+ encoded = vf->encode_locally (boost::bind (&Log::dcp_log, _film->log().get(), _1, _2));
+ LOG_TIMING ("finish-local-encode thread=%1 frame=%2", thread_id(), vf->index());
+ } catch (std::exception& e) {
+ /* This is very bad, so don't cope with it, just pass it on */
+ LOG_ERROR (N_("Local encode failed (%1)"), e.what ());
+ throw;
}
- LOG_ERROR (
- N_("Remote encode of %1 on %2 failed (%3); thread sleeping for %4s"),
- vf->index(), server->host_name(), e.what(), remote_backoff
- );
}
- } else {
- try {
- LOG_TIMING ("start-local-encode thread=%1 frame=%2", boost::this_thread::get_id(), vf->index());
- encoded = vf->encode_locally (boost::bind (&Log::dcp_log, _film->log().get(), _1, _2));
- LOG_TIMING ("finish-local-encode thread=%1 frame=%2", boost::this_thread::get_id(), vf->index());
- } catch (std::exception& e) {
- LOG_ERROR (N_("Local encode failed (%1)"), e.what ());
- throw;
+ if (encoded) {
+ _writer->write (encoded.get(), vf->index (), vf->eyes ());
+ frame_done ();
+ } else {
+ lock.lock ();
+ LOG_GENERAL (N_("[%1] Encoder thread pushes frame %2 back onto queue after failure"), thread_id(), vf->index());
+ _queue.push_front (vf);
+ lock.unlock ();
}
}
- if (encoded) {
- _writer->write (encoded.get(), vf->index (), vf->eyes ());
- frame_done ();
- } else {
- lock.lock ();
- LOG_GENERAL (N_("[%1] Encoder thread pushes frame %2 back onto queue after failure"), boost::this_thread::get_id(), vf->index());
- _queue.push_front (vf);
- lock.unlock ();
- }
-
if (remote_backoff > 0) {
boost::this_thread::sleep (boost::posix_time::seconds (remote_backoff));
}
_full_condition.notify_all ();
}
}
+catch (boost::thread_interrupted& e) {
+ /* Ignore these and just stop the thread */
+ _full_condition.notify_all ();
+}
catch (...)
{
store_current ();
#endif
if (!Config::instance()->only_servers_encode ()) {
- for (int i = 0; i < Config::instance()->num_local_encoding_threads (); ++i) {
+ for (int i = 0; i < Config::instance()->master_encoding_threads (); ++i) {
boost::thread* t = new boost::thread (boost::bind (&Encoder::encoder_thread, this, optional<EncodeServerDescription> ()));
_threads.push_back (t);
#ifdef BOOST_THREAD_PLATFORM_WIN32
projects / dcpomatic.git / blobdiff