More player debugging for butler video-full states.
[dcpomatic.git] / src / lib / writer.cc
index 10e4514fbcc134ef333d333d5086511b6b5660a3..45a74624f7da19564766b26ef2eba18da8f59b84 100644 (file)
@@ -1,5 +1,5 @@
 /*
-    Copyright (C) 2012-2017 Carl Hetherington <cth@carlh.net>
+    Copyright (C) 2012-2018 Carl Hetherington <cth@carlh.net>
 
     This file is part of DCP-o-matic.
 
@@ -23,6 +23,7 @@
 #include "film.h"
 #include "ratio.h"
 #include "log.h"
+#include "dcpomatic_log.h"
 #include "dcp_video.h"
 #include "dcp_content_type.h"
 #include "audio_mapping.h"
 
 #include "i18n.h"
 
-#define LOG_GENERAL(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_GENERAL);
-#define LOG_GENERAL_NC(...) _film->log()->log (__VA_ARGS__, LogEntry::TYPE_GENERAL);
-#define LOG_DEBUG_ENCODE(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_DEBUG_ENCODE);
-#define LOG_TIMING(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_TIMING);
-#define LOG_WARNING_NC(...) _film->log()->log (__VA_ARGS__, LogEntry::TYPE_WARNING);
-#define LOG_WARNING(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_WARNING);
-#define LOG_ERROR(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_ERROR);
-
 /* OS X strikes again */
 #undef set_key
 
@@ -63,9 +56,11 @@ using std::cout;
 using std::map;
 using std::min;
 using std::max;
+using std::vector;
 using boost::shared_ptr;
 using boost::weak_ptr;
 using boost::dynamic_pointer_cast;
+using boost::optional;
 using dcp::Data;
 
 Writer::Writer (shared_ptr<const Film> film, weak_ptr<Job> j)
@@ -74,7 +69,9 @@ Writer::Writer (shared_ptr<const Film> film, weak_ptr<Job> j)
        , _thread (0)
        , _finish (false)
        , _queued_full_in_memory (0)
-       , _maximum_frames_in_memory (0)
+       /* These will be reset to sensible values when J2KEncoder is created */
+       , _maximum_frames_in_memory (8)
+       , _maximum_queue_size (8)
        , _full_written (0)
        , _fake_written (0)
        , _repeat_written (0)
@@ -89,11 +86,14 @@ Writer::Writer (shared_ptr<const Film> film, weak_ptr<Job> j)
                _reels.push_back (ReelWriter (film, p, job, reel_index++, reels.size(), _film->content_summary(p)));
        }
 
-       /* We can keep track of the current audio and subtitle reels easily because audio
-          and subs arrive to the Writer in sequence.  This is not so for video.
+       /* We can keep track of the current audio, subtitle and closed caption reels easily because audio
+          and captions arrive to the Writer in sequence.  This is not so for video.
        */
        _audio_reel = _reels.begin ();
        _subtitle_reel = _reels.begin ();
+       BOOST_FOREACH (DCPTextTrack i, _film->closed_caption_tracks()) {
+               _caption_reels[i] = _reels.begin ();
+       }
 
        /* Check that the signer is OK if we need one */
        string reason;
@@ -106,6 +106,9 @@ void
 Writer::start ()
 {
        _thread = new boost::thread (boost::bind (&Writer::thread, this));
+#ifdef DCPOMATIC_LINUX
+       pthread_setname_np (_thread->native_handle(), "writer");
+#endif
 }
 
 Writer::~Writer ()
@@ -125,7 +128,9 @@ Writer::write (Data encoded, Frame frame, Eyes eyes)
        boost::mutex::scoped_lock lock (_state_mutex);
 
        while (_queued_full_in_memory > _maximum_frames_in_memory) {
-               /* The queue is too big; wait until that is sorted out */
+               /* There are too many full frames in memory; wake the main writer thread and
+                  wait until it sorts everything out */
+               _empty_condition.notify_all ();
                _full_condition.wait (lock);
        }
 
@@ -168,8 +173,11 @@ Writer::repeat (Frame frame, Eyes eyes)
 {
        boost::mutex::scoped_lock lock (_state_mutex);
 
-       while (_queued_full_in_memory > _maximum_frames_in_memory) {
-               /* The queue is too big; wait until that is sorted out */
+       while (_queue.size() > _maximum_queue_size && have_sequenced_image_at_queue_head()) {
+               /* The queue is too big, and the main writer thread can run and fix it, so
+                  wake it and wait until it has done.
+               */
+               _empty_condition.notify_all ();
                _full_condition.wait (lock);
        }
 
@@ -196,8 +204,11 @@ Writer::fake_write (Frame frame, Eyes eyes)
 {
        boost::mutex::scoped_lock lock (_state_mutex);
 
-       while (_queued_full_in_memory > _maximum_frames_in_memory) {
-               /* The queue is too big; wait until that is sorted out */
+       while (_queue.size() > _maximum_queue_size && have_sequenced_image_at_queue_head()) {
+               /* The queue is too big, and the main writer thread can run and fix it, so
+                  wake it and wait until it has done.
+               */
+               _empty_condition.notify_all ();
                _full_condition.wait (lock);
        }
 
@@ -402,6 +413,7 @@ try
                        }
 
                        lock.lock ();
+                       _full_condition.notify_all ();
                }
 
                while (_queued_full_in_memory > _maximum_frames_in_memory) {
@@ -419,7 +431,7 @@ try
                        DCPOMATIC_ASSERT (i != _queue.rend());
                        ++_pushed_to_disk;
                        /* For the log message below */
-                       int const awaiting = _reels[_queue.front().reel].last_written_video_frame();
+                       int const awaiting = _reels[_queue.front().reel].last_written_video_frame() + 1;
                        lock.unlock ();
 
                        /* i is valid here, even though we don't hold a lock on the mutex,
@@ -437,10 +449,8 @@ try
                        lock.lock ();
                        i->encoded.reset ();
                        --_queued_full_in_memory;
+                       _full_condition.notify_all ();
                }
-
-               /* The queue has probably just gone down a bit; notify anything wait()ing on _full_condition */
-               _full_condition.notify_all ();
        }
 }
 catch (...)
@@ -624,7 +634,7 @@ Writer::write_cover_sheet ()
 
        boost::algorithm::replace_all (text, "$LENGTH", length);
 
-       fwrite (text.c_str(), 1, text.length(), f);
+       checked_fwrite (text.c_str(), text.length(), f, cover);
        fclose (f);
 }
 
@@ -634,6 +644,11 @@ Writer::write_cover_sheet ()
 bool
 Writer::can_fake_write (Frame frame) const
 {
+       if (_film->encrypted()) {
+               /* We need to re-write the frame because the asset ID is embedded in the HMAC... I think... */
+               return false;
+       }
+
        /* We have to do a proper write of the first frame so that we can set up the JPEG2000
           parameters in the asset writer.
        */
@@ -645,18 +660,32 @@ Writer::can_fake_write (Frame frame) const
        return (frame != 0 && frame < reel.first_nonexistant_frame());
 }
 
+/** @param track Closed caption track if type == TEXT_CLOSED_CAPTION */
 void
-Writer::write (PlayerSubtitles subs, DCPTimePeriod period)
+Writer::write (PlayerText text, TextType type, optional<DCPTextTrack> track, DCPTimePeriod period)
 {
-       if (subs.text.empty ()) {
-               return;
+       vector<ReelWriter>::iterator* reel = 0;
+
+       switch (type) {
+       case TEXT_OPEN_SUBTITLE:
+               reel = &_subtitle_reel;
+               break;
+       case TEXT_CLOSED_CAPTION:
+               DCPOMATIC_ASSERT (track);
+               DCPOMATIC_ASSERT (_caption_reels.find(*track) != _caption_reels.end());
+               reel = &_caption_reels[*track];
+               break;
+       default:
+               DCPOMATIC_ASSERT (false);
        }
 
-       if (_subtitle_reel->period().to <= period.from) {
-               ++_subtitle_reel;
+       DCPOMATIC_ASSERT (*reel != _reels.end());
+       while ((*reel)->period().to <= period.from) {
+               ++(*reel);
+               DCPOMATIC_ASSERT (*reel != _reels.end());
        }
 
-       _subtitle_reel->write (subs);
+       (*reel)->write (text, type, track, period);
 }
 
 void
@@ -701,7 +730,9 @@ operator== (QueueItem const & a, QueueItem const & b)
 void
 Writer::set_encoder_threads (int threads)
 {
+       boost::mutex::scoped_lock lm (_state_mutex);
        _maximum_frames_in_memory = lrint (threads * Config::instance()->frames_in_memory_multiplier());
+       _maximum_queue_size = threads * 16;
 }
 
 void