/* Copyright (C) 2012-2015 Carl Hetherington This program is free software; you can redistribute it and/or modify it under the terms of the GNU General Public License as published by the Free Software Foundation; either version 2 of the License, or (at your option) any later version. This program is distributed in the hope that it will be useful, but WITHOUT ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License for more details. You should have received a copy of the GNU General Public License along with this program; if not, write to the Free Software Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA. */ /** @file src/encoder.h * @brief Parent class for classes which can encode video and audio frames. */ #include "encoder.h" #include "util.h" #include "film.h" #include "log.h" #include "config.h" #include "dcp_video.h" #include "cross.h" #include "writer.h" #include "encode_server_finder.h" #include "player.h" #include "player_video.h" #include "encode_server_description.h" #include "compose.hpp" #include #include #include #include "i18n.h" #define LOG_GENERAL(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_GENERAL); #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); using std::list; using std::cout; using boost::shared_ptr; using boost::weak_ptr; using boost::optional; using dcp::Data; int const Encoder::_history_size = 25; /** @param f Film that we are encoding */ Encoder::Encoder (shared_ptr film, shared_ptr writer) : _film (film) , _position (0) , _terminate_enqueue (false) , _terminate_encoding (false) , _writer (writer) { servers_list_changed (); } Encoder::~Encoder () { terminate_threads (); boost::mutex::scoped_lock lm (_queue_mutex); _terminate_enqueue = true; _full_condition.notify_all (); _empty_condition.notify_all (); } void Encoder::begin () { if (!EncodeServerFinder::instance()->disabled ()) { _server_found_connection = EncodeServerFinder::instance()->ServersListChanged.connect (boost::bind (&Encoder::servers_list_changed, this)); } } void Encoder::end () { boost::mutex::scoped_lock lock (_queue_mutex); LOG_GENERAL (N_("Clearing queue of %1"), _queue.size ()); /* Keep waking workers until the queue is empty */ while (!_queue.empty ()) { rethrow (); _empty_condition.notify_all (); _full_condition.wait (lock); } lock.unlock (); LOG_GENERAL_NC (N_("Terminating encoder threads")); terminate_threads (); LOG_GENERAL (N_("Mopping up %1"), _queue.size()); /* The following sequence of events can occur in the above code: 1. a remote worker takes the last image off the queue 2. the loop above terminates 3. the remote worker fails to encode the image and puts it back on the queue 4. the remote worker is then terminated by terminate_threads So just mop up anything left in the queue here. */ for (list >::iterator i = _queue.begin(); i != _queue.end(); ++i) { LOG_GENERAL (N_("Encode left-over frame %1"), (*i)->index ()); try { _writer->write ( (*i)->encode_locally (boost::bind (&Log::dcp_log, _film->log().get(), _1, _2)), (*i)->index (), (*i)->eyes () ); frame_done (); } catch (std::exception& e) { LOG_ERROR (N_("Local encode failed (%1)"), e.what ()); } } } /** @return an estimate of the current number of frames we are encoding per second, * or 0 if not known. */ 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 Number of video frames that have been sent out */ int Encoder::video_frames_out () const { boost::mutex::scoped_lock (_state_mutex); return _position; } /** Should be called when a frame has been encoded successfully. * @param n Source frame index. */ 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 (); } } /** Called to start 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 (list > pv) { BOOST_FOREACH (shared_ptr i, pv) { enqueue (i); } ++_position; } void Encoder::enqueue (shared_ptr pv) { _waker.nudge (); size_t threads = 0; { boost::mutex::scoped_lock threads_lock (_threads_mutex); threads = _threads.size (); } 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 && !_terminate_enqueue) { LOG_TIMING ("decoder-sleep queue=%1", _queue.size()); _full_condition.wait (queue_lock); LOG_TIMING ("decoder-wake queue=%1", _queue.size()); } if (_terminate_enqueue) { return; } _writer->rethrow (); /* Re-throw any exception raised by one of our threads. If more than one has thrown an exception, only one will be rethrown, I think; but then, if that happens something has gone badly wrong. */ rethrow (); if (_writer->can_fake_write (_position)) { /* We can fake-write this frame */ _writer->fake_write (_position, pv->eyes ()); frame_done (); } else if (pv->has_j2k ()) { /* 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 ()); } else { /* Queue this new frame for encoding */ LOG_TIMING ("add-frame-to-queue queue=%1", _queue.size ()); _queue.push_back (shared_ptr ( new DCPVideo ( pv, _position, _film->video_frame_rate(), _film->j2k_bandwidth(), _film->resolution(), _film->log() ) )); /* The queue might not be empty any more, so notify anything which is waiting on that. */ _empty_condition.notify_all (); } _last_player_video = pv; } void Encoder::terminate_threads () { { boost::mutex::scoped_lock queue_lock (_queue_mutex); _terminate_encoding = true; } boost::mutex::scoped_lock threads_lock (_threads_mutex); int n = 0; for (list::iterator i = _threads.begin(); i != _threads.end(); ++i) { LOG_GENERAL ("Terminating thread %1 of %2", n + 1, _threads.size ()); (*i)->interrupt (); if ((*i)->joinable ()) { (*i)->join (); } delete *i; LOG_GENERAL_NC ("Thread terminated"); ++n; } _threads.clear (); _terminate_encoding = false; } void Encoder::encoder_thread (optional server) try { if (server) { LOG_TIMING ("start-encoder-thread thread=%1 server=%2", boost::this_thread::get_id (), server->host_name ()); } else { LOG_TIMING ("start-encoder-thread thread=%1 server=localhost", boost::this_thread::get_id ()); } /* Number of seconds that we currently wait between attempts to connect to the server; not relevant for localhost encodings. */ int remote_backoff = 0; while (true) { LOG_TIMING ("encoder-sleep thread=%1", boost::this_thread::get_id()); boost::mutex::scoped_lock lock (_queue_mutex); while (_queue.empty () && !_terminate_encoding) { _empty_condition.wait (lock); } if (_terminate_encoding) { return; } LOG_TIMING ("encoder-wake thread=%1 queue=%2", boost::this_thread::get_id(), _queue.size()); shared_ptr 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 (); 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 ); } } 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"), 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)); } /* The queue might not be full any more, so notify anything that is waiting on that */ lock.lock (); _full_condition.notify_all (); } } catch (...) { store_current (); /* Wake anything waiting on _full_condition so it can see the exception */ _full_condition.notify_all (); } void Encoder::servers_list_changed () { terminate_threads (); /* XXX: could re-use threads */ boost::mutex::scoped_lock lm (_threads_mutex); if (!Config::instance()->only_servers_encode ()) { for (int i = 0; i < Config::instance()->num_local_encoding_threads (); ++i) { _threads.push_back (new boost::thread (boost::bind (&Encoder::encoder_thread, this, optional ()))); } } BOOST_FOREACH (EncodeServerDescription i, EncodeServerFinder::instance()->servers ()) { LOG_GENERAL (N_("Adding %1 worker threads for remote %2"), i.threads(), i.host_name ()); for (int j = 0; j < i.threads(); ++j) { _threads.push_back (new boost::thread (boost::bind (&Encoder::encoder_thread, this, i))); } } _writer->set_encoder_threads (_threads.size ()); }