Rename Server -> EncodeServer, ServerFinder -> EncodeServerFinder, ServerDescription...
[dcpomatic.git] / src / lib / encoder.cc
index c3ad084419a071958be2873ac0a8c1c6a373d1d2..8ba794a8e4c43b368e6cb801f4de28aac150e430 100644 (file)
 #include "log.h"
 #include "config.h"
 #include "dcp_video.h"
-#include "server.h"
 #include "cross.h"
 #include "writer.h"
-#include "server_finder.h"
+#include "encode_server_finder.h"
 #include "player.h"
 #include "player_video.h"
-#include "data.h"
+#include "encode_server_description.h"
+#include "compose.hpp"
 #include <libcxml/cxml.h>
-#include <boost/lambda/lambda.hpp>
+#include <boost/foreach.hpp>
 #include <iostream>
 
 #include "i18n.h"
 
-#define LOG_GENERAL(...) _film->log()->log (String::compose (__VA_ARGS__), Log::TYPE_GENERAL);
-#define LOG_ERROR(...) _film->log()->log (String::compose (__VA_ARGS__), Log::TYPE_ERROR);
-#define LOG_TIMING(...) _film->log()->microsecond_log (String::compose (__VA_ARGS__), Log::TYPE_TIMING);
+#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::pair;
-using std::string;
-using std::vector;
 using std::list;
 using std::cout;
-using std::min;
-using std::make_pair;
 using boost::shared_ptr;
 using boost::weak_ptr;
 using boost::optional;
-using boost::scoped_array;
+using dcp::Data;
 
 int const Encoder::_history_size = 25;
 
 /** @param f Film that we are encoding */
-Encoder::Encoder (shared_ptr<const Film> film, weak_ptr<Job> j, shared_ptr<Writer> writer)
+Encoder::Encoder (shared_ptr<const Film> film, shared_ptr<Writer> writer)
        : _film (film)
-       , _job (j)
-       , _video_frames_enqueued (0)
-       , _terminate (false)
+       , _position (0)
+       , _terminate_enqueue (false)
+       , _terminate_encoding (false)
        , _writer (writer)
 {
-
+       servers_list_changed ();
 }
 
 Encoder::~Encoder ()
 {
        terminate_threads ();
-}
 
-/** Add a worker thread for a each thread on a remote server.  Caller must hold
- *  a lock on _mutex, or know that one is not currently required to
- *  safely modify _threads.
- */
-void
-Encoder::add_worker_threads (ServerDescription d)
-{
-       LOG_GENERAL (N_("Adding %1 worker threads for remote %2"), d.threads(), d.host_name ());
-       for (int i = 0; i < d.threads(); ++i) {
-               _threads.push_back (new boost::thread (boost::bind (&Encoder::encoder_thread, this, d)));
-       }
-
-       _writer->set_encoder_threads (_threads.size ());
+       boost::mutex::scoped_lock lm (_queue_mutex);
+       _terminate_enqueue = true;
+       _full_condition.notify_all ();
+       _empty_condition.notify_all ();
 }
 
 void
 Encoder::begin ()
 {
-       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<ServerDescription> ())));
-       }
-
-       _writer->set_encoder_threads (_threads.size ());
-
-       if (!ServerFinder::instance()->disabled ()) {
-               _server_found_connection = ServerFinder::instance()->connect (boost::bind (&Encoder::server_found, this, _1));
+       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 (_mutex);
+       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());
@@ -168,7 +151,7 @@ int
 Encoder::video_frames_out () const
 {
        boost::mutex::scoped_lock (_state_mutex);
-       return _video_frames_enqueued;
+       return _position;
 }
 
 /** Should be called when a frame has been encoded successfully.
@@ -187,26 +170,43 @@ Encoder::frame_done ()
        }
 }
 
-/** Called in order, so each time this is called the supplied frame is the one
- *  after the previous one.
+/** 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<shared_ptr<PlayerVideo> > pv)
+{
+       BOOST_FOREACH (shared_ptr<PlayerVideo> i, pv) {
+               enqueue (i);
+       }
+       ++_position;
+}
+
 void
 Encoder::enqueue (shared_ptr<PlayerVideo> pv)
 {
        _waker.nudge ();
 
-       boost::mutex::scoped_lock lock (_mutex);
+       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.size() * 2 && !_terminate) {
-               LOG_TIMING ("decoder sleeps with queue of %1", _queue.size());
-               _full_condition.wait (lock);
-               LOG_TIMING ("decoder wakes with queue of %1", _queue.size());
+       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) {
+       if (_terminate_enqueue) {
                return;
        }
 
@@ -217,22 +217,22 @@ Encoder::enqueue (shared_ptr<PlayerVideo> pv)
        */
        rethrow ();
 
-       if (_writer->can_fake_write (_video_frames_enqueued)) {
+       if (_writer->can_fake_write (_position)) {
                /* We can fake-write this frame */
-               _writer->fake_write (_video_frames_enqueued, pv->eyes ());
+               _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(), _video_frames_enqueued, pv->eyes ());
-       } else if (_last_player_video && pv->same (_last_player_video)) {
-               _writer->repeat (_video_frames_enqueued, pv->eyes ());
+               _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 ("adding to queue of %1", _queue.size ());
+               LOG_TIMING ("add-frame-to-queue queue=%1", _queue.size ());
                _queue.push_back (shared_ptr<DCPVideo> (
                                          new DCPVideo (
                                                  pv,
-                                                 _video_frames_enqueued,
+                                                 _position,
                                                  _film->video_frame_rate(),
                                                  _film->j2k_bandwidth(),
                                                  _film->resolution(),
@@ -246,10 +246,6 @@ Encoder::enqueue (shared_ptr<PlayerVideo> pv)
                _empty_condition.notify_all ();
        }
 
-       if (pv->eyes() != EYES_LEFT) {
-               ++_video_frames_enqueued;
-       }
-
        _last_player_video = pv;
 }
 
@@ -257,26 +253,38 @@ void
 Encoder::terminate_threads ()
 {
        {
-               boost::mutex::scoped_lock lock (_mutex);
-               _terminate = true;
-               _full_condition.notify_all ();
-               _empty_condition.notify_all ();
+               boost::mutex::scoped_lock queue_lock (_queue_mutex);
+               _terminate_encoding = true;
        }
 
+       boost::mutex::scoped_lock threads_lock (_threads_mutex);
+
+       int n = 0;
        for (list<boost::thread *>::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<ServerDescription> server)
+Encoder::encoder_thread (optional<EncodeServerDescription> 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.
@@ -285,19 +293,19 @@ try
 
        while (true) {
 
-               LOG_TIMING ("[%1] encoder thread sleeps", boost::this_thread::get_id());
-               boost::mutex::scoped_lock lock (_mutex);
-               while (_queue.empty () && !_terminate) {
+               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) {
+               if (_terminate_encoding) {
                        return;
                }
 
-               LOG_TIMING ("[%1] encoder thread wakes with queue of %2", boost::this_thread::get_id(), _queue.size());
+               LOG_TIMING ("encoder-wake thread=%1 queue=%2", boost::this_thread::get_id(), _queue.size());
                shared_ptr<DCPVideo> vf = _queue.front ();
-               LOG_TIMING ("[%1] encoder thread pops frame %2 (%3) from queue", boost::this_thread::get_id(), vf->index(), vf->eyes ());
+               LOG_TIMING ("encoder-pop thread=%1 frame=%2 eyes=%3", boost::this_thread::get_id(), vf->index(), vf->eyes ());
                _queue.pop_front ();
 
                lock.unlock ();
@@ -329,11 +337,12 @@ try
 
                } else {
                        try {
-                               LOG_TIMING ("[%1] encoder thread begins local encode of %2", boost::this_thread::get_id(), vf->index());
+                               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 ("[%1] encoder thread finishes local encode of %2", boost::this_thread::get_id(), vf->index());
+                               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;
                        }
                }
 
@@ -348,7 +357,7 @@ try
                }
 
                if (remote_backoff > 0) {
-                       dcpomatic_sleep (remote_backoff);
+                       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 */
@@ -359,10 +368,31 @@ try
 catch (...)
 {
        store_current ();
+       /* Wake anything waiting on _full_condition so it can see the exception */
+       _full_condition.notify_all ();
 }
 
 void
-Encoder::server_found (ServerDescription s)
+Encoder::servers_list_changed ()
 {
-       add_worker_threads (s);
+       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<EncodeServerDescription> ())));
+               }
+       }
+
+       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 ());
 }