Merge master; fix destruction of Server; some test cleanups.
[dcpomatic.git] / src / lib / server.cc
index 5010a2051df0e92e7e6b23efac3af963fb4f83f1..66ee2b0e3cf2ca93eeb7512a03763c2598836dcc 100644 (file)
@@ -1,5 +1,5 @@
 /*
-    Copyright (C) 2012 Carl Hetherington <cth@carlh.net>
+    Copyright (C) 2012-2014 Carl Hetherington <cth@carlh.net>
 
     This program is free software; you can redistribute it and/or modify
     it under the terms of the GNU General Public License as published by
@@ -27,9 +27,9 @@
 #include <sstream>
 #include <iostream>
 #include <boost/algorithm/string.hpp>
-#include <boost/lexical_cast.hpp>
 #include <boost/scoped_array.hpp>
 #include <libcxml/cxml.h>
+#include <dcp/raw_convert.h>
 #include "server.h"
 #include "util.h"
 #include "scaler.h"
 #include "dcp_video_frame.h"
 #include "config.h"
 #include "cross.h"
+#include "player_video_frame.h"
 
 #include "i18n.h"
 
+#define LOG_GENERAL(...)    _log->log (String::compose (__VA_ARGS__), Log::TYPE_GENERAL);
+#define LOG_GENERAL_NC(...) _log->log (__VA_ARGS__, Log::TYPE_GENERAL);
+#define LOG_ERROR(...)      _log->log (String::compose (__VA_ARGS__), Log::TYPE_ERROR);
+#define LOG_ERROR_NC(...)   _log->log (__VA_ARGS__, Log::TYPE_ERROR);
+
 using std::string;
 using std::stringstream;
 using std::multimap;
 using std::vector;
 using std::list;
 using std::cout;
+using std::cerr;
+using std::setprecision;
+using std::fixed;
 using boost::shared_ptr;
 using boost::algorithm::is_any_of;
 using boost::algorithm::split;
@@ -53,82 +62,75 @@ using boost::thread;
 using boost::bind;
 using boost::scoped_array;
 using boost::optional;
-using boost::lexical_cast;
-using libdcp::Size;
-
-ServerDescription::ServerDescription (shared_ptr<const cxml::Node> node)
+using dcp::Size;
+using dcp::raw_convert;
+
+Server::Server (shared_ptr<Log> log, bool verbose)
+       : _terminate (false)
+       , _log (log)
+       , _verbose (verbose)
+       , _acceptor (_io_service, boost::asio::ip::tcp::endpoint (boost::asio::ip::tcp::v4(), Config::instance()->server_port_base()))
 {
-       _host_name = node->string_child ("HostName");
-       _threads = node->number_child<int> ("Threads");
-}
 
-void
-ServerDescription::as_xml (xmlpp::Node* root) const
-{
-       root->add_child("HostName")->add_child_text (_host_name);
-       root->add_child("Threads")->add_child_text (boost::lexical_cast<string> (_threads));
 }
 
-/** Create a server description from a string of metadata returned from as_metadata().
- *  @param v Metadata.
- *  @return ServerDescription, or 0.
- */
-optional<ServerDescription>
-ServerDescription::create_from_metadata (string v)
+Server::~Server ()
 {
-       vector<string> b;
-       split (b, v, is_any_of (" "));
-
-       if (b.size() != 2) {
-               return optional<ServerDescription> ();
+       {
+               boost::mutex::scoped_lock lm (_worker_mutex);
+               _terminate = true;
+               _worker_condition.notify_all ();
        }
 
-       return ServerDescription (b[0], atoi (b[1].c_str ()));
-}
+       for (vector<boost::thread*>::iterator i = _worker_threads.begin(); i != _worker_threads.end(); ++i) {
+               (*i)->join ();
+               delete *i;
+       }
 
-Server::Server (shared_ptr<Log> log)
-       : _log (log)
-{
+       _io_service.stop ();
 
+       _broadcast.io_service.stop ();
+       _broadcast.thread->join ();
 }
 
+/** @param after_read Filled in with gettimeofday() after reading the input from the network.
+ *  @param after_encode Filled in with gettimeofday() after encoding the image.
+ */
 int
-Server::process (shared_ptr<Socket> socket)
+Server::process (shared_ptr<Socket> socket, struct timeval& after_read, struct timeval& after_encode)
 {
        uint32_t length = socket->read_uint32 ();
        scoped_array<char> buffer (new char[length]);
        socket->read (reinterpret_cast<uint8_t*> (buffer.get()), length);
-       
+
        stringstream s (buffer.get());
        shared_ptr<cxml::Document> xml (new cxml::Document ("EncodingRequest"));
        xml->read_stream (s);
        if (xml->number_child<int> ("Version") != SERVER_LINK_VERSION) {
-               _log->log ("Mismatched server/client versions");
+               cerr << "Mismatched server/client versions\n";
+               LOG_ERROR_NC ("Mismatched server/client versions");
                return -1;
        }
 
-       libdcp::Size size (
-               xml->number_child<int> ("Width"), xml->number_child<int> ("Height")
-               );
+       shared_ptr<PlayerVideoFrame> pvf (new PlayerVideoFrame (xml, socket, _log));
 
-       shared_ptr<Image> image (new Image (PIX_FMT_RGB24, size, true));
+       DCPVideoFrame dcp_video_frame (pvf, xml, _log);
 
-       image->read_from_socket (socket);
-       DCPVideoFrame dcp_video_frame (image, xml, _log);
+       gettimeofday (&after_read, 0);
        
        shared_ptr<EncodedData> encoded = dcp_video_frame.encode_locally ();
+
+       gettimeofday (&after_encode, 0);
+       
        try {
                encoded->send (socket);
        } catch (std::exception& e) {
-               _log->log (String::compose (
-                                  "Send failed; frame %1, data size %2, pixel format %3, image size %4x%5, %6 components",
-                                  dcp_video_frame.frame(), encoded->size(), image->pixel_format(), image->size().width, image->size().height, image->components()
-                                  )
-                       );
+               cerr << "Send failed; frame " << dcp_video_frame.index() << "\n";
+               LOG_ERROR ("Send failed; frame %1", dcp_video_frame.index());
                throw;
        }
 
-       return dcp_video_frame.frame ();
+       return dcp_video_frame.index ();
 }
 
 void
@@ -136,26 +138,39 @@ Server::worker_thread ()
 {
        while (1) {
                boost::mutex::scoped_lock lock (_worker_mutex);
-               while (_queue.empty ()) {
+               while (_queue.empty () && !_terminate) {
                        _worker_condition.wait (lock);
                }
 
+               if (_terminate) {
+                       return;
+               }
+
                shared_ptr<Socket> socket = _queue.front ();
                _queue.pop_front ();
                
                lock.unlock ();
 
                int frame = -1;
+               string ip;
 
                struct timeval start;
+               struct timeval after_read;
+               struct timeval after_encode;
+               struct timeval end;
+               
                gettimeofday (&start, 0);
                
                try {
-                       frame = process (socket);
+                       frame = process (socket, after_read, after_encode);
+                       ip = socket->socket().remote_endpoint().address().to_string();
                } catch (std::exception& e) {
-                       _log->log (String::compose ("Error: %1", e.what()));
+                       cerr << "Error: " << e.what() << "\n";
+                       LOG_ERROR ("Error: %1", e.what());
                }
-               
+
+               gettimeofday (&end, 0);
+
                socket.reset ();
                
                lock.lock ();
@@ -163,8 +178,20 @@ Server::worker_thread ()
                if (frame >= 0) {
                        struct timeval end;
                        gettimeofday (&end, 0);
-                       cout << String::compose ("Encoded frame %1 in %2", frame, seconds (end) - seconds (start)) << "\n";
-                       _log->log (String::compose ("Encoded frame %1 in %2", frame, seconds (end) - seconds (start)));
+
+                       stringstream message;
+                       message.precision (2);
+                       message << fixed
+                               << "Encoded frame " << frame << " from " << ip << ": "
+                               << "receive " << (seconds(after_read) - seconds(start)) << "s "
+                               << "encode " << (seconds(after_encode) - seconds(after_read)) << "s "
+                               << "send " << (seconds(end) - seconds(after_encode)) << "s.";
+                                                  
+                       if (_verbose) {
+                               cout << message.str() << "\n";
+                       }
+
+                       LOG_GENERAL_NC (message.str ());
                }
                
                _worker_condition.notify_all ();
@@ -174,7 +201,10 @@ Server::worker_thread ()
 void
 Server::run (int num_threads)
 {
-       _log->log (String::compose (N_("Server starting with %1 threads"), num_threads));
+       LOG_GENERAL ("Server starting with %1 threads", num_threads);
+       if (_verbose) {
+               cout << "DCP-o-matic server starting with " << num_threads << " threads.\n";
+       }
        
        for (int i = 0; i < num_threads; ++i) {
                _worker_threads.push_back (new thread (bind (&Server::worker_thread, this)));
@@ -182,38 +212,18 @@ Server::run (int num_threads)
 
        _broadcast.thread = new thread (bind (&Server::broadcast_thread, this));
        
-       boost::asio::io_service io_service;
-
-       boost::asio::ip::tcp::acceptor acceptor (
-               io_service,
-               boost::asio::ip::tcp::endpoint (boost::asio::ip::tcp::v4(), Config::instance()->server_port_base ())
-               );
-       
-       while (1) {
-               shared_ptr<Socket> socket (new Socket);
-               acceptor.accept (socket->socket ());
-
-               boost::mutex::scoped_lock lock (_worker_mutex);
-               
-               /* Wait until the queue has gone down a bit */
-               while (int (_queue.size()) >= num_threads * 2) {
-                       _worker_condition.wait (lock);
-               }
-               
-               _queue.push_back (socket);
-               _worker_condition.notify_all ();
-       }
+       start_accept ();
+       _io_service.run ();
 }
 
 void
 Server::broadcast_thread ()
+try
 {
-       boost::asio::io_service io_service;
-
        boost::asio::ip::address address = boost::asio::ip::address_v4::any ();
        boost::asio::ip::udp::endpoint listen_endpoint (address, Config::instance()->server_port_base() + 1);
 
-       _broadcast.socket = new boost::asio::ip::udp::socket (io_service);
+       _broadcast.socket = new boost::asio::ip::udp::socket (_broadcast.io_service);
        _broadcast.socket->open (listen_endpoint.protocol ());
        _broadcast.socket->bind (listen_endpoint);
 
@@ -223,7 +233,11 @@ Server::broadcast_thread ()
                boost::bind (&Server::broadcast_received, this)
                );
 
-       io_service.run ();
+       _broadcast.io_service.run ();
+}
+catch (...)
+{
+       store_current ();
 }
 
 void
@@ -235,7 +249,7 @@ Server::broadcast_received ()
                /* Reply to the client saying what we can do */
                xmlpp::Document doc;
                xmlpp::Element* root = doc.create_root_node ("ServerAvailable");
-               root->add_child("Threads")->add_child_text (lexical_cast<string> (_worker_threads.size ()));
+               root->add_child("Threads")->add_child_text (raw_convert<string> (_worker_threads.size ()));
                stringstream xml;
                doc.write_to_stream (xml, "UTF-8");
 
@@ -254,3 +268,35 @@ Server::broadcast_received ()
                _broadcast.send_endpoint, boost::bind (&Server::broadcast_received, this)
                );
 }
+
+void
+Server::start_accept ()
+{
+       if (_terminate) {
+               return;
+       }
+
+       shared_ptr<Socket> socket (new Socket);
+       _acceptor.async_accept (socket->socket (), boost::bind (&Server::handle_accept, this, socket, boost::asio::placeholders::error));
+}
+
+void
+Server::handle_accept (shared_ptr<Socket> socket, boost::system::error_code const & error)
+{
+       if (error) {
+               return;
+       }
+
+       boost::mutex::scoped_lock lock (_worker_mutex);
+       
+       /* Wait until the queue has gone down a bit */
+       while (_queue.size() >= _worker_threads.size() * 2 && !_terminate) {
+               _worker_condition.wait (lock);
+       }
+       
+       _queue.push_back (socket);
+       _worker_condition.notify_all ();
+
+       start_accept ();
+}
+