X-Git-Url: https://git.carlh.net/gitweb/?a=blobdiff_plain;f=src%2Flib%2Fencoder.cc;h=f8a2ee3bde878c117f9948015d23951082d82fa5;hb=a78b741c43830c84bcb4d18e3147746f13a668e5;hp=116dd5d1920472018d234dd7f535712de64d591f;hpb=8e96f8c1677146d224438ec040982532879d6c34;p=dcpomatic.git diff --git a/src/lib/encoder.cc b/src/lib/encoder.cc index 116dd5d19..f8a2ee3bd 100644 --- a/src/lib/encoder.cc +++ b/src/lib/encoder.cc @@ -45,6 +45,7 @@ #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; @@ -164,11 +165,11 @@ Encoder::current_encoding_rate () const int Encoder::video_frames_enqueued () const { - if (!_last_player_video) { + if (!_last_player_video_time) { return 0; } - return _last_player_video->time().frames_floor (_film->video_frame_rate ()); + return _last_player_video_time->frames_floor (_film->video_frame_rate ()); } /** Should be called when a frame has been encoded successfully. @@ -187,13 +188,13 @@ Encoder::frame_done () } } -/** 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. */ void -Encoder::encode (shared_ptr pv) +Encoder::encode (shared_ptr pv, DCPTime time) { _waker.nudge (); @@ -221,18 +222,22 @@ Encoder::encode (shared_ptr pv) */ rethrow (); - Frame const position = pv->time().frames_floor(_film->video_frame_rate()); + Frame const position = time.frames_floor(_film->video_frame_rate()); if (_writer->can_fake_write (position)) { /* We can fake-write this frame */ + LOG_DEBUG_ENCODE("Frame @ %1 FAKE", to_string(pv->time())); _writer->fake_write (position, pv->eyes ()); frame_done (); } else if (pv->has_j2k ()) { + LOG_DEBUG_ENCODE("Frame @ %1 J2K", to_string(pv->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)) { + LOG_DEBUG_ENCODE("Frame @ %1 REPEAT", to_string(pv->time())); _writer->repeat (position, pv->eyes ()); } else { + LOG_DEBUG_ENCODE("Frame @ %1 ENCODE", to_string(pv->time())); /* Queue this new frame for encoding */ LOG_TIMING ("add-frame-to-queue queue=%1", _queue.size ()); _queue.push_back (shared_ptr ( @@ -253,6 +258,7 @@ Encoder::encode (shared_ptr pv) } _last_player_video = pv; + _last_player_video_time = time; } void @@ -304,57 +310,67 @@ try LOG_TIMING ("encoder-wake thread=%1 queue=%2", thread_id(), _queue.size()); shared_ptr vf = _queue.front (); - LOG_TIMING ("encoder-pop thread=%1 frame=%2 eyes=%3", thread_id(), vf->index(), (int) 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 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 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", 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) { - 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"), thread_id(), vf->index()); - _queue.push_front (vf); - lock.unlock (); - } - if (remote_backoff > 0) { boost::this_thread::sleep (boost::posix_time::seconds (remote_backoff)); }