Add some code to help with profiling the player.
authorCarl Hetherington <cth@carlh.net>
Tue, 6 Nov 2018 00:01:26 +0000 (00:01 +0000)
committerCarl Hetherington <cth@carlh.net>
Tue, 6 Nov 2018 00:01:26 +0000 (00:01 +0000)
src/lib/butler.cc
src/lib/ffmpeg_file_encoder.cc
src/lib/player_video.cc
src/lib/player_video.h
src/wx/film_viewer.cc
test/dcp_playback_test.cc [new file with mode: 0644]
test/player_test.cc
test/wscript

index 191bb0a5b68b52b006d8e300bb1002d40fb7f49f..d50c461c8a1275ab1102665623a45270faa3d434 100644 (file)
@@ -65,7 +65,7 @@ Butler::Butler (shared_ptr<Player> player, shared_ptr<Log> log, AudioMapping aud
        _player_video_connection = _player->Video.connect (bind (&Butler::video, this, _1, _2));
        _player_audio_connection = _player->Audio.connect (bind (&Butler::audio, this, _1, _2));
        _player_text_connection = _player->Text.connect (bind (&Butler::text, this, _1, _2, _3, _4));
-       /* The butler must here about things first, otherwise it might not sort out suspensions in time for
+       /* The butler must hear about things first, otherwise it might not sort out suspensions in time for
           get_video() to be called in response to this signal.
        */
        _player_change_connection = _player->Change.connect (bind (&Butler::player_change, this, _1, _3), boost::signals2::at_front);
@@ -78,7 +78,10 @@ Butler::Butler (shared_ptr<Player> player, shared_ptr<Log> log, AudioMapping aud
           multi-thread JPEG2000 decoding.
        */
 
-       LOG_TIMING("start-prepare-threads %1", boost::thread::hardware_concurrency());
+       if (_log) {
+               LOG_TIMING("start-prepare-threads %1", boost::thread::hardware_concurrency());
+       }
+
        for (size_t i = 0; i < boost::thread::hardware_concurrency(); ++i) {
                _prepare_pool.create_thread (bind (&boost::asio::io_service::run, &_prepare_service));
        }
@@ -120,11 +123,11 @@ Butler::should_run () const
                        (__FILE__, __LINE__, String::compose ("Butler audio buffers reached %1 frames (video is %2)", _audio.size(), _video.size()));
        }
 
-       if (_video.size() >= MAXIMUM_VIDEO_READAHEAD * 2) {
+       if (_video.size() >= MAXIMUM_VIDEO_READAHEAD * 2 && _log) {
                LOG_WARNING ("Butler video buffers reached %1 frames (audio is %2)", _video.size(), _audio.size());
        }
 
-       if (_audio.size() >= MAXIMUM_AUDIO_READAHEAD * 2) {
+       if (_audio.size() >= MAXIMUM_AUDIO_READAHEAD * 2 && _log) {
                LOG_WARNING ("Butler audio buffers reached %1 frames (video is %2)", _audio.size(), _video.size());
        }
 
@@ -259,9 +262,15 @@ Butler::prepare (weak_ptr<PlayerVideo> weak_video) const
        shared_ptr<PlayerVideo> video = weak_video.lock ();
        /* If the weak_ptr cannot be locked the video obviously no longer requires any work */
        if (video) {
-               LOG_TIMING("start-prepare in %1", thread_id());
+               if (_log) {
+                       LOG_TIMING("start-prepare in %1", thread_id());
+               }
+
                video->prepare ();
-               LOG_TIMING("finish-prepare in %1", thread_id());
+
+               if (_log) {
+                       LOG_TIMING("finish-prepare in %1", thread_id());
+               }
        }
 }
 
index 97a342e29a59733ec62f7b9d21708cd77e4a55ee..99c974d3ea049dbcdd841e38a0407c6cb9d49e75 100644 (file)
@@ -230,7 +230,7 @@ void
 FFmpegFileEncoder::video (shared_ptr<PlayerVideo> video, DCPTime time)
 {
        shared_ptr<Image> image = video->image (
-               bind (&Log::dcp_log, _log.get(), _1, _2),
+               boost::optional<dcp::NoteHandler>(bind(&Log::dcp_log, _log.get(), _1, _2)),
                bind (&force_pixel_format, _1, _pixel_format),
                true,
                false
index 12ec96a327db984bfcc47daf730133d8d94f0e03..ec8dd16d49f4a5b27ad6e3344853e0b716422f52 100644 (file)
@@ -111,7 +111,7 @@ PlayerVideo::set_text (PositionImage image)
  *  @param fast true to be fast at the expense of quality.
  */
 shared_ptr<Image>
-PlayerVideo::image (dcp::NoteHandler note, function<AVPixelFormat (AVPixelFormat)> pixel_format, bool aligned, bool fast) const
+PlayerVideo::image (optional<dcp::NoteHandler> note, function<AVPixelFormat (AVPixelFormat)> pixel_format, bool aligned, bool fast) const
 {
        pair<shared_ptr<Image>, int> prox = _in->image (optional<dcp::NoteHandler> (note), _inter_size);
        shared_ptr<Image> im = prox.first;
index 11b2c88330512b96ddc205ee104fc87237eab5cc..55a3566f0ae8e4e3e9449858a2f94c300581b380 100644 (file)
@@ -63,7 +63,7 @@ public:
        void set_text (PositionImage);
 
        void prepare ();
-       boost::shared_ptr<Image> image (dcp::NoteHandler note, boost::function<AVPixelFormat (AVPixelFormat)> pixel_format, bool aligned, bool fast) const;
+       boost::shared_ptr<Image> image (boost::optional<dcp::NoteHandler> note, boost::function<AVPixelFormat (AVPixelFormat)> pixel_format, bool aligned, bool fast) const;
 
        static AVPixelFormat always_rgb (AVPixelFormat);
        static AVPixelFormat keep_xyz_or_rgb (AVPixelFormat);
index 2247f3dd066b23eace5c03136519be8a76e62532..ccff35092929732a59da052a9744c782ecdf086b 100644 (file)
@@ -271,7 +271,7 @@ FilmViewer::display_player_video ()
         */
 
        _frame = _player_video.first->image (
-               bind (&Log::dcp_log, _film->log().get(), _1, _2),
+               optional<dcp::NoteHandler>(bind(&Log::dcp_log, _film->log().get(), _1, _2)),
                bind (&PlayerVideo::always_rgb, _1),
                false, true
                );
diff --git a/test/dcp_playback_test.cc b/test/dcp_playback_test.cc
new file mode 100644 (file)
index 0000000..6210ffc
--- /dev/null
@@ -0,0 +1,52 @@
+/*
+    Copyright (C) 2018 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 "lib/film.h"
+#include "lib/butler.h"
+#include "lib/player.h"
+#include "lib/dcp_content.h"
+#include "test.h"
+#include <boost/test/unit_test.hpp>
+
+using std::pair;
+using boost::shared_ptr;
+using boost::optional;
+
+/** Simulate the work that the player does, for profiling */
+BOOST_AUTO_TEST_CASE (dcp_playback_test)
+{
+       shared_ptr<Film> film = new_test_film ("dcp_playback_test");
+       shared_ptr<DCPContent> content (new DCPContent(film, private_data / "JourneyToJah_TLR-1_F_EN-DE-FR_CH_51_2K_LOK_20140225_DGL_SMPTE_OV"));
+       film->examine_and_add_content (content);
+       wait_for_jobs ();
+
+       shared_ptr<Butler> butler (new Butler(shared_ptr<Player>(new Player(film, film->playlist())), shared_ptr<Log>(), AudioMapping(6, 6), 6));
+       float* audio_buffer = new float[2000*6];
+       while (true) {
+               pair<shared_ptr<PlayerVideo>, DCPTime> p = butler->get_video ();
+               if (!p.first) {
+                       break;
+               }
+               /* assuming DCP is 24fps/48kHz */
+               butler->get_audio (audio_buffer, 2000);
+               p.first->image(optional<dcp::NoteHandler>(), bind(&PlayerVideo::always_rgb, _1), true, false);
+       }
+       delete[] audio_buffer;
+}
index 0fe1d953bead375b410acebc4720b206565aca25..60b5debffa3d9e70f151271b2a929a4e365a1e48 100644 (file)
@@ -226,7 +226,7 @@ BOOST_AUTO_TEST_CASE (player_seek_test)
                butler->seek (t, true);
                pair<shared_ptr<PlayerVideo>, DCPTime> video = butler->get_video();
                BOOST_CHECK_EQUAL(video.second.get(), t.get());
-               write_image(video.first->image(note_handler, PlayerVideo::always_rgb, false, true), String::compose("build/test/player_seek_test_%1.png", i), "RGB");
+               write_image(video.first->image(optional<dcp::NoteHandler>(note_handler), PlayerVideo::always_rgb, false, true), String::compose("build/test/player_seek_test_%1.png", i), "RGB");
                /* This 0.011 is empirically chosen (hopefully) to accept changes in rendering between the reference and a test machine
                   (17.10 and 16.04 seem to anti-alias a little differently) but to reject gross errors e.g. missing fonts or missing
                   text altogether.
@@ -259,7 +259,7 @@ BOOST_AUTO_TEST_CASE (player_seek_test2)
                butler->seek (t, true);
                pair<shared_ptr<PlayerVideo>, DCPTime> video = butler->get_video();
                BOOST_CHECK_EQUAL(video.second.get(), t.get());
-               write_image(video.first->image(note_handler, PlayerVideo::always_rgb, false, true), String::compose("build/test/player_seek_test2_%1.png", i), "RGB");
+               write_image(video.first->image(optional<dcp::NoteHandler>(note_handler), PlayerVideo::always_rgb, false, true), String::compose("build/test/player_seek_test2_%1.png", i), "RGB");
                check_image(String::compose("test/data/player_seek_test2_%1.png", i), String::compose("build/test/player_seek_test2_%1.png", i), 0.011);
        }
 }
index 24394971fbe57adf659ea6a79153f408160c2f93..47f3dc275e3d46bbbf504a1b80a0fa0b5cc34a9c 100644 (file)
@@ -58,6 +58,7 @@ def build(bld):
                  config_test.cc
                  content_test.cc
                  dcpomatic_time_test.cc
+                 dcp_playback_test.cc
                  dcp_subtitle_test.cc
                  digest_test.cc
                  empty_test.cc