Logging improvements to allow prettier displays in the server GUI.
[dcpomatic.git] / src / lib / dcp_video.cc
index a01a72f6b83aebb0a698a957549ea8a37019cbc7..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
 #include "dcp_video.h"
 #include "config.h"
 #include "exceptions.h"
-#include "server.h"
+#include "server_description.h"
 #include "dcpomatic_socket.h"
-#include "scaler.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/xyz_frame.h>
+#include <dcp/openjpeg_image.h>
 #include <dcp/rgb_xyz.h>
 #include <dcp/colour_matrix.h>
-#include <dcp/raw_convert.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;
-using dcp::raw_convert;
 
 #define DCI_COEFFICENT (48.0 / 52.37)
 
@@ -79,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)
@@ -100,26 +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.
- */
-shared_ptr<EncodedData>
-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::XYZFrame> xyz;
+       shared_ptr<dcp::OpenJPEGImage> xyz;
 
-       if (_frame->colour_conversion()) {
+       shared_ptr<Image> image = frame->image (AV_PIX_FMT_RGB48LE, note);
+       if (frame->colour_conversion()) {
                xyz = dcp::rgb_to_xyz (
-                       _frame->image (AV_PIX_FMT_RGB48LE, _burn_subtitles, note),
-                       _frame->colour_conversion().get()
+                       image->data()[0],
+                       image->size(),
+                       image->stride()[0],
+                       frame->colour_conversion().get(),
+                       note
                        );
        } else {
-               xyz = dcp::xyz_to_xyz (_frame->image (AV_PIX_FMT_RGB48LE, _burn_subtitles, note));
+               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) {
@@ -142,11 +144,11 @@ DCPVideo::encode_locally (dcp::NoteHandler note)
        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;
@@ -157,19 +159,19 @@ DCPVideo::encode_locally (dcp::NoteHandler note)
        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;
@@ -177,27 +179,27 @@ DCPVideo::encode_locally (dcp::NoteHandler note)
        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);
@@ -223,19 +225,19 @@ 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;
        }
 
-       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);
@@ -248,7 +250,7 @@ DCPVideo::encode_locally (dcp::NoteHandler note)
  *  @param serv Server to send to.
  *  @return Encoded data.
  */
-shared_ptr<EncodedData>
+Data
 DCPVideo::encode_remotely (ServerDescription serv)
 {
        boost::asio::io_service io_service;
@@ -266,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;
 }
 
@@ -294,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
@@ -312,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;
        }