Logging improvements to allow prettier displays in the server GUI.

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

diff --git a/src/lib/dcp_video.cc b/src/lib/dcp_video.cc
index 7610e6c9f43a5e1dda8643c8ad5f850ec5e1c67b..35cc282fd6f6780ad3730bbf282d01e1e5858415 100644 (file)
--- a/src/lib/dcp_video.cc
+++ b/src/lib/dcp_video.cc
@@ -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"
@@ -39,34 +39,27 @@
 #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_DEBUG_ENCODE(...) _log->log (String::compose (__VA_ARGS__), Log::TYPE_DEBUG_ENCODE);
+#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)
@@ -100,27 +93,35 @@ DCPVideo::DCPVideo (shared_ptr<const PlayerVideo> frame, shared_ptr<const cxml::
        _resolution = Resolution (node->optional_number_child<int>("Resolution").get_value_or (RESOLUTION_2K));
 }
 
-/** 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, 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) {
@@ -275,13 +276,17 @@ DCPVideo::encode_remotely (ServerDescription serv)
        socket->write ((uint8_t *) xml.c_str(), xml.length() + 1);
 
        /* Send binary data */
+       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_DEBUG_ENCODE (N_("Finished remotely-encoded frame %1"), _index);