Tidy up logging a bit. Make it configurable from the GUI.
authorCarl Hetherington <cth@carlh.net>
Wed, 21 May 2014 15:44:06 +0000 (16:44 +0100)
committerCarl Hetherington <cth@carlh.net>
Wed, 21 May 2014 15:44:06 +0000 (16:44 +0100)
26 files changed:
ChangeLog
src/lib/config.cc
src/lib/config.h
src/lib/cross.cc
src/lib/dcp_video_frame.cc
src/lib/encoder.cc
src/lib/ffmpeg_content.cc
src/lib/ffmpeg_decoder.cc
src/lib/film.cc
src/lib/image_decoder.cc
src/lib/image_proxy.cc
src/lib/image_proxy.h
src/lib/log.cc
src/lib/log.h
src/lib/player.cc
src/lib/player_video_frame.cc
src/lib/player_video_frame.h
src/lib/scp_dcp_job.cc
src/lib/server.cc
src/lib/transcode_job.cc
src/lib/util.h
src/lib/writer.cc
src/tools/dcpomatic.cc
src/tools/dcpomatic_cli.cc
src/wx/config_dialog.cc
test/client_server_test.cc

index da42e7ba1e65b1873ce39b9549c8e396895d10cd..0b6a24f8ae708a3c73c7a75705cb042fcfe9bac7 100644 (file)
--- a/ChangeLog
+++ b/ChangeLog
@@ -1,3 +1,9 @@
+2014-05-21  Carl Hetherington  <cth@carlh.net>
+
+       * Tidy up logging a bit and make it configurable from the GUI
+       (moving a few things into an Advanced preferences tab at
+       the same time).
+
 2014-05-19  Carl Hetherington  <cth@carlh.net>
 
        * Version 1.69.9 released.
index 40ae3971be9bd0ba5781bb9496bb7f9bf2f7b257..6d029dd1fa1e545f7ebf0d28bac9ed840737f310 100644 (file)
@@ -73,6 +73,7 @@ Config::Config ()
        , _check_for_updates (false)
        , _check_for_test_updates (false)
        , _maximum_j2k_bandwidth (250000000)
+       , _log_types (Log::GENERAL | Log::WARNING | Log::ERROR)
 {
        _allowed_dcp_frame_rates.push_back (24);
        _allowed_dcp_frame_rates.push_back (25);
@@ -189,6 +190,8 @@ Config::read ()
 
        _maximum_j2k_bandwidth = f.optional_number_child<int> ("MaximumJ2KBandwidth").get_value_or (250000000);
        _allow_any_dcp_frame_rate = f.optional_bool_child ("AllowAnyDCPFrameRate");
+
+       _log_types = f.optional_number_child<int> ("LogTypes").get_value_or (Log::GENERAL | Log::WARNING | Log::ERROR);
 }
 
 void
@@ -366,6 +369,7 @@ Config::write () const
 
        root->add_child("MaximumJ2KBandwidth")->add_child_text (raw_convert<string> (_maximum_j2k_bandwidth));
        root->add_child("AllowAnyDCPFrameRate")->add_child_text (_allow_any_dcp_frame_rate ? "1" : "0");
+       root->add_child("LogTypes")->add_child_text (raw_convert<string> (_log_types));
        
        doc.write_to_file_formatted (file(false).string ());
 }
index 87b7038def5844843db76892d76ae6c20a2d8969..bd8cfe2973b43ddc258c0780a7e279fa82c6da74 100644 (file)
@@ -188,6 +188,10 @@ public:
        int maximum_j2k_bandwidth () const {
                return _maximum_j2k_bandwidth;
        }
+
+       int log_types () const {
+               return _log_types;
+       }
        
        /** @param n New number of local encoding threads */
        void set_num_local_encoding_threads (int n) {
@@ -339,6 +343,11 @@ public:
                _maximum_j2k_bandwidth = b;
                changed ();
        }
+
+       void set_log_types (int t) {
+               _log_types = t;
+               changed ();
+       }
        
        boost::filesystem::path signer_chain_directory () const;
 
@@ -401,6 +410,7 @@ private:
        bool _check_for_test_updates;
        /** maximum allowed J2K bandwidth in bits per second */
        int _maximum_j2k_bandwidth;
+       int _log_types;
 
        /** Singleton instance, or 0 */
        static Config* _instance;
index 8785553cbe32ccfc3f35656739f6b22432eab374..9247baa97c2da963ba69d1b3bdeded56e0a780f7 100644 (file)
 #endif
 #include "exceptions.h"
 
+#include "i18n.h"
+
+#define LOG_GENERAL(...) log->log (String::compose (__VA_ARGS__), Log::GENERAL);
+#define LOG_ERROR(...) log->log (String::compose (__VA_ARGS__), Log::ERROR);
+
 using std::pair;
 using std::list;
 using std::ifstream;
@@ -184,13 +189,13 @@ run_ffprobe (boost::filesystem::path content, boost::filesystem::path out, share
        PROCESS_INFORMATION process_info;
        ZeroMemory (&process_info, sizeof (process_info));
        if (!CreateProcess (0, command, 0, 0, TRUE, CREATE_NO_WINDOW, 0, 0, &startup_info, &process_info)) {
-               log->log ("ffprobe call failed (could not CreateProcess)");
+               LOG_ERROR (N_("ffprobe call failed (could not CreateProcess)"));
                return;
        }
 
        FILE* o = fopen_boost (out, "w");
        if (!o) {
-               log->log ("ffprobe call failed (could not create output file)");
+               LOG_ERROR (N_("ffprobe call failed (could not create output file)"));
                return;
        }
 
@@ -215,7 +220,7 @@ run_ffprobe (boost::filesystem::path content, boost::filesystem::path out, share
 
 #ifdef DCPOMATIC_LINUX 
        string ffprobe = "ffprobe \"" + content.string() + "\" 2> \"" + out.string() + "\"";
-       log->log (String::compose ("Probing with %1", ffprobe));
+       LOG_GENERAL (N_("Probing with %1"), ffprobe);
         system (ffprobe.c_str ());
 #endif
 
@@ -225,7 +230,7 @@ run_ffprobe (boost::filesystem::path content, boost::filesystem::path out, share
        path /= "ffprobe";
        
        string ffprobe = path.string() + " \"" + content.string() + "\" 2> \"" + out.string() + "\"";
-       log->log (String::compose ("Probing with %1", ffprobe));
+       LOG_GENERAL (N_("Probing with %1"), ffprobe);
        system (ffprobe.c_str ());
 #endif
 }
index 5cd6a118e6256987646734b0a2d47b4187872ac3..265cbaae8cc7d7a895382fcbcc55a1e0b85f3168 100644 (file)
@@ -63,6 +63,8 @@
 #include "cross.h"
 #include "player_video_frame.h"
 
+#define LOG_GENERAL(...) _log->log (String::compose (__VA_ARGS__), Log::GENERAL);
+
 #include "i18n.h"
 
 using std::string;
@@ -250,13 +252,13 @@ DCPVideoFrame::encode_locally ()
 
        switch (_frame->eyes()) {
        case EYES_BOTH:
-               _log->log (String::compose (N_("Finished locally-encoded frame %1 for mono"), _index));
+               LOG_GENERAL (N_("Finished locally-encoded frame %1 for mono"), _index);
                break;
        case EYES_LEFT:
-               _log->log (String::compose (N_("Finished locally-encoded frame %1 for L"), _index));
+               LOG_GENERAL (N_("Finished locally-encoded frame %1 for L"), _index);
                break;
        case EYES_RIGHT:
-               _log->log (String::compose (N_("Finished locally-encoded frame %1 for R"), _index));
+               LOG_GENERAL (N_("Finished locally-encoded frame %1 for R"), _index);
                break;
        default:
                break;
@@ -293,7 +295,7 @@ DCPVideoFrame::encode_remotely (ServerDescription serv)
        root->add_child("Version")->add_child_text (raw_convert<string> (SERVER_LINK_VERSION));
        add_metadata (root);
 
-       _log->log (String::compose (N_("Sending frame %1 to remote"), _index));
+       LOG_GENERAL (N_("Sending frame %1 to remote"), _index);
        
        /* Send XML metadata */
        stringstream xml;
@@ -310,7 +312,7 @@ DCPVideoFrame::encode_remotely (ServerDescription serv)
        shared_ptr<EncodedData> e (new RemotelyEncodedData (socket->read_uint32 ()));
        socket->read (e->data(), e->size());
 
-       _log->log (String::compose (N_("Finished remotely-encoded frame %1"), _index));
+       LOG_GENERAL (N_("Finished remotely-encoded frame %1"), _index);
        
        return e;
 }
index 4fc2d7f81c152b760d00b0a8e0db79c2dd307c0c..05da6bbdf53db33e0ec62847bd2e0a6e02c4b9c8 100644 (file)
 
 #include "i18n.h"
 
+#define LOG_GENERAL(...) _film->log()->log (String::compose (__VA_ARGS__), Log::GENERAL);
+#define LOG_ERROR(...) _film->log()->log (String::compose (__VA_ARGS__), Log::ERROR);
+#define LOG_TIMING(...) _film->log()->log (String::compose (__VA_ARGS__), Log::TIMING);
+
 using std::pair;
 using std::string;
 using std::stringstream;
@@ -78,7 +82,7 @@ Encoder::~Encoder ()
 void
 Encoder::add_worker_threads (ServerDescription d)
 {
-       _film->log()->log (String::compose (N_("Adding %1 worker threads for remote %2"), d.host_name ()));
+       LOG_GENERAL (N_("Adding %1 worker threads for remote %2"), d.host_name ());
        for (int i = 0; i < d.threads(); ++i) {
                _threads.push_back (new boost::thread (boost::bind (&Encoder::encoder_thread, this, d)));
        }
@@ -100,11 +104,10 @@ Encoder::process_end ()
 {
        boost::mutex::scoped_lock lock (_mutex);
 
-       _film->log()->log (String::compose (N_("Clearing queue of %1"), _queue.size ()));
+       LOG_GENERAL (N_("Clearing queue of %1"), _queue.size ());
 
        /* Keep waking workers until the queue is empty */
        while (!_queue.empty ()) {
-               _film->log()->log (String::compose (N_("Waking with %1"), _queue.size ()), Log::VERBOSE);
                _condition.notify_all ();
                _condition.wait (lock);
        }
@@ -113,7 +116,7 @@ Encoder::process_end ()
        
        terminate_threads ();
 
-       _film->log()->log (String::compose (N_("Mopping up %1"), _queue.size()));
+       LOG_GENERAL (N_("Mopping up %1"), _queue.size());
 
        /* The following sequence of events can occur in the above code:
             1. a remote worker takes the last image off the queue
@@ -125,12 +128,12 @@ Encoder::process_end ()
        */
 
        for (list<shared_ptr<DCPVideoFrame> >::iterator i = _queue.begin(); i != _queue.end(); ++i) {
-               _film->log()->log (String::compose (N_("Encode left-over frame %1"), (*i)->index ()));
+               LOG_GENERAL (N_("Encode left-over frame %1"), (*i)->index ());
                try {
                        _writer->write ((*i)->encode_locally(), (*i)->index (), (*i)->eyes ());
                        frame_done ();
                } catch (std::exception& e) {
-                       _film->log()->log (String::compose (N_("Local encode failed (%1)"), e.what ()));
+                       LOG_ERROR (N_("Local encode failed (%1)"), e.what ());
                }
        }
                
@@ -190,9 +193,9 @@ Encoder::process_video (shared_ptr<PlayerVideoFrame> pvf, bool same)
 
        /* Wait until the queue has gone down a bit */
        while (_queue.size() >= _threads.size() * 2 && !_terminate) {
-               TIMING ("decoder sleeps with queue of %1", _queue.size());
+               LOG_TIMING ("decoder sleeps with queue of %1", _queue.size());
                _condition.wait (lock);
-               TIMING ("decoder wakes with queue of %1", _queue.size());
+               LOG_TIMING ("decoder wakes with queue of %1", _queue.size());
        }
 
        if (_terminate) {
@@ -216,7 +219,7 @@ Encoder::process_video (shared_ptr<PlayerVideoFrame> pvf, bool same)
                frame_done ();
        } else {
                /* Queue this new frame for encoding */
-               TIMING ("adding to queue of %1", _queue.size ());
+               LOG_TIMING ("adding to queue of %1", _queue.size ());
                _queue.push_back (shared_ptr<DCPVideoFrame> (
                                          new DCPVideoFrame (
                                                  pvf, _video_frames_out, _film->video_frame_rate(),
@@ -270,7 +273,7 @@ try
        
        while (1) {
 
-               TIMING ("encoder thread %1 sleeps", boost::this_thread::get_id());
+               LOG_TIMING ("encoder thread %1 sleeps", boost::this_thread::get_id());
                boost::mutex::scoped_lock lock (_mutex);
                while (_queue.empty () && !_terminate) {
                        _condition.wait (lock);
@@ -280,9 +283,9 @@ try
                        return;
                }
 
-               TIMING ("encoder thread %1 wakes with queue of %2", boost::this_thread::get_id(), _queue.size());
+               LOG_TIMING ("encoder thread %1 wakes with queue of %2", boost::this_thread::get_id(), _queue.size());
                shared_ptr<DCPVideoFrame> vf = _queue.front ();
-               TIMING ("encoder thread %1 pops frame %2 (%3) from queue", boost::this_thread::get_id(), vf->index(), vf->eyes ());
+               LOG_TIMING ("encoder thread %1 pops frame %2 (%3) from queue", boost::this_thread::get_id(), vf->index(), vf->eyes ());
                _queue.pop_front ();
                
                lock.unlock ();
@@ -294,7 +297,7 @@ try
                                encoded = vf->encode_remotely (server.get ());
 
                                if (remote_backoff > 0) {
-                                       _film->log()->log (String::compose (N_("%1 was lost, but now she is found; removing backoff"), server->host_name ()));
+                                       LOG_GENERAL ("%1 was lost, but now she is found; removing backoff", server->host_name ());
                                }
                                
                                /* This job succeeded, so remove any backoff */
@@ -305,20 +308,19 @@ try
                                        /* back off more */
                                        remote_backoff += 10;
                                }
-                               _film->log()->log (
-                                       String::compose (
-                                               N_("Remote encode of %1 on %2 failed (%3); thread sleeping for %4s"),
-                                               vf->index(), server->host_name(), e.what(), remote_backoff)
+                               LOG_ERROR (
+                                       N_("Remote encode of %1 on %2 failed (%3); thread sleeping for %4s"),
+                                       vf->index(), server->host_name(), e.what(), remote_backoff
                                        );
                        }
                                
                } else {
                        try {
-                               TIMING ("encoder thread %1 begins local encode of %2", boost::this_thread::get_id(), vf->index());
+                               LOG_TIMING ("encoder thread %1 begins local encode of %2", boost::this_thread::get_id(), vf->index());
                                encoded = vf->encode_locally ();
-                               TIMING ("encoder thread %1 finishes local encode of %2", boost::this_thread::get_id(), vf->index());
+                               LOG_TIMING ("encoder thread %1 finishes local encode of %2", boost::this_thread::get_id(), vf->index());
                        } catch (std::exception& e) {
-                               _film->log()->log (String::compose (N_("Local encode failed (%1)"), e.what ()));
+                               LOG_ERROR (N_("Local encode failed (%1)"), e.what ());
                        }
                }
 
@@ -327,9 +329,7 @@ try
                        frame_done ();
                } else {
                        lock.lock ();
-                       _film->log()->log (
-                               String::compose (N_("Encoder thread %1 pushes frame %2 back onto queue after failure"), boost::this_thread::get_id(), vf->index())
-                               );
+                       LOG_GENERAL (N_("Encoder thread %1 pushes frame %2 back onto queue after failure"), boost::this_thread::get_id(), vf->index());
                        _queue.push_front (vf);
                        lock.unlock ();
                }
index f810d53be21374e27cd3e929214d04130fcb98b6..5d0a6a309aac4263aa3c6409c5a518065e72f020 100644 (file)
@@ -34,6 +34,8 @@ extern "C" {
 
 #include "i18n.h"
 
+#define LOG_GENERAL(...) film->log()->log (String::compose (__VA_ARGS__), Log::GENERAL);
+
 using std::string;
 using std::stringstream;
 using std::vector;
@@ -171,7 +173,7 @@ FFmpegContent::examine (shared_ptr<Job> job)
 
        VideoContent::Frame video_length = 0;
        video_length = examiner->video_length ();
-       film->log()->log (String::compose ("Video length obtained from header as %1 frames", video_length));
+       LOG_GENERAL ("Video length obtained from header as %1 frames", video_length);
 
        {
                boost::mutex::scoped_lock lm (_mutex);
index 7a5bf8ba832f51a538ea57775147ba20296a3c06..6351c7e2200edaa73c14e3bc100a865c755df71e 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
@@ -46,6 +46,10 @@ extern "C" {
 
 #include "i18n.h"
 
+#define LOG_GENERAL(...) film->log()->log (String::compose (__VA_ARGS__), Log::GENERAL);
+#define LOG_ERROR(...) film->log()->log (String::compose (__VA_ARGS__), Log::ERROR);
+#define LOG_WARNING(...) film->log()->log (__VA_ARGS__, Log::WARNING);
+
 using std::cout;
 using std::string;
 using std::vector;
@@ -158,7 +162,7 @@ FFmpegDecoder::pass ()
                        av_strerror (r, buf, sizeof(buf));
                        shared_ptr<const Film> film = _film.lock ();
                        assert (film);
-                       film->log()->log (String::compose (N_("error on av_read_frame (%1) (%2)"), buf, r));
+                       LOG_ERROR (N_("error on av_read_frame (%1) (%2)"), buf, r);
                }
 
                flush ();
@@ -400,7 +404,7 @@ FFmpegDecoder::decode_audio_packet ()
                if (decode_result < 0) {
                        shared_ptr<const Film> film = _film.lock ();
                        assert (film);
-                       film->log()->log (String::compose ("avcodec_decode_audio4 failed (%1)", decode_result));
+                       LOG_ERROR ("avcodec_decode_audio4 failed (%1)", decode_result);
                        return;
                }
 
@@ -461,13 +465,16 @@ FFmpegDecoder::decode_video_packet ()
                graph.reset (new FilterGraph (_ffmpeg_content, libdcp::Size (_frame->width, _frame->height), (AVPixelFormat) _frame->format));
                _filter_graphs.push_back (graph);
 
-               film->log()->log (String::compose (N_("New graph for %1x%2, pixel format %3"), _frame->width, _frame->height, _frame->format));
+               LOG_GENERAL (N_("New graph for %1x%2, pixel format %3"), _frame->width, _frame->height, _frame->format);
        } else {
                graph = *i;
        }
 
        list<pair<shared_ptr<Image>, int64_t> > images = graph->process (_frame);
 
+       shared_ptr<const Film> film = _film.lock ();
+       assert (film);
+
        for (list<pair<shared_ptr<Image>, int64_t> >::iterator i = images.begin(); i != images.end(); ++i) {
 
                shared_ptr<Image> image = i->first;
@@ -502,20 +509,21 @@ FFmpegDecoder::decode_video_packet ()
                                                )
                                        );
                                
+                               shared_ptr<const Film> film = _film.lock ();
+                               assert (film);
+
                                black->make_black ();
-                               video (shared_ptr<ImageProxy> (new RawImageProxy (image)), false, _video_position);
+                               video (shared_ptr<ImageProxy> (new RawImageProxy (image, film->log())), false, _video_position);
                                delta -= one_frame;
                        }
 
                        if (delta > -one_frame) {
                                /* This PTS is within a frame of being right; emit this (otherwise it will be dropped) */
-                               video (shared_ptr<ImageProxy> (new RawImageProxy (image)), false, _video_position);
+                               video (shared_ptr<ImageProxy> (new RawImageProxy (image, film->log())), false, _video_position);
                        }
                                
                } else {
-                       shared_ptr<const Film> film = _film.lock ();
-                       assert (film);
-                       film->log()->log ("Dropping frame without PTS");
+                       LOG_WARNING ("Dropping frame without PTS");
                }
        }
 
index 12a57753f4aa5a03806cbc20ce3cad2f14080754..206400da2fce8cc223cf9d82bb3346af5911de3b 100644 (file)
@@ -81,6 +81,9 @@ using libdcp::Size;
 using libdcp::Signer;
 using libdcp::raw_convert;
 
+#define LOG_GENERAL(...) log()->log (String::compose (__VA_ARGS__), Log::GENERAL);
+#define LOG_GENERAL_NC(...) log()->log (__VA_ARGS__, Log::GENERAL);
+
 /* 5 -> 6
  * AudioMapping XML changed.
  * 6 -> 7
@@ -253,43 +256,43 @@ Film::make_dcp ()
         */
        write_metadata ();
 
-       log()->log (String::compose ("DCP-o-matic %1 git %2 using %3", dcpomatic_version, dcpomatic_git_commit, dependency_version_summary()));
+       LOG_GENERAL ("DCP-o-matic %1 git %2 using %3", dcpomatic_version, dcpomatic_git_commit, dependency_version_summary());
 
        {
                char buffer[128];
                gethostname (buffer, sizeof (buffer));
-               log()->log (String::compose ("Starting to make DCP on %1", buffer));
+               LOG_GENERAL ("Starting to make DCP on %1", buffer);
        }
 
        ContentList cl = content ();
        for (ContentList::const_iterator i = cl.begin(); i != cl.end(); ++i) {
-               log()->log (String::compose ("Content: %1", (*i)->technical_summary()));
+               LOG_GENERAL ("Content: %1", (*i)->technical_summary());
        }
-       log()->log (String::compose ("DCP video rate %1 fps", video_frame_rate()));
-       log()->log (String::compose ("%1 threads", Config::instance()->num_local_encoding_threads()));
-       log()->log (String::compose ("J2K bandwidth %1", j2k_bandwidth()));
+       LOG_GENERAL ("DCP video rate %1 fps", video_frame_rate());
+       LOG_GENERAL ("%1 threads", Config::instance()->num_local_encoding_threads());
+       LOG_GENERAL ("J2K bandwidth %1", j2k_bandwidth());
 #ifdef DCPOMATIC_DEBUG
-       log()->log ("DCP-o-matic built in debug mode.");
+       LOG_GENERAL_NC ("DCP-o-matic built in debug mode.");
 #else
-       log()->log ("DCP-o-matic built in optimised mode.");
+       LOG_GENERAL_NC ("DCP-o-matic built in optimised mode.");
 #endif
 #ifdef LIBDCP_DEBUG
-       log()->log ("libdcp built in debug mode.");
+       LOG_GENERAL_NC ("libdcp built in debug mode.");
 #else
-       log()->log ("libdcp built in optimised mode.");
+       LOG_GENERAL_NC ("libdcp built in optimised mode.");
 #endif
 
 #ifdef DCPOMATIC_WINDOWS
        OSVERSIONINFO info;
        info.dwOSVersionInfoSize = sizeof (info);
        GetVersionEx (&info);
-       log()->log (String::compose ("Windows version %1.%2.%3 SP %4", info.dwMajorVersion, info.dwMinorVersion, info.dwBuildNumber, info.szCSDVersion));
+       LOG_GENERAL ("Windows version %1.%2.%3 SP %4", info.dwMajorVersion, info.dwMinorVersion, info.dwBuildNumber, info.szCSDVersion);
 #endif 
        
-       log()->log (String::compose ("CPU: %1, %2 processors", cpu_info(), boost::thread::hardware_concurrency ()));
+       LOG_GENERAL ("CPU: %1, %2 processors", cpu_info(), boost::thread::hardware_concurrency ());
        list<pair<string, string> > const m = mount_info ();
        for (list<pair<string, string> >::const_iterator i = m.begin(); i != m.end(); ++i) {
-               log()->log (String::compose ("Mount: %1 %2", i->first, i->second));
+               LOG_GENERAL ("Mount: %1 %2", i->first, i->second);
        }
        
        if (container() == 0) {
index d33b64cd446086a96c092bf9c9e64e6b8292ee7a..7a9acd9e4960e611bda76e912e4837738e94dc59 100644 (file)
@@ -53,7 +53,10 @@ ImageDecoder::pass ()
                return;
        }
 
-       _image.reset (new MagickImageProxy (_image_content->path (_image_content->still() ? 0 : _video_position)));
+       shared_ptr<const Film> film = _film.lock ();
+       assert (film);
+
+       _image.reset (new MagickImageProxy (_image_content->path (_image_content->still() ? 0 : _video_position), film->log ()));
        video (_image, false, _video_position);
 }
 
index 0806b4ccc132e1b6ec44526170189a221492d645..c0e75c77c6343dd943e2399db5f0624a0561ccb8 100644 (file)
 #include "image.h"
 #include "exceptions.h"
 #include "cross.h"
+#include "log.h"
 
 #include "i18n.h"
 
+#define LOG_TIMING(...) _log->microsecond_log (String::compose (__VA_ARGS__), Log::TIMING);
+
 using std::cout;
 using std::string;
 using std::stringstream;
 using boost::shared_ptr;
 
-RawImageProxy::RawImageProxy (shared_ptr<Image> image)
-       : _image (image)
+ImageProxy::ImageProxy (shared_ptr<Log> log)
+       : _log (log)
+{
+
+}
+
+RawImageProxy::RawImageProxy (shared_ptr<Image> image, shared_ptr<Log> log)
+       : ImageProxy (log)
+       , _image (image)
 {
 
 }
 
-RawImageProxy::RawImageProxy (shared_ptr<cxml::Node> xml, shared_ptr<Socket> socket)
+RawImageProxy::RawImageProxy (shared_ptr<cxml::Node> xml, shared_ptr<Socket> socket, shared_ptr<Log> log)
+       : ImageProxy (log)
 {
        libdcp::Size size (
                xml->number_child<int> ("Width"), xml->number_child<int> ("Height")
@@ -68,7 +79,8 @@ RawImageProxy::send_binary (shared_ptr<Socket> socket) const
        _image->write_to_socket (socket);
 }
 
-MagickImageProxy::MagickImageProxy (boost::filesystem::path path)
+MagickImageProxy::MagickImageProxy (boost::filesystem::path path, shared_ptr<Log> log)
+       : ImageProxy (log)
 {
        /* Read the file into a Blob */
        
@@ -89,7 +101,8 @@ MagickImageProxy::MagickImageProxy (boost::filesystem::path path)
        delete[] data;
 }
 
-MagickImageProxy::MagickImageProxy (shared_ptr<cxml::Node>, shared_ptr<Socket> socket)
+MagickImageProxy::MagickImageProxy (shared_ptr<cxml::Node>, shared_ptr<Socket> socket, shared_ptr<Log> log)
+       : ImageProxy (log)
 {
        uint32_t const size = socket->read_uint32 ();
        uint8_t* data = new uint8_t[size];
@@ -105,7 +118,7 @@ MagickImageProxy::image () const
                return _image;
        }
 
-       TIMING("MagickImageProxy begins read and decode of %1 bytes", _blob.length());
+       LOG_TIMING ("MagickImageProxy begins read and decode of %1 bytes", _blob.length());
 
        Magick::Image* magick_image = 0;
        try {
@@ -134,7 +147,7 @@ MagickImageProxy::image () const
 
        delete magick_image;
 
-       TIMING("MagickImageProxy completes read and decode of %1 bytes", _blob.length());
+       LOG_TIMING ("MagickImageProxy completes read and decode of %1 bytes", _blob.length());
 
        return _image;
 }
@@ -153,12 +166,12 @@ MagickImageProxy::send_binary (shared_ptr<Socket> socket) const
 }
 
 shared_ptr<ImageProxy>
-image_proxy_factory (shared_ptr<cxml::Node> xml, shared_ptr<Socket> socket)
+image_proxy_factory (shared_ptr<cxml::Node> xml, shared_ptr<Socket> socket, shared_ptr<Log> log)
 {
        if (xml->string_child("Type") == N_("Raw")) {
-               return shared_ptr<ImageProxy> (new RawImageProxy (xml, socket));
+               return shared_ptr<ImageProxy> (new RawImageProxy (xml, socket, log));
        } else if (xml->string_child("Type") == N_("Magick")) {
-               return shared_ptr<MagickImageProxy> (new MagickImageProxy (xml, socket));
+               return shared_ptr<MagickImageProxy> (new MagickImageProxy (xml, socket, log));
        }
 
        throw NetworkError (_("Unexpected image type received by server"));
index 792fa004aea931e3d3a4041822571a4c89ec3633..fcbda7dd1f6695f5c29c6f0623eb619991e5eeb5 100644 (file)
@@ -28,6 +28,7 @@
 
 class Image;
 class Socket;
+class Log;
 
 namespace cxml {
        class Node;
@@ -47,16 +48,21 @@ namespace cxml {
 class ImageProxy
 {
 public:
+       ImageProxy (boost::shared_ptr<Log> log);
+       
        virtual boost::shared_ptr<Image> image () const = 0;
        virtual void add_metadata (xmlpp::Node *) const = 0;
        virtual void send_binary (boost::shared_ptr<Socket>) const = 0;
+
+protected:
+       boost::shared_ptr<Log> _log;
 };
 
 class RawImageProxy : public ImageProxy
 {
 public:
-       RawImageProxy (boost::shared_ptr<Image>);
-       RawImageProxy (boost::shared_ptr<cxml::Node> xml, boost::shared_ptr<Socket> socket);
+       RawImageProxy (boost::shared_ptr<Image>, boost::shared_ptr<Log> log);
+       RawImageProxy (boost::shared_ptr<cxml::Node> xml, boost::shared_ptr<Socket> socket, boost::shared_ptr<Log> log);
 
        boost::shared_ptr<Image> image () const;
        void add_metadata (xmlpp::Node *) const;
@@ -69,8 +75,8 @@ private:
 class MagickImageProxy : public ImageProxy
 {
 public:
-       MagickImageProxy (boost::filesystem::path);
-       MagickImageProxy (boost::shared_ptr<cxml::Node> xml, boost::shared_ptr<Socket> socket);
+       MagickImageProxy (boost::filesystem::path, boost::shared_ptr<Log> log);
+       MagickImageProxy (boost::shared_ptr<cxml::Node> xml, boost::shared_ptr<Socket> socket, boost::shared_ptr<Log> log);
 
        boost::shared_ptr<Image> image () const;
        void add_metadata (xmlpp::Node *) const;
@@ -81,4 +87,4 @@ private:
        mutable boost::shared_ptr<Image> _image;
 };
 
-boost::shared_ptr<ImageProxy> image_proxy_factory (boost::shared_ptr<cxml::Node> xml, boost::shared_ptr<Socket> socket);
+boost::shared_ptr<ImageProxy> image_proxy_factory (boost::shared_ptr<cxml::Node> xml, boost::shared_ptr<Socket> socket, boost::shared_ptr<Log> log);
index a0b031589bf1836080c98c170c2fde1860df8dfe..be32315d108a5bad7c84d49dd8c5a858f452fa39 100644 (file)
 
 #include <time.h>
 #include <cstdio>
+#include <boost/algorithm/string.hpp>
 #include "log.h"
 #include "cross.h"
+#include "config.h"
 
 #include "i18n.h"
 
 using namespace std;
+using boost::algorithm::is_any_of;
+using boost::algorithm::split;
+
+int const Log::GENERAL = 0x1;
+int const Log::WARNING = 0x2;
+int const Log::ERROR   = 0x4;
+int const Log::TIMING  = 0x8;
 
 Log::Log ()
-       : _level (STANDARD)
+       : _types (0)
 {
+       Config::instance()->Changed.connect (boost::bind (&Log::config_changed, this));
+       config_changed ();
+}
 
+void
+Log::config_changed ()
+{
+       set_types (Config::instance()->log_types ());
 }
 
 /** @param n String to log */
 void
-Log::log (string m, Level l)
+Log::log (string message, int type)
 {
        boost::mutex::scoped_lock lm (_mutex);
 
-       if (l > _level) {
+       if ((_types & type) == 0) {
                return;
        }
 
@@ -51,16 +67,26 @@ Log::log (string m, Level l)
        string a = ctime (&t);
 
        stringstream s;
-       s << a.substr (0, a.length() - 1) << N_(": ") << m;
+       s << a.substr (0, a.length() - 1) << N_(": ");
+
+       if (type & ERROR) {
+               s << "ERROR: ";
+       }
+
+       if (type & WARNING) {
+               s << "WARNING: ";
+       }
+       
+       s << message;
        do_log (s.str ());
 }
 
 void
-Log::microsecond_log (string m, Level l)
+Log::microsecond_log (string m, int t)
 {
        boost::mutex::scoped_lock lm (_mutex);
 
-       if (l > _level) {
+       if ((_types & t) == 0) {
                return;
        }
 
@@ -73,24 +99,34 @@ Log::microsecond_log (string m, Level l)
 }      
 
 void
-Log::set_level (Level l)
+Log::set_types (int t)
 {
        boost::mutex::scoped_lock lm (_mutex);
-       _level = l;
+       _types = t;
 }
 
+/** @param A comma-separate list of debug types to enable */
 void
-Log::set_level (string l)
+Log::set_types (string t)
 {
-       if (l == N_("verbose")) {
-               set_level (VERBOSE);
-               return;
-       } else if (l == N_("timing")) {
-               set_level (TIMING);
-               return;
-       }
+       boost::mutex::scoped_lock lm (_mutex);
 
-       set_level (STANDARD);
+       vector<string> types;
+       split (types, t, is_any_of (","));
+
+       _types = 0;
+
+       for (vector<string>::const_iterator i = types.begin(); i != types.end(); ++i) {
+               if (*i == N_("general")) {
+                       _types |= GENERAL;
+               } else if (*i == N_("warning")) {
+                       _types |= WARNING;
+               } else if (*i == N_("error")) {
+                       _types |= ERROR;
+               } else if (*i == N_("timing")) {
+                       _types |= TIMING;
+               }
+       }
 }
 
 /** @param file Filename to write log to */
index 991532404293a7a01fc59762b3b1b8b0d15af6ec..641ce186d40cf72fdfaf8f75e571ea470e7c5d90 100644 (file)
@@ -37,17 +37,16 @@ public:
        Log ();
        virtual ~Log () {}
 
-       enum Level {
-               STANDARD = 0,
-               VERBOSE = 1,
-               TIMING = 2
-       };
+       static const int GENERAL;
+       static const int WARNING;
+       static const int ERROR;
+       static const int TIMING;
 
-       void log (std::string m, Level l = STANDARD);
-       void microsecond_log (std::string m, Level l = STANDARD);
+       void log (std::string message, int type);
+       void microsecond_log (std::string message, int type);
 
-       void set_level (Level l);
-       void set_level (std::string l);
+       void set_types (int types);
+       void set_types (std::string types);
 
 protected:     
        /** mutex to protect the log */
@@ -55,9 +54,10 @@ protected:
        
 private:
        virtual void do_log (std::string m) = 0;
+       void config_changed ();
        
-       /** level above which to ignore log messages */
-       Level _level;
+       /** bit-field of log types which should be put into the log (others are ignored) */
+       int _types;
 };
 
 class FileLog : public Log
index 9f0f380e377c253eb1944e6d268fd7183155450b..a90350922edcd88af9b06a87a0572232fe33dee7 100644 (file)
@@ -37,6 +37,8 @@
 #include "scaler.h"
 #include "player_video_frame.h"
 
+#define LOG_GENERAL(...) _film->log()->log (String::compose (__VA_ARGS__), Log::GENERAL);
+
 using std::list;
 using std::cout;
 using std::min;
@@ -526,7 +528,7 @@ Player::set_video_container_size (libdcp::Size s)
        
        _black_frame.reset (
                new PlayerVideoFrame (
-                       shared_ptr<ImageProxy> (new RawImageProxy (im)),
+                       shared_ptr<ImageProxy> (new RawImageProxy (im, _film->log ())),
                        Crop(),
                        _video_container_size,
                        _video_container_size,
@@ -550,10 +552,8 @@ Player::resampler (shared_ptr<AudioContent> c, bool create)
                return shared_ptr<Resampler> ();
        }
 
-       _film->log()->log (
-               String::compose (
-                       "Creating new resampler for %1 to %2 with %3 channels", c->content_audio_frame_rate(), c->output_audio_frame_rate(), c->audio_channels()
-                       )
+       LOG_GENERAL (
+               "Creating new resampler for %1 to %2 with %3 channels", c->content_audio_frame_rate(), c->output_audio_frame_rate(), c->audio_channels()
                );
        
        shared_ptr<Resampler> r (new Resampler (c->content_audio_frame_rate(), c->output_audio_frame_rate(), c->audio_channels()));
index c96ed3a33d9e14753dcccdbd55aa2a3dfd87a230..94760e495ce95b5ce0c284b5c5d2f8a4492e24c5 100644 (file)
@@ -50,7 +50,7 @@ PlayerVideoFrame::PlayerVideoFrame (
 
 }
 
-PlayerVideoFrame::PlayerVideoFrame (shared_ptr<cxml::Node> node, shared_ptr<Socket> socket)
+PlayerVideoFrame::PlayerVideoFrame (shared_ptr<cxml::Node> node, shared_ptr<Socket> socket, shared_ptr<Log> log)
 {
        _crop = Crop (node);
 
@@ -61,7 +61,7 @@ PlayerVideoFrame::PlayerVideoFrame (shared_ptr<cxml::Node> node, shared_ptr<Sock
        _part = (Part) node->number_child<int> ("Part");
        _colour_conversion = ColourConversion (node);
 
-       _in = image_proxy_factory (node->node_child ("In"), socket);
+       _in = image_proxy_factory (node->node_child ("In"), socket, log);
 
        if (node->optional_number_child<int> ("SubtitleX")) {
                
index 6461134a9c60649cb106292c1633d4fd36ec3c1d..b085cb609e659f59b55f6a709c88b046c2a6a078 100644 (file)
@@ -26,6 +26,7 @@ class Image;
 class ImageProxy;
 class Scaler;
 class Socket;
+class Log;
 
 /** Everything needed to describe a video frame coming out of the player, but with the
  *  bits still their raw form.  We may want to combine the bits on a remote machine,
@@ -35,7 +36,7 @@ class PlayerVideoFrame
 {
 public:
        PlayerVideoFrame (boost::shared_ptr<const ImageProxy>, Crop, libdcp::Size, libdcp::Size, Scaler const *, Eyes, Part, ColourConversion);
-       PlayerVideoFrame (boost::shared_ptr<cxml::Node>, boost::shared_ptr<Socket>);
+       PlayerVideoFrame (boost::shared_ptr<cxml::Node>, boost::shared_ptr<Socket>, boost::shared_ptr<Log>);
 
        void set_subtitle (boost::shared_ptr<const Image>, Position<int>);
        
index 0b713b0427b15c62cdda2e39455c0a5e3dab1bc3..30bfc3441ae80c72aad9de4d330a4dfd4a76028a 100644 (file)
@@ -37,6 +37,8 @@
 
 #include "i18n.h"
 
+#define LOG_GENERAL_NC(...) _film->log()->microsecond_log (__VA_ARGS__, Log::GENERAL);
+
 using std::string;
 using std::stringstream;
 using std::min;
@@ -119,7 +121,7 @@ SCPDCPJob::json_name () const
 void
 SCPDCPJob::run ()
 {
-       _film->log()->log (N_("SCP DCP job starting"));
+       LOG_GENERAL_NC (N_("SCP DCP job starting"));
        
        SSHSession ss;
        
index b9bb825ee051f4694d6a61be522d5a8a851a4b86..c4c98a4c9f0ea6da1106e1c3f3b46dad959883c4 100644 (file)
 
 #include "i18n.h"
 
+#define LOG_GENERAL(...) _log->microsecond_log (String::compose (__VA_ARGS__), Log::GENERAL);
+#define LOG_GENERAL_NC(...) _log->microsecond_log (__VA_ARGS__, Log::GENERAL);
+#define LOG_ERROR(...) _log->microsecond_log (String::compose (__VA_ARGS__), Log::ERROR);
+#define LOG_ERROR_NC(...) _log->microsecond_log (__VA_ARGS__, Log::ERROR);
+
 using std::string;
 using std::stringstream;
 using std::multimap;
@@ -82,11 +87,11 @@ Server::process (shared_ptr<Socket> socket, struct timeval& after_read, struct t
        xml->read_stream (s);
        if (xml->number_child<int> ("Version") != SERVER_LINK_VERSION) {
                cerr << "Mismatched server/client versions\n";
-               _log->log ("Mismatched server/client versions");
+               LOG_ERROR_NC ("Mismatched server/client versions");
                return -1;
        }
 
-       shared_ptr<PlayerVideoFrame> pvf (new PlayerVideoFrame (xml, socket));
+       shared_ptr<PlayerVideoFrame> pvf (new PlayerVideoFrame (xml, socket, _log));
 
        DCPVideoFrame dcp_video_frame (pvf, xml, _log);
 
@@ -99,7 +104,7 @@ Server::process (shared_ptr<Socket> socket, struct timeval& after_read, struct t
        try {
                encoded->send (socket);
        } catch (std::exception& e) {
-               _log->log (String::compose ("Send failed; frame %1", dcp_video_frame.index()));
+               LOG_ERROR ("Send failed; frame %1", dcp_video_frame.index());
                throw;
        }
 
@@ -134,7 +139,7 @@ Server::worker_thread ()
                        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()));
+                       LOG_ERROR ("Error: %1", e.what());
                }
 
                gettimeofday (&end, 0);
@@ -159,7 +164,7 @@ Server::worker_thread ()
                                cout << message.str() << "\n";
                        }
 
-                       _log->log (message.str ());
+                       LOG_GENERAL_NC (message.str ());
                }
                
                _worker_condition.notify_all ();
@@ -169,7 +174,7 @@ Server::worker_thread ()
 void
 Server::run (int num_threads)
 {
-       _log->log (String::compose ("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";
        }
index 7b304cb35b48d549e683bd403ec8b5d923b0e4e9..fb9a5917956109a8bbe1dcfd57df7d93fa322890 100644 (file)
@@ -30,6 +30,9 @@
 
 #include "i18n.h"
 
+#define LOG_GENERAL_NC(...) _film->log()->microsecond_log (__VA_ARGS__, Log::GENERAL);
+#define LOG_ERROR_NC(...) _film->log()->microsecond_log (__VA_ARGS__, Log::ERROR);
+
 using std::string;
 using std::stringstream;
 using std::fixed;
@@ -61,20 +64,20 @@ TranscodeJob::run ()
 {
        try {
 
-               _film->log()->log (N_("Transcode job starting"));
+               LOG_GENERAL_NC (N_("Transcode job starting"));
 
                _transcoder.reset (new Transcoder (_film, shared_from_this ()));
                _transcoder->go ();
                set_progress (1);
                set_state (FINISHED_OK);
 
-               _film->log()->log (N_("Transcode job completed successfully"));
+               LOG_GENERAL_NC (N_("Transcode job completed successfully"));
                _transcoder.reset ();
 
        } catch (...) {
                set_progress (1);
                set_state (FINISHED_ERROR);
-               _film->log()->log (N_("Transcode job failed or cancelled"));
+               LOG_ERROR_NC (N_("Transcode job failed or cancelled"));
                _transcoder.reset ();
                throw;
        }
index e85abf402d8ec1637570222a923c7708c6242601..5ca9f74c88d68a878a54f5e5b75a7af0628caa22 100644 (file)
@@ -40,12 +40,6 @@ extern "C" {
 #include "types.h"
 #include "video_content.h"
 
-#ifdef DCPOMATIC_DEBUG
-#define TIMING(...) _film->log()->microsecond_log (String::compose (__VA_ARGS__), Log::TIMING);
-#else
-#define TIMING(...)
-#endif
-
 #undef check
 
 /** The maximum number of audio channels that we can have in a DCP */
index 6396851492be8fc2322b13b7d43387bfc81adf2e..b058c2801160d301142e00509159aa7a243b57a1 100644 (file)
 
 #include "i18n.h"
 
+#define LOG_GENERAL(...) _film->log()->log (String::compose (__VA_ARGS__), Log::GENERAL);
+#define LOG_TIMING(...) _film->log()->microsecond_log (String::compose (__VA_ARGS__), Log::TIMING);
+#define LOG_WARNING_NC(...) _film->log()->log (__VA_ARGS__, Log::WARNING);
+
 /* OS X strikes again */
 #undef set_key
 
@@ -239,9 +243,9 @@ try
                                break;
                        }
 
-                       TIMING (N_("writer sleeps with a queue of %1"), _queue.size());
+                       LOG_TIMING (N_("writer sleeps with a queue of %1"), _queue.size());
                        _empty_condition.wait (lock);
-                       TIMING (N_("writer wakes with a queue of %1"), _queue.size());
+                       LOG_TIMING (N_("writer wakes with a queue of %1"), _queue.size());
                }
 
                if (_finish && _queue.empty()) {
@@ -260,7 +264,7 @@ try
                        switch (qi.type) {
                        case QueueItem::FULL:
                        {
-                               _film->log()->log (String::compose (N_("Writer FULL-writes %1 to MXF"), qi.frame));
+                               LOG_GENERAL (N_("Writer FULL-writes %1 to MXF"), qi.frame);
                                if (!qi.encoded) {
                                        qi.encoded.reset (new EncodedData (_film->j2c_path (qi.frame, qi.eyes, false)));
                                }
@@ -272,14 +276,14 @@ try
                                break;
                        }
                        case QueueItem::FAKE:
-                               _film->log()->log (String::compose (N_("Writer FAKE-writes %1 to MXF"), qi.frame));
+                               LOG_GENERAL (N_("Writer FAKE-writes %1 to MXF"), qi.frame);
                                _picture_asset_writer->fake_write (qi.size);
                                _last_written[qi.eyes].reset ();
                                ++_fake_written;
                                break;
                        case QueueItem::REPEAT:
                        {
-                               _film->log()->log (String::compose (N_("Writer REPEAT-writes %1 to MXF"), qi.frame));
+                               LOG_GENERAL (N_("Writer REPEAT-writes %1 to MXF"), qi.frame);
                                libdcp::FrameInfo fin = _picture_asset_writer->write (
                                        _last_written[qi.eyes]->data(),
                                        _last_written[qi.eyes]->size()
@@ -328,11 +332,10 @@ try
                        
                        lock.unlock ();
 
-                       _film->log()->log (
-                               String::compose (
-                                       "Writer full (awaiting %1 [last eye was %2]); pushes %3 to disk",
-                                       _last_written_frame + 1,
-                                       _last_written_eyes, qi.frame)
+                       LOG_GENERAL (
+                               "Writer full (awaiting %1 [last eye was %2]); pushes %3 to disk",
+                               _last_written_frame + 1,
+                               _last_written_eyes, qi.frame
                                );
                        
                        qi.encoded->write (_film, qi.frame, qi.eyes);
@@ -403,7 +406,7 @@ Writer::finish ()
        if (ec) {
                /* hard link failed; copy instead */
                boost::filesystem::copy_file (video_from, video_to);
-               _film->log()->log ("Hard-link failed; fell back to copying");
+               LOG_WARNING_NC ("Hard-link failed; fell back to copying");
        }
 
        /* And update the asset */
@@ -465,8 +468,8 @@ Writer::finish ()
        meta.set_issue_date_now ();
        dcp.write_xml (_film->interop (), meta, _film->is_signed() ? make_signer () : shared_ptr<const libdcp::Signer> ());
 
-       _film->log()->log (
-               String::compose (N_("Wrote %1 FULL, %2 FAKE, %3 REPEAT; %4 pushed to disk"), _full_written, _fake_written, _repeat_written, _pushed_to_disk)
+       LOG_GENERAL (
+               N_("Wrote %1 FULL, %2 FAKE, %3 REPEAT; %4 pushed to disk"), _full_written, _fake_written, _repeat_written, _pushed_to_disk
                );
 }
 
@@ -502,14 +505,14 @@ Writer::check_existing_picture_mxf_frame (FILE* mxf, int f, Eyes eyes)
        /* Read the frame info as written */
        FILE* ifi = fopen_boost (_film->info_path (f, eyes), "r");
        if (!ifi) {
-               _film->log()->log (String::compose ("Existing frame %1 has no info file", f));
+               LOG_GENERAL ("Existing frame %1 has no info file", f);
                return false;
        }
        
        libdcp::FrameInfo info (ifi);
        fclose (ifi);
        if (info.size == 0) {
-               _film->log()->log (String::compose ("Existing frame %1 has no info file", f));
+               LOG_GENERAL ("Existing frame %1 has no info file", f);
                return false;
        }
        
@@ -518,13 +521,13 @@ Writer::check_existing_picture_mxf_frame (FILE* mxf, int f, Eyes eyes)
        EncodedData data (info.size);
        size_t const read = fread (data.data(), 1, data.size(), mxf);
        if (read != static_cast<size_t> (data.size ())) {
-               _film->log()->log (String::compose ("Existing frame %1 is incomplete", f));
+               LOG_GENERAL ("Existing frame %1 is incomplete", f);
                return false;
        }
        
        string const existing_hash = md5_digest (data.data(), data.size());
        if (existing_hash != info.hash) {
-               _film->log()->log (String::compose ("Existing frame %1 failed hash check", f));
+               LOG_GENERAL ("Existing frame %1 failed hash check", f);
                return false;
        }
 
@@ -540,7 +543,7 @@ Writer::check_existing_picture_mxf ()
        p /= _film->internal_video_mxf_filename ();
        FILE* mxf = fopen_boost (p, "rb");
        if (!mxf) {
-               _film->log()->log (String::compose ("Could not open existing MXF at %1 (errno=%2)", p.string(), errno));
+               LOG_GENERAL ("Could not open existing MXF at %1 (errno=%2)", p.string(), errno);
                return;
        }
 
@@ -571,7 +574,7 @@ Writer::check_existing_picture_mxf ()
                        }
                }
 
-               _film->log()->log (String::compose ("Have existing frame %1", _first_nonexistant_frame));
+               LOG_GENERAL ("Have existing frame %1", _first_nonexistant_frame);
                ++_first_nonexistant_frame;
        }
 
index 28074a4ba39e8703d493665f24159cefb88a589f..d092992a17a31c640141c3791c9ba3c33bc719d7 100644 (file)
@@ -74,7 +74,7 @@ using boost::dynamic_pointer_cast;
 static FilmEditor* film_editor = 0;
 static FilmViewer* film_viewer = 0;
 static shared_ptr<Film> film;
-static std::string log_level;
+static std::string log_types = "general,log,warning";
 static std::string film_to_load;
 static std::string film_to_create;
 static std::string content_to_add;
@@ -157,7 +157,7 @@ load_film (boost::filesystem::path file)
        for (list<string>::const_iterator i = notes.begin(); i != notes.end(); ++i) {
                error_dialog (0, std_to_wx (*i));
        }
-       film->log()->set_level (log_level);
+       film->log()->set_types (log_types);
 }
 
 #define ALWAYS                  0x0
@@ -401,7 +401,7 @@ private:
                        maybe_save_then_delete_film ();
                        film.reset (new Film (d->get_path ()));
                        film->write_metadata ();
-                       film->log()->set_level (log_level);
+                       film->log()->set_types (log_types);
                        film->set_name (boost::filesystem::path (d->get_path()).filename().generic_string());
                        set_film ();
                }
@@ -609,7 +609,7 @@ private:
 };
 
 static const wxCmdLineEntryDesc command_line_description[] = {
-       { wxCMD_LINE_OPTION, "l", "log", "set log level (silent, verbose or timing)", wxCMD_LINE_VAL_STRING, wxCMD_LINE_PARAM_OPTIONAL },
+       { wxCMD_LINE_OPTION, "l", "log", "set message types to log (general,warning,error,timing)", wxCMD_LINE_VAL_STRING, wxCMD_LINE_PARAM_OPTIONAL },
        { wxCMD_LINE_SWITCH, "n", "new", "create new film", wxCMD_LINE_VAL_NONE, wxCMD_LINE_PARAM_OPTIONAL },
        { wxCMD_LINE_OPTION, "c", "content", "add content file", wxCMD_LINE_VAL_STRING, wxCMD_LINE_PARAM_OPTIONAL },
        { wxCMD_LINE_PARAM, 0, 0, "film to load or create", wxCMD_LINE_VAL_STRING, wxCMD_LINE_PARAM_OPTIONAL },
@@ -668,7 +668,7 @@ class App : public wxApp
                if (!film_to_create.empty ()) {
                        film.reset (new Film (film_to_create));
                        film->write_metadata ();
-                       film->log()->set_level (log_level);
+                       film->log()->set_types (log_types);
                        film->set_name (boost::filesystem::path (film_to_create).filename().generic_string ());
                }
 
@@ -728,7 +728,7 @@ class App : public wxApp
 
                wxString log;
                if (parser.Found (wxT ("log"), &log)) {
-                       log_level = wx_to_std (log);
+                       log_types = wx_to_std (log);
                }
 
                return true;
index a74ece149af2b9e96e7cd46103917dec5bfe98f1..73067f406d559996ee3255157b1315edde14b039 100644 (file)
@@ -65,7 +65,7 @@ main (int argc, char* argv[])
        string film_dir;
        bool progress = true;
        bool no_remote = false;
-       int log_level = 0;
+       string log_types = "general,warning,error";
        int json_port = 0;
        bool keep_going = false;
 
@@ -78,7 +78,7 @@ main (int argc, char* argv[])
                        { "flags", no_argument, 0, 'f'},
                        { "no-progress", no_argument, 0, 'n'},
                        { "no-remote", no_argument, 0, 'r'},
-                       { "log-level", required_argument, 0, 'l' },
+                       { "log-types", required_argument, 0, 'l' },
                        { "json", required_argument, 0, 'j' },
                        { "keep-going", no_argument, 0, 'k' },
                        { 0, 0, 0, 0 }
@@ -110,7 +110,7 @@ main (int argc, char* argv[])
                        no_remote = true;
                        break;
                case 'l':
-                       log_level = atoi (optarg);
+                       log_types = optarg;
                        break;
                case 'j':
                        json_port = atoi (optarg);
@@ -155,7 +155,7 @@ main (int argc, char* argv[])
                exit (EXIT_FAILURE);
        }
 
-       film->log()->set_level ((Log::Level) log_level);
+       film->log()->set_types (log_types);
 
        cout << "\nMaking DCP for " << film->name() << "\n";
 //     cout << "Content: " << film->content() << "\n";
index e27b79172ea0ab8d9ca7dde851b4ae251b3feb83..109ff9f87b065a734e6eaf4014589580932034ba 100644 (file)
@@ -106,14 +106,6 @@ public:
                _num_local_encoding_threads = new wxSpinCtrl (panel);
                table->Add (_num_local_encoding_threads, 1);
 
-               add_label_to_sizer (table, panel, _("Maximum JPEG2000 bandwidth"), true);
-               _maximum_j2k_bandwidth = new wxSpinCtrl (panel);
-               table->Add (_maximum_j2k_bandwidth, 1);
-
-               _allow_any_dcp_frame_rate = new wxCheckBox (panel, wxID_ANY, _("Allow any DCP frame rate"));
-               table->Add (_allow_any_dcp_frame_rate, 1, wxEXPAND | wxALL);
-               table->AddSpacer (0);
-               
                add_label_to_sizer (table, panel, _("Outgoing mail server"), true);
                _mail_server = new wxTextCtrl (panel, wxID_ANY);
                table->Add (_mail_server, 1, wxEXPAND | wxALL);
@@ -171,10 +163,6 @@ public:
                _num_local_encoding_threads->SetValue (config->num_local_encoding_threads ());
                _num_local_encoding_threads->Bind (wxEVT_COMMAND_SPINCTRL_UPDATED, boost::bind (&GeneralPage::num_local_encoding_threads_changed, this));
 
-               _maximum_j2k_bandwidth->SetRange (1, 500);
-               _maximum_j2k_bandwidth->SetValue (config->maximum_j2k_bandwidth() / 1000000);
-               _maximum_j2k_bandwidth->Bind (wxEVT_COMMAND_SPINCTRL_UPDATED, boost::bind (&GeneralPage::maximum_j2k_bandwidth_changed, this));
-               
                _mail_server->SetValue (std_to_wx (config->mail_server ()));
                _mail_server->Bind (wxEVT_COMMAND_TEXT_UPDATED, boost::bind (&GeneralPage::mail_server_changed, this));
                _mail_user->SetValue (std_to_wx (config->mail_user ()));
@@ -187,8 +175,6 @@ public:
                _check_for_updates->Bind (wxEVT_COMMAND_CHECKBOX_CLICKED, boost::bind (&GeneralPage::check_for_updates_changed, this));
                _check_for_test_updates->SetValue (config->check_for_test_updates ());
                _check_for_test_updates->Bind (wxEVT_COMMAND_CHECKBOX_CLICKED, boost::bind (&GeneralPage::check_for_test_updates_changed, this));
-               _allow_any_dcp_frame_rate->SetValue (config->allow_any_dcp_frame_rate ());
-               _allow_any_dcp_frame_rate->Bind (wxEVT_COMMAND_CHECKBOX_CLICKED, boost::bind (&GeneralPage::allow_any_dcp_frame_rate_changed, this));
                
                return panel;
        }
@@ -271,21 +257,9 @@ private:
                Config::instance()->set_num_local_encoding_threads (_num_local_encoding_threads->GetValue ());
        }
 
-       void maximum_j2k_bandwidth_changed ()
-       {
-               Config::instance()->set_maximum_j2k_bandwidth (_maximum_j2k_bandwidth->GetValue() * 1000000);
-       }
-
-       void allow_any_dcp_frame_rate_changed ()
-       {
-               Config::instance()->set_allow_any_dcp_frame_rate (_allow_any_dcp_frame_rate->GetValue ());
-       }
-       
        wxCheckBox* _set_language;
        wxChoice* _language;
        wxSpinCtrl* _num_local_encoding_threads;
-       wxSpinCtrl* _maximum_j2k_bandwidth;
-       wxCheckBox* _allow_any_dcp_frame_rate;
        wxTextCtrl* _mail_server;
        wxTextCtrl* _mail_user;
        wxTextCtrl* _mail_password;
@@ -742,6 +716,104 @@ private:
        wxTextCtrl* _kdm_email;
 };
 
+class AdvancedPage : public wxStockPreferencesPage, public Page
+{
+public:
+
+       AdvancedPage (wxSize panel_size, int border)
+               : wxStockPreferencesPage (Kind_Advanced)
+               , Page (panel_size, border)
+       {}
+       
+       wxWindow* CreateWindow (wxWindow* parent)
+       {
+               wxPanel* panel = new wxPanel (parent);
+
+               wxBoxSizer* s = new wxBoxSizer (wxVERTICAL);
+               panel->SetSizer (s);
+
+               wxFlexGridSizer* table = new wxFlexGridSizer (2, DCPOMATIC_SIZER_X_GAP, DCPOMATIC_SIZER_Y_GAP);
+               table->AddGrowableCol (1, 1);
+               s->Add (table, 1, wxALL | wxEXPAND, _border);
+               
+               add_label_to_sizer (table, panel, _("Maximum JPEG2000 bandwidth"), true);
+               _maximum_j2k_bandwidth = new wxSpinCtrl (panel);
+               table->Add (_maximum_j2k_bandwidth, 1);
+
+               _allow_any_dcp_frame_rate = new wxCheckBox (panel, wxID_ANY, _("Allow any DCP frame rate"));
+               table->Add (_allow_any_dcp_frame_rate, 1, wxEXPAND | wxALL);
+               table->AddSpacer (0);
+
+               add_label_to_sizer (table, panel, _("Log"), true);
+               _log_general = new wxCheckBox (panel, wxID_ANY, _("General"));
+               table->Add (_log_general, 1, wxEXPAND | wxALL);
+               _log_warning = new wxCheckBox (panel, wxID_ANY, _("Warnings"));
+               table->AddSpacer (0);
+               table->Add (_log_warning, 1, wxEXPAND | wxALL);
+               _log_error = new wxCheckBox (panel, wxID_ANY, _("Errors"));
+               table->AddSpacer (0);
+               table->Add (_log_error, 1, wxEXPAND | wxALL);
+               _log_timing = new wxCheckBox (panel, wxID_ANY, _("Timing"));
+               table->AddSpacer (0);
+               table->Add (_log_timing, 1, wxEXPAND | wxALL);
+
+               Config* config = Config::instance ();
+               
+               _maximum_j2k_bandwidth->SetRange (1, 500);
+               _maximum_j2k_bandwidth->SetValue (config->maximum_j2k_bandwidth() / 1000000);
+               _maximum_j2k_bandwidth->Bind (wxEVT_COMMAND_SPINCTRL_UPDATED, boost::bind (&AdvancedPage::maximum_j2k_bandwidth_changed, this));
+               _allow_any_dcp_frame_rate->SetValue (config->allow_any_dcp_frame_rate ());
+               _allow_any_dcp_frame_rate->Bind (wxEVT_COMMAND_CHECKBOX_CLICKED, boost::bind (&AdvancedPage::allow_any_dcp_frame_rate_changed, this));
+               _log_general->SetValue (config->log_types() & Log::GENERAL);
+               _log_general->Bind (wxEVT_COMMAND_CHECKBOX_CLICKED, boost::bind (&AdvancedPage::log_changed, this));
+               _log_warning->SetValue (config->log_types() & Log::WARNING);
+               _log_warning->Bind (wxEVT_COMMAND_CHECKBOX_CLICKED, boost::bind (&AdvancedPage::log_changed, this));
+               _log_error->SetValue (config->log_types() & Log::ERROR);
+               _log_error->Bind (wxEVT_COMMAND_CHECKBOX_CLICKED, boost::bind (&AdvancedPage::log_changed, this));
+               _log_timing->SetValue (config->log_types() & Log::TIMING);
+               _log_timing->Bind (wxEVT_COMMAND_CHECKBOX_CLICKED, boost::bind (&AdvancedPage::log_changed, this));
+               
+               return panel;
+       }
+
+private:
+
+       void maximum_j2k_bandwidth_changed ()
+       {
+               Config::instance()->set_maximum_j2k_bandwidth (_maximum_j2k_bandwidth->GetValue() * 1000000);
+       }
+
+       void allow_any_dcp_frame_rate_changed ()
+       {
+               Config::instance()->set_allow_any_dcp_frame_rate (_allow_any_dcp_frame_rate->GetValue ());
+       }
+
+       void log_changed ()
+       {
+               int types = 0;
+               if (_log_general->GetValue ()) {
+                       types |= Log::GENERAL;
+               }
+               if (_log_warning->GetValue ()) {
+                       types |= Log::WARNING;
+               }
+               if (_log_error->GetValue ())  {
+                       types |= Log::ERROR;
+               }
+               if (_log_timing->GetValue ()) {
+                       types |= Log::TIMING;
+               }
+               Config::instance()->set_log_types (types);
+       }
+       
+       wxSpinCtrl* _maximum_j2k_bandwidth;
+       wxCheckBox* _allow_any_dcp_frame_rate;
+       wxCheckBox* _log_general;
+       wxCheckBox* _log_warning;
+       wxCheckBox* _log_error;
+       wxCheckBox* _log_timing;
+};
+       
 wxPreferencesEditor*
 create_config_dialog ()
 {
@@ -768,5 +840,6 @@ create_config_dialog ()
        e->AddPage (new ColourConversionsPage (ps, border));
        e->AddPage (new TMSPage (ps, border));
        e->AddPage (new KDMEmailPage (ps, border));
+       e->AddPage (new AdvancedPage (ps, border));
        return e;
 }
index c8a2b49efdcd88f83133ec6e25d81cc3175a5225..98993cc5bd67c5148870e38245ff56db6da5864e 100644 (file)
@@ -70,9 +70,11 @@ BOOST_AUTO_TEST_CASE (client_server_test)
                p += sub_image->stride()[0];
        }
 
+       shared_ptr<FileLog> log (new FileLog ("build/test/client_server_test.log"));
+
        shared_ptr<PlayerVideoFrame> pvf (
                new PlayerVideoFrame (
-                       shared_ptr<ImageProxy> (new RawImageProxy (image)),
+                       shared_ptr<ImageProxy> (new RawImageProxy (image, log)),
                        Crop (),
                        libdcp::Size (1998, 1080),
                        libdcp::Size (1998, 1080),
@@ -85,8 +87,6 @@ BOOST_AUTO_TEST_CASE (client_server_test)
 
        pvf->set_subtitle (sub_image, Position<int> (50, 60));
 
-       shared_ptr<FileLog> log (new FileLog ("build/test/client_server_test.log"));
-
        shared_ptr<DCPVideoFrame> frame (
                new DCPVideoFrame (
                        pvf,