Logging improvements to allow prettier displays in the server GUI.
[dcpomatic.git] / src / lib / dcp_video.cc
index b72353d9ecbc6482c6573f496275e53687d495d4..35cc282fd6f6780ad3730bbf282d01e1e5858415 100644 (file)
@@ -31,7 +31,7 @@
 #include "dcp_video.h"
 #include "config.h"
 #include "exceptions.h"
-#include "server.h"
+#include "server_description.h"
 #include "dcpomatic_socket.h"
 #include "image.h"
 #include "log.h"
 #include "player_video.h"
 #include "raw_convert.h"
 #include "data.h"
+#include "compose.hpp"
 #include <libcxml/cxml.h>
 #include <dcp/openjpeg_image.h>
 #include <dcp/rgb_xyz.h>
 #include <dcp/colour_matrix.h>
-#include <boost/array.hpp>
+#include <libxml++/libxml++.h>
 #include <boost/asio.hpp>
-#include <boost/filesystem.hpp>
-#include <boost/lexical_cast.hpp>
+#include <boost/thread.hpp>
 #include <stdint.h>
-#include <cstring>
-#include <cstdlib>
-#include <stdexcept>
-#include <cstdio>
 #include <iomanip>
 #include <iostream>
-#include <fstream>
-#include <unistd.h>
-#include <errno.h>
 
-#define LOG_GENERAL(...) _log->log (String::compose (__VA_ARGS__), Log::TYPE_GENERAL);
+#define LOG_GENERAL(...) _log->log (String::compose (__VA_ARGS__), LogEntry::TYPE_GENERAL);
+#define LOG_DEBUG_ENCODE(...) _log->log (String::compose (__VA_ARGS__), LogEntry::TYPE_DEBUG_ENCODE);
+#define LOG_TIMING(...) _log->log (String::compose (__VA_ARGS__), LogEntry::TYPE_TIMING);
 
 #include "i18n.h"
 
 using std::string;
 using std::cout;
 using boost::shared_ptr;
-using boost::lexical_cast;
 using dcp::Size;
 
 #define DCI_COEFFICENT (48.0 / 52.37)
@@ -77,14 +71,13 @@ using dcp::Size;
  *  @param l Log to write to.
  */
 DCPVideo::DCPVideo (
-       shared_ptr<const PlayerVideo> frame, int index, int dcp_fps, int bw, Resolution r, bool b, shared_ptr<Log> l
+       shared_ptr<const PlayerVideo> frame, int index, int dcp_fps, int bw, Resolution r, shared_ptr<Log> l
        )
        : _frame (frame)
        , _index (index)
        , _frames_per_second (dcp_fps)
        , _j2k_bandwidth (bw)
        , _resolution (r)
-       , _burn_subtitles (b)
        , _log (l)
 {
 
@@ -98,30 +91,37 @@ DCPVideo::DCPVideo (shared_ptr<const PlayerVideo> frame, shared_ptr<const cxml::
        _frames_per_second = node->number_child<int> ("FramesPerSecond");
        _j2k_bandwidth = node->number_child<int> ("J2KBandwidth");
        _resolution = Resolution (node->optional_number_child<int>("Resolution").get_value_or (RESOLUTION_2K));
-       _burn_subtitles = node->bool_child ("BurnSubtitles");
 }
 
-/** J2K-encode this frame on the local host.
- *  @return Encoded data.
- */
-Data
-DCPVideo::encode_locally (dcp::NoteHandler note)
+shared_ptr<dcp::OpenJPEGImage>
+DCPVideo::convert_to_xyz (shared_ptr<const PlayerVideo> frame, dcp::NoteHandler note)
 {
        shared_ptr<dcp::OpenJPEGImage> xyz;
 
-       shared_ptr<Image> image = _frame->image (AV_PIX_FMT_RGB48LE, _burn_subtitles, note);
-       if (_frame->colour_conversion()) {
+       shared_ptr<Image> image = frame->image (AV_PIX_FMT_RGB48LE, note);
+       if (frame->colour_conversion()) {
                xyz = dcp::rgb_to_xyz (
                        image->data()[0],
                        image->size(),
                        image->stride()[0],
-                       _frame->colour_conversion().get(),
+                       frame->colour_conversion().get(),
                        note
                        );
        } else {
                xyz = dcp::xyz_to_xyz (image->data()[0], image->size(), image->stride()[0]);
        }
 
+       return xyz;
+}
+
+/** J2K-encode this frame on the local host.
+ *  @return Encoded data.
+ */
+Data
+DCPVideo::encode_locally (dcp::NoteHandler note)
+{
+       shared_ptr<dcp::OpenJPEGImage> xyz = convert_to_xyz (_frame, note);
+
        /* Set the max image and component sizes based on frame_rate */
        int max_cs_len = ((float) _j2k_bandwidth) / 8 / _frames_per_second;
        if (_frame->eyes() == EYES_LEFT || _frame->eyes() == EYES_RIGHT) {
@@ -225,13 +225,13 @@ DCPVideo::encode_locally (dcp::NoteHandler note)
 
        switch (_frame->eyes()) {
        case EYES_BOTH:
-               LOG_GENERAL (N_("Finished locally-encoded frame %1 for mono"), _index);
+               LOG_DEBUG_ENCODE (N_("Finished locally-encoded frame %1 for mono"), _index);
                break;
        case EYES_LEFT:
-               LOG_GENERAL (N_("Finished locally-encoded frame %1 for L"), _index);
+               LOG_DEBUG_ENCODE (N_("Finished locally-encoded frame %1 for L"), _index);
                break;
        case EYES_RIGHT:
-               LOG_GENERAL (N_("Finished locally-encoded frame %1 for R"), _index);
+               LOG_DEBUG_ENCODE (N_("Finished locally-encoded frame %1 for R"), _index);
                break;
        default:
                break;
@@ -268,7 +268,7 @@ DCPVideo::encode_remotely (ServerDescription serv)
        root->add_child("Version")->add_child_text (raw_convert<string> (SERVER_LINK_VERSION));
        add_metadata (root);
 
-       LOG_GENERAL (N_("Sending frame %1 to remote"), _index);
+       LOG_DEBUG_ENCODE (N_("Sending frame %1 to remote"), _index);
 
        /* Send XML metadata */
        string xml = doc.write_to_string ("UTF-8");
@@ -276,15 +276,19 @@ DCPVideo::encode_remotely (ServerDescription serv)
        socket->write ((uint8_t *) xml.c_str(), xml.length() + 1);
 
        /* Send binary data */
-       _frame->send_binary (socket, _burn_subtitles);
+       LOG_TIMING("start-remote-send thread=%1", boost::this_thread::get_id());
+       _frame->send_binary (socket);
 
        /* Read the response (JPEG2000-encoded data); this blocks until the data
           is ready and sent back.
        */
+       LOG_TIMING("start-remote-encode thread=%1", boost::this_thread::get_id ());
        Data e (socket->read_uint32 ());
+       LOG_TIMING("start-remote-receive thread=%1", boost::this_thread::get_id ());
        socket->read (e.data().get(), e.size());
+       LOG_TIMING("finish-remote-receive thread=%1", boost::this_thread::get_id ());
 
-       LOG_GENERAL (N_("Finished remotely-encoded frame %1"), _index);
+       LOG_DEBUG_ENCODE (N_("Finished remotely-encoded frame %1"), _index);
 
        return e;
 }
@@ -296,8 +300,7 @@ DCPVideo::add_metadata (xmlpp::Element* el) const
        el->add_child("FramesPerSecond")->add_child_text (raw_convert<string> (_frames_per_second));
        el->add_child("J2KBandwidth")->add_child_text (raw_convert<string> (_j2k_bandwidth));
        el->add_child("Resolution")->add_child_text (raw_convert<string> (int (_resolution)));
-       el->add_child("BurnSubtitles")->add_child_text (_burn_subtitles ? "1" : "0");
-       _frame->add_metadata (el, _burn_subtitles);
+       _frame->add_metadata (el);
 }
 
 Eyes
@@ -314,8 +317,7 @@ DCPVideo::same (shared_ptr<const DCPVideo> other) const
 {
        if (_frames_per_second != other->_frames_per_second ||
            _j2k_bandwidth != other->_j2k_bandwidth ||
-           _resolution != other->_resolution ||
-           _burn_subtitles != other->_burn_subtitles) {
+           _resolution != other->_resolution) {
                return false;
        }