Tidy up logging a bit. Make it configurable from the GUI.

21 files changed, 242 insertions, 142 deletions

diff --git a/src/lib/config.cc b/src/lib/config.cc
index 40ae3971b..6d029dd1f 100644
--- a/src/lib/config.cc
+++ b/src/lib/config.cc
@@ -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 ());
 }
diff --git a/src/lib/config.h b/src/lib/config.h
index 87b7038de..bd8cfe297 100644
--- a/src/lib/config.h
+++ b/src/lib/config.h
@@ -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;
diff --git a/src/lib/cross.cc b/src/lib/cross.cc
index 8785553cb..9247baa97 100644
--- a/src/lib/cross.cc
+++ b/src/lib/cross.cc
@@ -44,6 +44,11 @@
 #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
 }
diff --git a/src/lib/dcp_video_frame.cc b/src/lib/dcp_video_frame.cc
index 5cd6a118e..265cbaae8 100644
--- a/src/lib/dcp_video_frame.cc
+++ b/src/lib/dcp_video_frame.cc
@@ -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;
 }
diff --git a/src/lib/encoder.cc b/src/lib/encoder.cc
index 4fc2d7f81..05da6bbdf 100644
--- a/src/lib/encoder.cc
+++ b/src/lib/encoder.cc
@@ -39,6 +39,10 @@
 
 #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 ();
 		}
diff --git a/src/lib/ffmpeg_content.cc b/src/lib/ffmpeg_content.cc
index f810d53be..5d0a6a309 100644
--- a/src/lib/ffmpeg_content.cc
+++ b/src/lib/ffmpeg_content.cc
@@ -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);
diff --git a/src/lib/ffmpeg_decoder.cc b/src/lib/ffmpeg_decoder.cc
index 7a5bf8ba8..6351c7e22 100644
--- a/src/lib/ffmpeg_decoder.cc
+++ b/src/lib/ffmpeg_decoder.cc
@@ -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");
 		}
 	}
 
diff --git a/src/lib/film.cc b/src/lib/film.cc
index 12a57753f..206400da2 100644
--- a/src/lib/film.cc
+++ b/src/lib/film.cc
@@ -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) {
diff --git a/src/lib/image_decoder.cc b/src/lib/image_decoder.cc
index d33b64cd4..7a9acd9e4 100644
--- a/src/lib/image_decoder.cc
+++ b/src/lib/image_decoder.cc
@@ -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);
 }
 
diff --git a/src/lib/image_proxy.cc b/src/lib/image_proxy.cc
index 0806b4ccc..c0e75c77c 100644
--- a/src/lib/image_proxy.cc
+++ b/src/lib/image_proxy.cc
@@ -24,21 +24,32 @@
 #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"));
diff --git a/src/lib/image_proxy.h b/src/lib/image_proxy.h
index 792fa004a..fcbda7dd1 100644
--- a/src/lib/image_proxy.h
+++ b/src/lib/image_proxy.h
@@ -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);
diff --git a/src/lib/log.cc b/src/lib/log.cc
index a0b031589..be32315d1 100644
--- a/src/lib/log.cc
+++ b/src/lib/log.cc
@@ -23,26 +23,42 @@
 
 #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 */
diff --git a/src/lib/log.h b/src/lib/log.h
index 991532404..641ce186d 100644
--- a/src/lib/log.h
+++ b/src/lib/log.h
@@ -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
diff --git a/src/lib/player.cc b/src/lib/player.cc
index 9f0f380e3..a90350922 100644
--- a/src/lib/player.cc
+++ b/src/lib/player.cc
@@ -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()));
diff --git a/src/lib/player_video_frame.cc b/src/lib/player_video_frame.cc
index c96ed3a33..94760e495 100644
--- a/src/lib/player_video_frame.cc
+++ b/src/lib/player_video_frame.cc
@@ -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")) {
 		
diff --git a/src/lib/player_video_frame.h b/src/lib/player_video_frame.h
index 6461134a9..b085cb609 100644
--- a/src/lib/player_video_frame.h
+++ b/src/lib/player_video_frame.h
@@ -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>);
 	
diff --git a/src/lib/scp_dcp_job.cc b/src/lib/scp_dcp_job.cc
index 0b713b042..30bfc3441 100644
--- a/src/lib/scp_dcp_job.cc
+++ b/src/lib/scp_dcp_job.cc
@@ -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;
 	
diff --git a/src/lib/server.cc b/src/lib/server.cc
index b9bb825ee..c4c98a4c9 100644
--- a/src/lib/server.cc
+++ b/src/lib/server.cc
@@ -41,6 +41,11 @@
 
 #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";
 	}
diff --git a/src/lib/transcode_job.cc b/src/lib/transcode_job.cc
index 7b304cb35..fb9a59179 100644
--- a/src/lib/transcode_job.cc
+++ b/src/lib/transcode_job.cc
@@ -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;
 	}
diff --git a/src/lib/util.h b/src/lib/util.h
index e85abf402..5ca9f74c8 100644
--- a/src/lib/util.h
+++ b/src/lib/util.h
@@ -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 */
diff --git a/src/lib/writer.cc b/src/lib/writer.cc
index 639685149..b058c2801 100644
--- a/src/lib/writer.cc
+++ b/src/lib/writer.cc
@@ -40,6 +40,10 @@
 
 #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;
 	}