Logging improvements to allow prettier displays in the server GUI.
[dcpomatic.git] / src / lib / dcp_video.cc
index f6c671fd14774b655acb67708b75084c6a49eaf8..35cc282fd6f6780ad3730bbf282d01e1e5858415 100644 (file)
@@ -1,5 +1,5 @@
 /*
-    Copyright (C) 2012-2014 Carl Hetherington <cth@carlh.net>
+    Copyright (C) 2012-2015 Carl Hetherington <cth@carlh.net>
     Taken from code Copyright (C) 2010-2011 Terrence Meiczinger
 
     This program is free software; you can redistribute it and/or modify
  *  of images that require encoding.
  */
 
-#include <stdint.h>
-#include <cstring>
-#include <cstdlib>
-#include <stdexcept>
-#include <cstdio>
-#include <iomanip>
-#include <iostream>
-#include <fstream>
-#include <unistd.h>
-#include <errno.h>
-#include <boost/array.hpp>
-#include <boost/asio.hpp>
-#include <boost/filesystem.hpp>
-#include <boost/lexical_cast.hpp>
-#include <dcp/gamma_lut.h>
-#include <dcp/xyz_frame.h>
-#include <dcp/rgb_xyz.h>
-#include <dcp/colour_matrix.h>
-#include <dcp/raw_convert.h>
-#include <libcxml/cxml.h>
-#include "film.h"
 #include "dcp_video.h"
 #include "config.h"
 #include "exceptions.h"
-#include "server.h"
-#include "util.h"
-#include "scaler.h"
+#include "server_description.h"
+#include "dcpomatic_socket.h"
 #include "image.h"
 #include "log.h"
 #include "cross.h"
 #include "player_video.h"
-#include "encoded_data.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 <libxml++/libxml++.h>
+#include <boost/asio.hpp>
+#include <boost/thread.hpp>
+#include <stdint.h>
+#include <iomanip>
+#include <iostream>
 
-#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;
-using dcp::raw_convert;
 
 #define DCI_COEFFICENT (48.0 / 52.37)
 
@@ -81,17 +71,16 @@ using dcp::raw_convert;
  *  @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)
 {
-       
+
 }
 
 DCPVideo::DCPVideo (shared_ptr<const PlayerVideo> frame, shared_ptr<const cxml::Node> node, shared_ptr<Log> log)
@@ -102,34 +91,36 @@ 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");
+}
+
+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, note);
+       if (frame->colour_conversion()) {
+               xyz = dcp::rgb_to_xyz (
+                       image->data()[0],
+                       image->size(),
+                       image->stride()[0],
+                       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.
  */
-shared_ptr<EncodedData>
-DCPVideo::encode_locally ()
+Data
+DCPVideo::encode_locally (dcp::NoteHandler note)
 {
-       shared_ptr<dcp::GammaLUT> in_lut = dcp::GammaLUT::cache.get (
-               12, _frame->colour_conversion().input_gamma, _frame->colour_conversion().input_gamma_linearised
-               );
-       
-       /* XXX: libdcp should probably use boost */
-       
-       double matrix[3][3];
-       for (int i = 0; i < 3; ++i) {
-               for (int j = 0; j < 3; ++j) {
-                       matrix[i][j] = _frame->colour_conversion().matrix (i, j);
-               }
-       }
-
-       shared_ptr<dcp::XYZFrame> xyz = dcp::rgb_to_xyz (
-               _frame->image (AV_PIX_FMT_RGB48LE, _burn_subtitles),
-               in_lut,
-               dcp::GammaLUT::cache.get (16, 1 / _frame->colour_conversion().output_gamma, false),
-               matrix
-               );
+       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;
@@ -153,11 +144,11 @@ DCPVideo::encode_locally ()
        parameters.tile_size_on = false;
        parameters.cp_tdx = 1;
        parameters.cp_tdy = 1;
-       
+
        /* Tile part */
        parameters.tp_flag = 'C';
        parameters.tp_on = 1;
-       
+
        /* Tile and Image shall be at (0,0) */
        parameters.cp_tx0 = 0;
        parameters.cp_ty0 = 0;
@@ -168,19 +159,19 @@ DCPVideo::encode_locally ()
        parameters.cblockw_init = 32;
        parameters.cblockh_init = 32;
        parameters.csty |= 0x01;
-       
+
        /* The progression order shall be CPRL */
        parameters.prog_order = CPRL;
-       
+
        /* No ROI */
        parameters.roi_compno = -1;
-       
+
        parameters.subsampling_dx = 1;
        parameters.subsampling_dy = 1;
-       
+
        /* 9-7 transform */
        parameters.irreversible = 1;
-       
+
        parameters.tcp_rates[0] = 0;
        parameters.tcp_numlayers++;
        parameters.cp_disto_alloc = 1;
@@ -188,27 +179,27 @@ DCPVideo::encode_locally ()
        if (_resolution == RESOLUTION_4K) {
                parameters.numpocs = 2;
                parameters.POC[0].tile = 1;
-               parameters.POC[0].resno0 = 0; 
+               parameters.POC[0].resno0 = 0;
                parameters.POC[0].compno0 = 0;
                parameters.POC[0].layno1 = 1;
                parameters.POC[0].resno1 = parameters.numresolution - 1;
                parameters.POC[0].compno1 = 3;
                parameters.POC[0].prg1 = CPRL;
                parameters.POC[1].tile = 1;
-               parameters.POC[1].resno0 = parameters.numresolution - 1; 
+               parameters.POC[1].resno0 = parameters.numresolution - 1;
                parameters.POC[1].compno0 = 0;
                parameters.POC[1].layno1 = 1;
                parameters.POC[1].resno1 = parameters.numresolution;
                parameters.POC[1].compno1 = 3;
                parameters.POC[1].prg1 = CPRL;
        }
-       
+
        parameters.cp_comment = strdup (N_("DCP-o-matic"));
        parameters.cp_cinema = _resolution == RESOLUTION_2K ? CINEMA2K_24 : CINEMA4K_24;
 
        /* 3 components, so use MCT */
        parameters.tcp_mct = 1;
-       
+
        /* set max image */
        parameters.max_comp_size = max_comp_size;
        parameters.tcp_rates[0] = ((float) (3 * xyz->size().width * xyz->size().height * 12)) / (max_cs_len * 8);
@@ -234,19 +225,19 @@ DCPVideo::encode_locally ()
 
        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;
        }
 
-       shared_ptr<EncodedData> enc (new LocallyEncodedData (cio->buffer, cio_tell (cio)));
+       Data enc (cio->buffer, cio_tell (cio));
 
        opj_cio_close (cio);
        free (parameters.cp_comment);
@@ -259,7 +250,7 @@ DCPVideo::encode_locally ()
  *  @param serv Server to send to.
  *  @return Encoded data.
  */
-shared_ptr<EncodedData>
+Data
 DCPVideo::encode_remotely (ServerDescription serv)
 {
        boost::asio::io_service io_service;
@@ -277,24 +268,28 @@ 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");
        socket->write (xml.length() + 1);
        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.
        */
-       shared_ptr<EncodedData> e (new RemotelyEncodedData (socket->read_uint32 ()));
-       socket->read (e->data(), e->size());
+       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_DEBUG_ENCODE (N_("Finished remotely-encoded frame %1"), _index);
 
-       LOG_GENERAL (N_("Finished remotely-encoded frame %1"), _index);
-       
        return e;
 }
 
@@ -305,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
@@ -323,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;
        }