27 files changed, 206 insertions, 43 deletions

diff --git a/src/lib/butler.cc b/src/lib/butler.cc
index dd9874587..5fd695a94 100644
--- a/src/lib/butler.cc
+++ b/src/lib/butler.cc
@@ -88,6 +88,7 @@ Butler::Butler (
 	, _alignment (alignment)
 	, _fast (fast)
 	, _prepare_only_proxy (prepare_only_proxy)
+	, _lookahead(false)
 {
 	_player_video_connection = _player.Video.connect(bind(&Butler::video, this, _1, _2));
 	_player_audio_connection = _player.Audio.connect(bind(&Butler::audio, this, _1, _2, _3));
@@ -107,7 +108,7 @@ Butler::Butler (
 
 	LOG_TIMING("start-prepare-threads %1", boost::thread::hardware_concurrency() * 2);
 
-	for (size_t i = 0; i < boost::thread::hardware_concurrency() * 2; ++i) {
+	for (size_t i = 0; i < boost::thread::hardware_concurrency() / 2; ++i) {
 		_prepare_pool.create_thread (bind (&boost::asio::io_service::run, &_prepare_service));
 	}
 }
@@ -200,6 +201,7 @@ try
 		/* Do any seek that has been requested */
 		if (_pending_seek_position) {
 			_finished = false;
+			std::cout << "-------------------------------- seek " << to_string(*_pending_seek_position) << " " << _pending_seek_accurate << "\n";
 			_player.seek(*_pending_seek_position, _pending_seek_accurate);
 			_pending_seek_position = optional<DCPTime> ();
 		}
@@ -322,11 +324,12 @@ void
 Butler::prepare (weak_ptr<PlayerVideo> weak_video)
 try
 {
-	auto video = weak_video.lock ();
 	/* If the weak_ptr cannot be locked the video obviously no longer requires any work */
-	if (video) {
+	if (auto video = weak_video.lock()) {
 		LOG_TIMING("start-prepare in %1", thread_id());
+		std::cout << "SPREP.\n";
 		video->prepare (_pixel_format, _video_range, _alignment, _fast, _prepare_only_proxy);
+		std::cout << "FPREP.\n";
 		LOG_TIMING("finish-prepare in %1", thread_id());
 	}
 }
@@ -355,7 +358,10 @@ Butler::video (shared_ptr<PlayerVideo> video, DCPTime time)
 		return;
 	}
 
-	_prepare_service.post (bind(&Butler::prepare, this, weak_ptr<PlayerVideo>(video)));
+	std::cout << "POST " << to_string(time) << " to prep service.\n";
+	// if (_lookahead) {
+		_prepare_service.post(bind(&Butler::prepare, this, weak_ptr<PlayerVideo>(video)));
+	// }
 
 	_video.put (video, time);
 }
@@ -481,3 +487,17 @@ Butler::Error::summary () const
 	return "";
 }
 
+
+void
+Butler::enable_lookahead()
+{
+	_lookahead = true;
+}
+
+
+void
+Butler::disable_lookahead()
+{
+	_lookahead = false;
+}
+
diff --git a/src/lib/butler.h b/src/lib/butler.h
index 6bb0467af..bc6d7485a 100644
--- a/src/lib/butler.h
+++ b/src/lib/butler.h
@@ -95,6 +95,9 @@ public:
 
 	std::pair<size_t, std::string> memory_used () const;
 
+	void enable_lookahead();
+	void disable_lookahead();
+
 private:
 	void thread ();
 	void video (std::shared_ptr<PlayerVideo> video, dcpomatic::DCPTime time);
@@ -152,6 +155,8 @@ private:
 	*/
 	boost::optional<dcpomatic::DCPTime> _awaiting;
 
+	boost::atomic<bool> _lookahead;
+
 	boost::signals2::scoped_connection _player_video_connection;
 	boost::signals2::scoped_connection _player_audio_connection;
 	boost::signals2::scoped_connection _player_text_connection;
diff --git a/src/lib/change_signaller.cc b/src/lib/change_signaller.cc
deleted file mode 100644
index a1f093d14..000000000
--- a/src/lib/change_signaller.cc
+++ /dev/null
@@ -1,24 +0,0 @@
-/*
-    Copyright (C) 2018-2021 Carl Hetherington <cth@carlh.net>
-
-    This file is part of DCP-o-matic.
-
-    DCP-o-matic is free software; you can redistribute it and/or modify
-    it under the terms of the GNU General Public License as published by
-    the Free Software Foundation; either version 2 of the License, or
-    (at your option) any later version.
-
-    DCP-o-matic is distributed in the hope that it will be useful,
-    but WITHOUT ANY WARRANTY; without even the implied warranty of
-    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
-    GNU General Public License for more details.
-
-    You should have received a copy of the GNU General Public License
-    along with DCP-o-matic.  If not, see <http://www.gnu.org/licenses/>.
-
-*/
-
-
-#include "change_signaller.h"
-
-
diff --git a/src/lib/change_signaller.h b/src/lib/change_signaller.h
index 0b2c1539d..f66e83ff6 100644
--- a/src/lib/change_signaller.h
+++ b/src/lib/change_signaller.h
@@ -23,9 +23,12 @@
 #define DCPOMATIC_CHANGE_SIGNALLER_H
 
 
+#include "timer.h"
 #include <boost/thread.hpp>
 #include <vector>
 
+#include <iostream>
+
 
 enum class ChangeType
 {
@@ -73,6 +76,7 @@ public:
 			boost::mutex::scoped_lock lm(_mutex);
 			_pending.push_back(signal);
 		} else {
+			GlobalTimer::instance()->mark("signalled");
 			signal.thing->signal_change(signal.type, signal.property);
 		}
 	}
@@ -128,6 +132,9 @@ public:
 
 	~ChangeSignaller ()
 	{
+		if (static_cast<int>(_property) == 401) {
+			GlobalTimer::instance()->mark("signal_change 401");
+		}
 		ChangeSignalDespatcher<T, P>::instance()->signal_change({_thing, _property, _done ? ChangeType::DONE : ChangeType::CANCELLED});
 	}
 
diff --git a/src/lib/content.cc b/src/lib/content.cc
index 5e6dd7e31..91574a669 100644
--- a/src/lib/content.cc
+++ b/src/lib/content.cc
@@ -204,10 +204,12 @@ Content::examine(shared_ptr<const Film>, shared_ptr<Job> job, bool)
 void
 Content::signal_change (ChangeType c, int p)
 {
+	std::cout << "Content::signal_change " << p << " " << static_cast<int>(c) << "\n";
 	try {
 		if (c == ChangeType::PENDING || c == ChangeType::CANCELLED) {
 			Change (c, shared_from_this(), p, _change_signals_frequent);
 		} else {
+			PeriodTimer timer("emit");
 			emit (boost::bind (boost::ref(Change), c, shared_from_this(), p, _change_signals_frequent));
 		}
 	} catch (std::bad_weak_ptr &) {
diff --git a/src/lib/film.cc b/src/lib/film.cc
index 9c0637dbb..0db103969 100644
--- a/src/lib/film.cc
+++ b/src/lib/film.cc
@@ -1578,12 +1578,12 @@ Film::playlist_content_change (ChangeType type, weak_ptr<Content> c, int p, bool
 	}
 
 	if (type == ChangeType::DONE) {
-		emit (boost::bind (boost::ref (ContentChange), type, c, p, frequent));
+		// emit (boost::bind (boost::ref (ContentChange), type, c, p, frequent));
 		if (!frequent) {
 			check_settings_consistency ();
 		}
 	} else {
-		ContentChange (type, c, p, frequent);
+		// ContentChange (type, c, p, frequent);
 	}
 
 	set_dirty (true);
diff --git a/src/lib/player.cc b/src/lib/player.cc
index 7048435b5..a4912ce61 100644
--- a/src/lib/player.cc
+++ b/src/lib/player.cc
@@ -255,6 +255,8 @@ have_audio (shared_ptr<const Content> content)
 void
 Player::setup_pieces ()
 {
+	std::cout << "setup pieces.\n";
+
 	boost::mutex::scoped_lock lm (_mutex);
 
 	auto old_pieces = _pieces;
@@ -416,6 +418,10 @@ Player::setup_pieces ()
 void
 Player::playlist_content_change (ChangeType type, int property, bool frequent)
 {
+	if (frequent) {
+		return;
+	}
+
 	auto film = _film.lock();
 	if (!film) {
 		return;
diff --git a/src/lib/player_video.cc b/src/lib/player_video.cc
index b2da6c33b..b3fc57c74 100644
--- a/src/lib/player_video.cc
+++ b/src/lib/player_video.cc
@@ -115,13 +115,27 @@ PlayerVideo::set_text (PositionImage image)
 }
 
 
+bool
+PlayerVideo::have_image() const
+{
+	boost::mutex::scoped_lock lm (_mutex);
+	return have_image_unlocked();
+}
+
+
+bool
+PlayerVideo::have_image_unlocked() const
+{
+	return _image && _crop == _image_crop && _inter_size == _image_inter_size && _out_size == _image_out_size && _fade == _image_fade;
+}
+
+
 shared_ptr<Image>
 PlayerVideo::image (function<AVPixelFormat (AVPixelFormat)> pixel_format, VideoRange video_range, bool fast) const
 {
 	/* XXX: this assumes that image() and prepare() are only ever called with the same parameters (except crop, inter size, out size, fade) */
-
 	boost::mutex::scoped_lock lm (_mutex);
-	if (!_image || _crop != _image_crop || _inter_size != _image_inter_size || _out_size != _image_out_size || _fade != _image_fade) {
+	if (!have_image_unlocked()) {
 		make_image (pixel_format, video_range, fast);
 	}
 	return _image;
diff --git a/src/lib/player_video.h b/src/lib/player_video.h
index e2968749c..e27975932 100644
--- a/src/lib/player_video.h
+++ b/src/lib/player_video.h
@@ -75,6 +75,7 @@ public:
 		return _text;
 	}
 
+	bool have_image() const;
 	void prepare (std::function<AVPixelFormat (AVPixelFormat)> pixel_format, VideoRange video_range, Image::Alignment alignment, bool fast, bool proxy_only);
 	std::shared_ptr<Image> image (std::function<AVPixelFormat (AVPixelFormat)> pixel_format, VideoRange video_range, bool fast) const;
 	std::shared_ptr<const Image> raw_image () const;
@@ -128,6 +129,7 @@ public:
 
 private:
 	void make_image (std::function<AVPixelFormat (AVPixelFormat)> pixel_format, VideoRange video_range, bool fast) const;
+	bool have_image_unlocked() const;
 
 	std::shared_ptr<const ImageProxy> _in;
 	Crop _crop;
diff --git a/src/lib/playlist.cc b/src/lib/playlist.cc
index a0d7d6531..f50285681 100644
--- a/src/lib/playlist.cc
+++ b/src/lib/playlist.cc
@@ -96,6 +96,7 @@ Playlist::content_change (weak_ptr<const Film> weak_film, ChangeType type, weak_
 	DCPOMATIC_ASSERT (film);
 
 	if (type == ChangeType::DONE) {
+		PeriodTimer timer("content_change#1 in Playlist");
 		if (
 			property == ContentProperty::TRIM_START ||
 			property == ContentProperty::TRIM_END ||
@@ -116,6 +117,7 @@ Playlist::content_change (weak_ptr<const Film> weak_film, ChangeType type, weak_
 			property == ContentProperty::TRIM_START ||
 			property == ContentProperty::TRIM_END) {
 
+
 			bool changed = false;
 
 			{
@@ -134,6 +136,8 @@ Playlist::content_change (weak_ptr<const Film> weak_film, ChangeType type, weak_
 		}
 	}
 
+
+	PeriodTimer timer("content_change#2 in Playlist");
 	ContentChange (type, content, property, frequent);
 }
 
diff --git a/src/lib/signal_manager.h b/src/lib/signal_manager.h
index 99e3b5c52..853c473c7 100644
--- a/src/lib/signal_manager.h
+++ b/src/lib/signal_manager.h
@@ -27,6 +27,8 @@
 #include <boost/asio.hpp>
 #include <boost/thread.hpp>
 
+#include <iostream>
+
 
 class Signaller;
 
@@ -85,6 +87,7 @@ private:
 				store_current ();
 			}
 		} else {
+			std::cout << "[[waiting]]\n";
 			/* non-UI thread; post to the service and wake up the UI */
 			_service.post (f);
 			wake_ui ();
diff --git a/src/lib/timer.cc b/src/lib/timer.cc
index caef89e0e..46766d70f 100644
--- a/src/lib/timer.cc
+++ b/src/lib/timer.cc
@@ -27,6 +27,7 @@
 #include "compose.hpp"
 #include "timer.h"
 #include "util.h"
+#include <fmt/format.h>
 #include <sys/time.h>
 #include <iostream>
 
@@ -41,6 +42,9 @@ using std::string;
 using boost::optional;
 
 
+GlobalTimer* GlobalTimer::_instance = nullptr;
+
+
 /** @param n Name to use when giving output */
 PeriodTimer::PeriodTimer (string n)
 	: _name (n)
@@ -54,7 +58,7 @@ PeriodTimer::~PeriodTimer ()
 {
 	struct timeval stop;
 	gettimeofday (&stop, 0);
-	cout << N_("T: ") << _name << N_(": ") << (seconds (stop) - seconds (_start)) << N_("\n");
+	cout << fmt::format("T: {}: {:.3f}\n", _name, seconds(stop) - seconds(_start));
 }
 
 
@@ -143,3 +147,47 @@ StateTimer::~StateTimer ()
 		cout << N_("\t") << i.second << "\n";
 	}
 }
+
+
+GlobalTimer*
+GlobalTimer::instance()
+{
+	if (!_instance) {
+		_instance = new GlobalTimer();
+	}
+
+	return _instance;
+}
+
+
+void
+GlobalTimer::reset()
+{
+	struct timeval now;
+	gettimeofday(&now, 0);
+	_reset = _last = seconds(now);
+	// std::cout << "|----------------------\\\n";
+}
+
+
+void
+GlobalTimer::mark(string const& tag)
+{
+	// std::cout << "|" << tag << " ";
+
+	struct timeval now;
+	gettimeofday(&now, 0);
+	auto const now_seconds = seconds(now);
+
+	if (_last > 0) {
+		// std::cout << fmt::format("{:.2} ", now_seconds - _last);
+	}
+
+	if (_reset > 0) {
+		// std::cout << fmt::format("{:.2} ", now_seconds - _reset);
+	}
+
+	_last = now_seconds;
+	// std::cout << "\n";
+}
+
diff --git a/src/lib/timer.h b/src/lib/timer.h
index be3706607..e60b1a8ba 100644
--- a/src/lib/timer.h
+++ b/src/lib/timer.h
@@ -105,4 +105,20 @@ private:
 };
 
 
+class GlobalTimer
+{
+public:
+	void mark(std::string const& tag);
+	void reset();
+
+	static GlobalTimer* instance();
+
+private:
+	static GlobalTimer* _instance;
+
+	double _reset = 0;
+	double _last = 0;
+};
+
+
 #endif
diff --git a/src/lib/wscript b/src/lib/wscript
index 8a4b17dbc..0f5a23521 100644
--- a/src/lib/wscript
+++ b/src/lib/wscript
@@ -51,7 +51,6 @@ sources = """
           check_content_job.cc
           cinema_list.cc
           cinema_sound_processor.cc
-          change_signaller.cc
           collator.cc
           colour_conversion.cc
           config.cc
diff --git a/src/wx/audio_panel.cc b/src/wx/audio_panel.cc
index 1418f1ff9..1bc62b547 100644
--- a/src/wx/audio_panel.cc
+++ b/src/wx/audio_panel.cc
@@ -214,6 +214,8 @@ AudioPanel::film_changed (FilmProperty property)
 void
 AudioPanel::film_content_changed (int property)
 {
+	PeriodTimer timer("AudioPanel::film_content_changed");
+
 	auto ac = _parent->selected_audio ();
 	if (property == AudioContentProperty::STREAMS) {
 		if (ac.size() == 1) {
diff --git a/src/wx/content_panel.cc b/src/wx/content_panel.cc
index 8938ef0fd..4b60e13a8 100644
--- a/src/wx/content_panel.cc
+++ b/src/wx/content_panel.cc
@@ -865,6 +865,8 @@ ContentPanel::select_all ()
 void
 ContentPanel::film_content_changed (int property)
 {
+	PeriodTimer timer("ContentPanel::film_content_changed");
+
 	if (
 		property == ContentProperty::PATH ||
 		property == DCPContentProperty::NEEDS_ASSETS ||
diff --git a/src/wx/content_timeline.cc b/src/wx/content_timeline.cc
index 7200bf076..cdbe60760 100644
--- a/src/wx/content_timeline.cc
+++ b/src/wx/content_timeline.cc
@@ -48,6 +48,9 @@ LIBDCP_ENABLE_WARNINGS
 #include <list>
 
 
+#include "lib/timer.h"
+
+
 using std::abs;
 using std::dynamic_pointer_cast;
 using std::list;
@@ -643,7 +646,9 @@ ContentTimeline::left_up_select(wxMouseEvent& ev)
 		_down_view->content()->set_change_signals_frequent (false);
 	}
 
-	_content_panel->set_selection (selected_content ());
+	PeriodTimer timer("Let's a go");
+	// _content_panel->set_selection (selected_content ());
+
 	/* Since we may have just set change signals back to `not-frequent', we have to
 	   make sure this position change is signalled, even if the position value has
 	   not changed since the last time it was set (with frequent=true).  This is
@@ -856,6 +861,8 @@ ContentTimeline::set_position_from_event(wxMouseEvent& ev, bool force_emit)
 		new_position = DCPTime ();
 	}
 
+	GlobalTimer::instance()->reset();
+	GlobalTimer::instance()->mark("set_position");
 	_down_view->content()->set_position (film, new_position, force_emit);
 
 	film->set_sequence (false);
@@ -865,6 +872,7 @@ ContentTimeline::set_position_from_event(wxMouseEvent& ev, bool force_emit)
 void
 ContentTimeline::force_redraw(dcpomatic::Rect<int> const & r)
 {
+	GlobalTimer::instance()->mark("RefreshRect");
 	_main_canvas->RefreshRect (wxRect (r.x, r.y, r.width, r.height), false);
 }
 
diff --git a/src/wx/content_widget.h b/src/wx/content_widget.h
index f7edf6b30..68e257c7f 100644
--- a/src/wx/content_widget.h
+++ b/src/wx/content_widget.h
@@ -211,9 +211,9 @@ private:
 
 	void model_changed (ChangeType type, int property)
 	{
-		if (type == ChangeType::DONE && property == _property && !_ignore_model_changes) {
-			update_from_model ();
-		}
+		// if (type == ChangeType::DONE && property == _property && !_ignore_model_changes) {
+		// 	update_from_model ();
+		// }
 	}
 
 	T* _wrapped;
diff --git a/src/wx/dcp_referencing_dialog.cc b/src/wx/dcp_referencing_dialog.cc
index 9b1c61c12..4d314a031 100644
--- a/src/wx/dcp_referencing_dialog.cc
+++ b/src/wx/dcp_referencing_dialog.cc
@@ -83,6 +83,8 @@ DCPReferencingDialog::film_changed(ChangeType type, FilmProperty property)
 void
 DCPReferencingDialog::film_content_changed(ChangeType type, int property)
 {
+	PeriodTimer timer("DCPReferencingDialog::film_content_changed");
+
 	if (type != ChangeType::DONE) {
 		return;
 	}
diff --git a/src/wx/film_viewer.cc b/src/wx/film_viewer.cc
index a7a2ab984..a40c316f6 100644
--- a/src/wx/film_viewer.cc
+++ b/src/wx/film_viewer.cc
@@ -405,6 +405,7 @@ FilmViewer::start ()
 	start_audio_stream_if_open ();
 
 	_playing = true;
+	_butler->enable_lookahead();
 	/* Calling start() below may directly result in Stopped being emitted, and if that
 	 * happens we want it to come after the Started signal, so do that first.
 	 */
@@ -423,6 +424,7 @@ FilmViewer::stop ()
 	}
 
 	_playing = false;
+	_butler->disable_lookahead();
 	_video_view->stop ();
 	Stopped ();
 
@@ -451,6 +453,7 @@ void
 FilmViewer::player_change (vector<int> properties)
 {
 	calculate_sizes ();
+	PeriodTimer timer("FV player_change");
 
 	bool try_quick_refresh = false;
 	bool update_ccap_tracks = false;
@@ -484,9 +487,11 @@ FilmViewer::player_change (vector<int> properties)
 }
 
 
+
 void
 FilmViewer::film_change(ChangeType type, FilmProperty p)
 {
+	PeriodTimer timer("FV film_change");
 	if (type != ChangeType::DONE) {
 		return;
 	}
@@ -506,6 +511,7 @@ FilmViewer::film_change(ChangeType type, FilmProperty p)
 void
 FilmViewer::film_length_change ()
 {
+	PeriodTimer timer("FV film_length_change");
 	_video_view->set_length (_film->length());
 }
 
@@ -514,6 +520,7 @@ FilmViewer::film_length_change ()
 void
 FilmViewer::slow_refresh ()
 {
+	PeriodTimer timer("FV slow refresh\n");
 	seek (_video_view->position(), true);
 }
 
diff --git a/src/wx/simple_video_view.cc b/src/wx/simple_video_view.cc
index 84c837757..91d4d4215 100644
--- a/src/wx/simple_video_view.cc
+++ b/src/wx/simple_video_view.cc
@@ -195,12 +195,17 @@ SimpleVideoView::start ()
 VideoView::NextFrameResult
 SimpleVideoView::display_next_frame (bool non_blocking)
 {
+	std::cout << "dnf non_blocking=" << non_blocking << "\n";
+	PeriodTimer timer("dnf");
+
 	auto const r = get_next_frame (non_blocking);
 	if (r != SUCCESS) {
 		return r;
 	}
 
-	update ();
+	if (do_update(non_blocking)) {
+		return AGAIN;
+	}
 
 	try {
 		_viewer->butler()->rethrow ();
@@ -215,18 +220,30 @@ SimpleVideoView::display_next_frame (bool non_blocking)
 void
 SimpleVideoView::update ()
 {
+	do_update(false);
+}
+
+
+/** @return true if this call was aborted because it would take too long, and we're non_blocking */
+bool
+SimpleVideoView::do_update(bool non_blocking)
+{
+	StateTimer timer("update", "early-return");
 	if (!player_video().first) {
 		_image.reset ();
 		refresh_panel ();
-		return;
+		return false;
 	}
 
+	timer.set("check too late");
+
 	if (_viewer->playing() && (_viewer->time() - player_video().second) > one_video_frame()) {
+		std::cout << "too late!\n";
 		/* Too late; just drop this frame before we try to get its image (which will be the time-consuming
 		   part if this frame is J2K).
 		*/
 		add_dropped ();
-		return;
+		return false;
 	}
 
 	/* In an ideal world, what we would do here is:
@@ -249,18 +266,30 @@ SimpleVideoView::update ()
 
 	_state_timer.set ("get image");
 
+	timer.set("player_video()");
 	auto const pv = player_video();
+	timer.set("get image");
+	// if (non_blocking && !pv.first->have_image()) {
+	// 	std::cout << "not ready\n";
+	// 	return true;
+	// }
+
 	_image = pv.first->image(boost::bind(&PlayerVideo::force, AV_PIX_FMT_RGB24), VideoRange::FULL, true);
+	timer.set("fix 2020");
 	if (pv.first->colour_conversion() && pv.first->colour_conversion()->about_equal(dcp::ColourConversion::rec2020_to_xyz(), 1e-6)) {
 		_image = Image::ensure_alignment(_rec2020_filter_graph.get(_image->size(), _image->pixel_format())->process(_image).front(), Image::Alignment::COMPACT);
 	}
 
 	_state_timer.set ("ImageChanged");
+	timer.set("image_changed");
 	_viewer->image_changed (player_video().first);
 	_state_timer.unset ();
 
 	_inter_position = player_video().first->inter_position ();
 	_inter_size = player_video().first->inter_size ();
 
+	timer.set("refresh_panel");
 	refresh_panel ();
+
+	return false;
 }
diff --git a/src/wx/simple_video_view.h b/src/wx/simple_video_view.h
index e19068979..80087a7d8 100644
--- a/src/wx/simple_video_view.h
+++ b/src/wx/simple_video_view.h
@@ -48,6 +48,7 @@ public:
 	NextFrameResult display_next_frame (bool non_blocking) override;
 
 private:
+	bool do_update(bool non_blocking);
 	void refresh_panel ();
 	void paint ();
 	void timer ();
diff --git a/src/wx/text_panel.cc b/src/wx/text_panel.cc
index b69f115f7..90842ee80 100644
--- a/src/wx/text_panel.cc
+++ b/src/wx/text_panel.cc
@@ -394,6 +394,7 @@ TextPanel::film_changed(FilmProperty property)
 void
 TextPanel::film_content_changed (int property)
 {
+	PeriodTimer timer("TextPanel::film_content_changed");
 	auto fc = _parent->selected_ffmpeg ();
 	auto sc = _parent->selected_text ();
 
diff --git a/src/wx/timeline_content_view.cc b/src/wx/timeline_content_view.cc
index 69a675c42..ef9165d0d 100644
--- a/src/wx/timeline_content_view.cc
+++ b/src/wx/timeline_content_view.cc
@@ -175,6 +175,8 @@ TimelineContentView::do_paint (wxGraphicsContext* gc, list<dcpomatic::Rect<int>>
 void
 TimelineContentView::content_change (ChangeType type, int p)
 {
+	PeriodTimer timer("TimelineContentView::content_change");
+
 	if (type != ChangeType::DONE) {
 		return;
 	}
diff --git a/src/wx/video_panel.cc b/src/wx/video_panel.cc
index 06de93526..f83df0d0e 100644
--- a/src/wx/video_panel.cc
+++ b/src/wx/video_panel.cc
@@ -371,6 +371,7 @@ hash_value (boost::optional<ColourConversion> const & c)
 void
 VideoPanel::film_content_changed (int property)
 {
+	PeriodTimer timer("VideoPanel::film_content_changed");
 	auto vc = _parent->selected_video ();
 	shared_ptr<Content> vcs;
 	shared_ptr<FFmpegContent> fcs;
@@ -543,6 +544,8 @@ VideoPanel::edit_colour_conversion_clicked ()
 void
 VideoPanel::content_selection_changed ()
 {
+	std::cout << "VideoContentProperty::content_selection_changed\n";
+
 	auto video_sel = _parent->selected_video ();
 
 	_frame_type->set_content (video_sel);
diff --git a/src/wx/video_view.cc b/src/wx/video_view.cc
index c271cb65e..1a19426f5 100644
--- a/src/wx/video_view.cc
+++ b/src/wx/video_view.cc
@@ -61,6 +61,8 @@ VideoView::clear ()
 VideoView::NextFrameResult
 VideoView::get_next_frame (bool non_blocking)
 {
+	PeriodTimer timer("get_next_frame");
+
 	if (length() == dcpomatic::DCPTime()) {
 		return FAIL;
 	}
diff --git a/src/wx/video_view.h b/src/wx/video_view.h
index 3ea03a5fd..7f6471934 100644
--- a/src/wx/video_view.h
+++ b/src/wx/video_view.h
@@ -56,8 +56,10 @@ public:
 
 	/** @return the thing displaying the image */
 	virtual wxWindow* get () const = 0;
-	/** Re-make and display the image from the current _player_video */
-	virtual void update () = 0;
+	/** Re-make and display the image from the current _player_video.
+	 *  It's OK if this takes a while.
+	 */
+	virtual void update() = 0;
 	/** Called when playback starts */
 	virtual void start ();
 	/** Called when playback stops */