Some work on rationalising and tidying up timing logging.

[dcpomatic.git] / src / lib / encoder.cc

diff --git a/src/lib/encoder.cc b/src/lib/encoder.cc
index 93e15031db14f2b754a824fccf2d65ad4c743285..08f4e66d482bbf4ec8f2c437cdf5a9d6cd3c83f1 100644 (file)
--- a/src/lib/encoder.cc
+++ b/src/lib/encoder.cc
@@ -34,8 +34,9 @@
 #include "player.h"
 #include "player_video.h"
 #include "data.h"
+#include "compose.hpp"
 #include <libcxml/cxml.h>
-#include <boost/lambda/lambda.hpp>
+#include <boost/foreach.hpp>
 #include <iostream>
 
 #include "i18n.h"
@@ -44,17 +45,11 @@
 #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);
 
-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;
 
 int const Encoder::_history_size = 25;
 
@@ -63,10 +58,12 @@ Encoder::Encoder (shared_ptr<const Film> film, weak_ptr<Job> j, shared_ptr<Write
        : _film (film)
        , _job (j)
        , _video_frames_enqueued (0)
+       , _left_done (false)
+       , _right_done (false)
        , _terminate (false)
        , _writer (writer)
 {
-
+       servers_list_changed ();
 }
 
 Encoder::~Encoder ()
@@ -92,14 +89,16 @@ Encoder::add_worker_threads (ServerDescription d)
 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> ())));
+       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<ServerDescription> ())));
+               }
        }
 
        _writer->set_encoder_threads (_threads.size ());
 
        if (!ServerFinder::instance()->disabled ()) {
-               _server_found_connection = ServerFinder::instance()->connect (boost::bind (&Encoder::server_found, this, _1));
+               _server_found_connection = ServerFinder::instance()->ServersListChanged.connect (boost::bind (&Encoder::servers_list_changed, this));
        }
 }
 
@@ -201,9 +200,9 @@ Encoder::enqueue (shared_ptr<PlayerVideo> pv)
 
        /* 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());
+               LOG_TIMING ("decoder-sleep queue=%1", _queue.size());
                _full_condition.wait (lock);
-               LOG_TIMING ("decoder wakes with queue of %1", _queue.size());
+               LOG_TIMING ("decoder-wake queue=%1", _queue.size());
        }
 
        if (_terminate) {
@@ -228,7 +227,7 @@ Encoder::enqueue (shared_ptr<PlayerVideo> pv)
                _writer->repeat (_video_frames_enqueued, 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,
@@ -236,7 +235,6 @@ Encoder::enqueue (shared_ptr<PlayerVideo> pv)
                                                  _film->video_frame_rate(),
                                                  _film->j2k_bandwidth(),
                                                  _film->resolution(),
-                                                 _film->burn_subtitles(),
                                                  _film->log()
                                                  )
                                          ));
@@ -247,8 +245,23 @@ Encoder::enqueue (shared_ptr<PlayerVideo> pv)
                _empty_condition.notify_all ();
        }
 
-       if (pv->eyes() != EYES_LEFT) {
+       switch (pv->eyes ()) {
+       case EYES_BOTH:
                ++_video_frames_enqueued;
+               break;
+       case EYES_LEFT:
+               _left_done = true;
+               break;
+       case EYES_RIGHT:
+               _right_done = true;
+               break;
+       default:
+               break;
+       }
+
+       if (_left_done && _right_done) {
+               ++_video_frames_enqueued;
+               _left_done = _right_done = false;
        }
 
        _last_player_video = pv;
@@ -272,6 +285,7 @@ Encoder::terminate_threads ()
        }
 
        _threads.clear ();
+       _terminate = false;
 }
 
 void
@@ -286,7 +300,7 @@ try
 
        while (true) {
 
-               LOG_TIMING ("[%1] encoder thread sleeps", boost::this_thread::get_id());
+               LOG_TIMING ("encoder-sleep thread=%1", boost::this_thread::get_id());
                boost::mutex::scoped_lock lock (_mutex);
                while (_queue.empty () && !_terminate) {
                        _empty_condition.wait (lock);
@@ -296,9 +310,9 @@ try
                        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 ();
@@ -330,9 +344,9 @@ 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 ());
                        }
@@ -363,7 +377,10 @@ catch (...)
 }
 
 void
-Encoder::server_found (ServerDescription s)
+Encoder::servers_list_changed ()
 {
-       add_worker_threads (s);
+       terminate_threads ();
+       BOOST_FOREACH (ServerDescription i, ServerFinder::instance()->servers ()) {
+               add_worker_threads (i);
+       }
 }