wip2882-hang

4 files changed, 68 insertions, 1 deletions

diff --git a/src/lib/butler.cc b/src/lib/butler.cc
index b2fbc6c60..5e1db9baa 100644
--- a/src/lib/butler.cc
+++ b/src/lib/butler.cc
@@ -136,6 +136,7 @@ Butler::~Butler ()
 bool
 Butler::should_run () const
 {
+	std::cout << "V:" << _video.size() << " A:" << _audio.size() << "\n";
 	if (_video.size() >= MAXIMUM_VIDEO_READAHEAD * 10) {
 		/* This is way too big */
 		optional<DCPTime> pos = _audio.peek();
@@ -166,20 +167,25 @@ Butler::should_run () const
 
 	if (_audio.size() >= MAXIMUM_AUDIO_READAHEAD * 2) {
 		LOG_WARNING ("Butler audio buffers reached %1 frames (video is %2)", _audio.size(), _video.size());
+		// std::cout << String::compose("Butler audio buffers reached %1 frames (video is %2)", _audio.size(), _video.size()) << "\n";
 	}
 
 	if (_stop_thread || _finished || _died || _suspended) {
 		/* Definitely do not run */
+		// std::cout << "run?0\n";
 		return false;
 	}
 
 	if (_video.size() < MINIMUM_VIDEO_READAHEAD || (!_disable_audio && _audio.size() < MINIMUM_AUDIO_READAHEAD)) {
 		/* Definitely do run: we need data */
+		// std::cout << "run?1\n";
 		return true;
 	}
 
 	/* Run if we aren't full of video or audio */
-	return (_video.size() < MAXIMUM_VIDEO_READAHEAD) && (_audio.size() < MAXIMUM_AUDIO_READAHEAD);
+	auto x = (_video.size() < MAXIMUM_VIDEO_READAHEAD) && (_audio.size() < MAXIMUM_AUDIO_READAHEAD);
+	// std::cout << "run?" << x << "\n";
+	return x;
 }
 
 
@@ -199,6 +205,7 @@ try
 
 		/* Do any seek that has been requested */
 		if (_pending_seek_position) {
+			std::cout << "seek to " << to_string(*_pending_seek_position) << "\n";
 			_finished = false;
 			_player.seek(*_pending_seek_position, _pending_seek_accurate);
 			_pending_seek_position = optional<DCPTime> ();
diff --git a/src/lib/ffmpeg_decoder.cc b/src/lib/ffmpeg_decoder.cc
index 45983795b..4d2bf782e 100644
--- a/src/lib/ffmpeg_decoder.cc
+++ b/src/lib/ffmpeg_decoder.cc
@@ -148,6 +148,7 @@ FFmpegDecoder::flush_codecs()
 		}
 	}
 
+	std::cout << "-> FLUSH AUDIO STREAMS\n";
 	for (auto i: ffmpeg_content()->ffmpeg_audio_streams()) {
 		auto context = _codec_context[i->index(_format_context)];
 		int r = avcodec_send_packet (context, nullptr);
@@ -161,6 +162,7 @@ FFmpegDecoder::flush_codecs()
 			did_something = true;
 		}
 	}
+	std::cout << "<- FLUSH AUDIO STREAMS\n";
 
 	return did_something ? FlushResult::AGAIN : FlushResult::DONE;
 }
@@ -579,16 +581,24 @@ FFmpegDecoder::decode_and_process_video_packet (AVPacket* packet)
 
 	bool pending = false;
 	do {
+		if (packet) {
+			std::cout << "V: -> avcodec_send_packet " << packet->size << "\n";
+		} else {
+			std::cout << "V: -> avcodec_send_packet null\n";
+		}
 		int r = avcodec_send_packet (context, packet);
 		if (r < 0) {
 			LOG_WARNING("avcodec_send_packet returned %1 for a video packet", r);
 		}
+		std::cout << "V: <- avcodec_send_packet " << r << "\n";
 
 		/* EAGAIN means we should call avcodec_receive_frame and then re-send the same packet */
 		pending = r == AVERROR(EAGAIN);
 
 		while (true) {
+			std::cout << "V: -> avcodec_receive_frame\n";
 			r = avcodec_receive_frame (context, _video_frame);
+			std::cout << "V: <- avcodec_receive_frame " << r << "\n";
 			if (r == AVERROR(EAGAIN) || r == AVERROR_EOF || (r < 0 && !packet)) {
 				/* More input is required, no more frames are coming, or we are flushing and there was
 				 * some error which we just want to ignore.
diff --git a/src/lib/player.cc b/src/lib/player.cc
index 75f6b7919..c51e826ca 100644
--- a/src/lib/player.cc
+++ b/src/lib/player.cc
@@ -1444,6 +1444,7 @@ Player::emit_video (shared_ptr<PlayerVideo> pv, DCPTime time)
 {
 	auto film = _film.lock();
 	DCPOMATIC_ASSERT(film);
+	std::cout << "Player::emit_video " << to_string(time) << "\n";
 
 	/* We need a delay to give a little wiggle room to ensure that relevant subtitles arrive at the
 	   player before the video that requires them.
@@ -1468,6 +1469,7 @@ Player::emit_video (shared_ptr<PlayerVideo> pv, DCPTime time)
 void
 Player::do_emit_video (shared_ptr<PlayerVideo> pv, DCPTime time)
 {
+	std::cout << "Player::do_emit_video " << to_string(time) << "\n";
 	if (pv->eyes() == Eyes::BOTH || pv->eyes() == Eyes::RIGHT) {
 		std::for_each(_active_texts.begin(), _active_texts.end(), [time](ActiveText& a) { a.clear_before(time); });
 	}
diff --git a/test/player_test.cc b/test/player_test.cc
index a13b50352..c63266e34 100644
--- a/test/player_test.cc
+++ b/test/player_test.cc
@@ -729,3 +729,51 @@ BOOST_AUTO_TEST_CASE(unmapped_audio_does_not_raise_buffer_error)
 	butler.rethrow();
 }
 
+
+/* Test #2882: skipping back with a particular file would kill the butler because no video frames were decoded */
+BOOST_AUTO_TEST_CASE(no_video_on_seek)
+{
+	auto content = content_factory(TestPaths::private_data() / "00015-remux.ts")[0];
+	auto film = new_test_film2("no_video_on_seek", { content });
+
+	Player player(film, Image::Alignment::COMPACT);
+	Butler butler(film, player, AudioMapping(), 2, bind(PlayerVideo::force, AV_PIX_FMT_RGB24), VideoRange::FULL, Image::Alignment::PADDED, true, false, Butler::Audio::ENABLED);
+
+	auto get_until = [&butler](dcpomatic::DCPTime const& time) {
+		dcpomatic::DCPTime video_time;
+		dcpomatic::DCPTime audio_time;
+
+		auto constexpr frames = 2000;
+		std::vector<float> audio_data(frames * 6);
+
+		while (video_time < time) {
+			if (video_time <= audio_time) {
+				Butler::Error error;
+				auto video = butler.get_video(Butler::Behaviour::BLOCKING, &error);
+				if (!video.first && error.code == Butler::Error::Code::FINISHED) {
+					break;
+				}
+				video_time = video.second;
+			} else {
+				auto audio = butler.get_audio(Butler::Behaviour::BLOCKING, audio_data.data(), frames);
+				if (audio) {
+					audio_time = *audio;
+				}
+			}
+		}
+	};
+
+	/* Simulate playing to the end */
+	get_until(dcpomatic::DCPTime::from_seconds(200));
+
+	/* Skip around a bit */
+	butler.seek(dcpomatic::DCPTime(6696000), false);
+	// dcpomatic_sleep_seconds(20);
+	dcpomatic_sleep_seconds(60);
+	butler.seek(dcpomatic::DCPTime(8956000), false);
+	// dcpomatic_sleep_seconds(20);
+	dcpomatic_sleep_seconds(60);
+
+	/* See if the butler died */
+	butler.rethrow();
+}