Some fixes and logs.
[dcpomatic.git] / src / lib / encoder.cc
index efedfcfef76e18bd30923a3ca193ac25a19a3129..0d5fc1c6efbca6dd8a843a284b7dfde905d3959e 100644 (file)
@@ -24,6 +24,7 @@
 #include <iostream>
 #include <boost/filesystem.hpp>
 #include <boost/lexical_cast.hpp>
+#include <libdcp/picture_asset.h>
 #include "encoder.h"
 #include "util.h"
 #include "options.h"
@@ -34,6 +35,7 @@
 #include "config.h"
 #include "dcp_video_frame.h"
 #include "server.h"
+#include "format.h"
 #include "cross.h"
 
 using std::pair;
@@ -46,21 +48,26 @@ using std::make_pair;
 using namespace boost;
 
 int const Encoder::_history_size = 25;
+unsigned int const Encoder::_maximum_frames_in_memory = 8;
 
 /** @param f Film that we are encoding.
  *  @param o Options.
  */
-Encoder::Encoder (shared_ptr<const Film> f, shared_ptr<const EncodeOptions> o)
+Encoder::Encoder (shared_ptr<const Film> f)
        : _film (f)
-       , _opt (o)
        , _just_skipped (false)
-       , _video_frame (0)
-       , _audio_frame (0)
+       , _video_frames_in (0)
+       , _audio_frames_in (0)
+       , _video_frames_out (0)
+       , _audio_frames_out (0)
 #ifdef HAVE_SWRESAMPLE   
        , _swr_context (0)
-#endif   
-       , _audio_frames_written (0)
-       , _process_end (false)
+#endif
+       , _have_a_real_frame (false)
+       , _terminate_encoder (false)
+       , _writer_thread (0)
+       , _finish_writer (false)
+       , _last_written_frame (-1)
 {
        if (_film->audio_stream()) {
                /* Create sound output files with .tmp suffixes; we will rename
@@ -72,9 +79,9 @@ Encoder::Encoder (shared_ptr<const Film> f, shared_ptr<const EncodeOptions> o)
                        /* We write mono files */
                        sf_info.channels = 1;
                        sf_info.format = SF_FORMAT_WAV | SF_FORMAT_PCM_24;
-                       SNDFILE* f = sf_open (_opt->multichannel_audio_out_path (i, true).c_str (), SFM_WRITE, &sf_info);
+                       SNDFILE* f = sf_open (_film->multichannel_audio_out_path (i, true).c_str (), SFM_WRITE, &sf_info);
                        if (f == 0) {
-                               throw CreateFileError (_opt->multichannel_audio_out_path (i, true));
+                               throw CreateFileError (_film->multichannel_audio_out_path (i, true));
                        }
                        _sound_files.push_back (f);
                }
@@ -85,6 +92,7 @@ Encoder::~Encoder ()
 {
        close_sound_files ();
        terminate_worker_threads ();
+       finish_writer_thread ();
 }
 
 void
@@ -130,6 +138,19 @@ Encoder::process_begin ()
                        _worker_threads.push_back (new boost::thread (boost::bind (&Encoder::encoder_thread, this, *i)));
                }
        }
+
+       /* XXX! */
+       _picture_asset.reset (
+               new libdcp::MonoPictureAsset (
+                       _film->dir (_film->dcp_name()),
+                       String::compose ("video_%1.mxf", 0),
+                       DCPFrameRate (_film->frames_per_second()).frames_per_second,
+                       _film->format()->dcp_size()
+                       )
+               );
+       
+       _picture_asset_writer = _picture_asset->start_write ();
+       _writer_thread = new boost::thread (boost::bind (&Encoder::writer_thread, this));
 }
 
 
@@ -165,20 +186,20 @@ Encoder::process_end ()
                
                /* Rename .wav.tmp files to .wav */
                for (int i = 0; i < dcp_audio_channels (_film->audio_channels()); ++i) {
-                       if (boost::filesystem::exists (_opt->multichannel_audio_out_path (i, false))) {
-                               boost::filesystem::remove (_opt->multichannel_audio_out_path (i, false));
+                       if (boost::filesystem::exists (_film->multichannel_audio_out_path (i, false))) {
+                               boost::filesystem::remove (_film->multichannel_audio_out_path (i, false));
                        }
-                       boost::filesystem::rename (_opt->multichannel_audio_out_path (i, true), _opt->multichannel_audio_out_path (i, false));
+                       boost::filesystem::rename (_film->multichannel_audio_out_path (i, true), _film->multichannel_audio_out_path (i, false));
                }
        }
 
        boost::mutex::scoped_lock lock (_worker_mutex);
 
-       _film->log()->log ("Clearing queue of " + lexical_cast<string> (_queue.size ()));
+       _film->log()->log ("Clearing queue of " + lexical_cast<string> (_encode_queue.size ()));
 
        /* Keep waking workers until the queue is empty */
-       while (!_queue.empty ()) {
-               _film->log()->log ("Waking with " + lexical_cast<string> (_queue.size ()), Log::VERBOSE);
+       while (!_encode_queue.empty ()) {
+               _film->log()->log ("Waking with " + lexical_cast<string> (_encode_queue.size ()), Log::VERBOSE);
                _worker_condition.notify_all ();
                _worker_condition.wait (lock);
        }
@@ -187,7 +208,7 @@ Encoder::process_end ()
        
        terminate_worker_threads ();
 
-       _film->log()->log ("Mopping up " + lexical_cast<string> (_queue.size()));
+       _film->log()->log ("Mopping up " + lexical_cast<string> (_encode_queue.size()));
 
        /* The following sequence of events can occur in the above code:
             1. a remote worker takes the last image off the queue
@@ -198,22 +219,23 @@ Encoder::process_end ()
             So just mop up anything left in the queue here.
        */
 
-       for (list<shared_ptr<DCPVideoFrame> >::iterator i = _queue.begin(); i != _queue.end(); ++i) {
+       for (list<shared_ptr<DCPVideoFrame> >::iterator i = _encode_queue.begin(); i != _encode_queue.end(); ++i) {
                _film->log()->log (String::compose ("Encode left-over frame %1", (*i)->frame ()));
                try {
                        shared_ptr<EncodedData> e = (*i)->encode_locally ();
-                       e->write (_opt, (*i)->frame ());
+                       {
+                               boost::mutex::scoped_lock lock2 (_writer_mutex);
+                               _write_queue.push_back (make_pair (e, (*i)->frame ()));
+                               _writer_condition.notify_all ();
+                       }
                        frame_done ();
                } catch (std::exception& e) {
                        _film->log()->log (String::compose ("Local encode failed (%1)", e.what ()));
                }
        }
 
-       /* Now do links (or copies on windows) to duplicate frames */
-       for (list<pair<int, int> >::iterator i = _links_required.begin(); i != _links_required.end(); ++i) {
-               link (_opt->frame_out_path (i->first, false), _opt->frame_out_path (i->second, false));
-               link (_opt->hash_out_path (i->first, false), _opt->hash_out_path (i->second, false));
-       }
+       finish_writer_thread ();
+       _picture_asset_writer->finalize ();
 }      
 
 /** @return an estimate of the current number of frames we are encoding per second,
@@ -241,12 +263,12 @@ Encoder::skipping () const
        return _just_skipped;
 }
 
-/** @return Number of video frames that have been received */
-SourceFrame
-Encoder::video_frame () const
+/** @return Number of video frames that have been sent out */
+int
+Encoder::video_frames_out () const
 {
        boost::mutex::scoped_lock (_history_mutex);
-       return _video_frame;
+       return _video_frames_out;
 }
 
 /** Should be called when a frame has been encoded successfully.
@@ -279,91 +301,70 @@ Encoder::frame_skipped ()
 void
 Encoder::process_video (shared_ptr<Image> image, bool same, boost::shared_ptr<Subtitle> sub)
 {
-       if (_opt->video_skip != 0 && (_video_frame % _opt->video_skip) != 0) {
-               ++_video_frame;
+       DCPFrameRate dfr (_film->frames_per_second ());
+       
+       if (dfr.skip && (_video_frames_in % 2)) {
+               ++_video_frames_in;
                return;
        }
 
-       if (_opt->video_range) {
-               pair<SourceFrame, SourceFrame> const r = _opt->video_range.get();
-               if (_video_frame < r.first || _video_frame >= r.second) {
-                       ++_video_frame;
-                       return;
-               }
-       }
-
        boost::mutex::scoped_lock lock (_worker_mutex);
 
        /* Wait until the queue has gone down a bit */
-       while (_queue.size() >= _worker_threads.size() * 2 && !_process_end) {
-               TIMING ("decoder sleeps with queue of %1", _queue.size());
+       while (_encode_queue.size() >= _worker_threads.size() * 2 && !_terminate_encoder) {
+               TIMING ("decoder sleeps with queue of %1", _encode_queue.size());
                _worker_condition.wait (lock);
-               TIMING ("decoder wakes with queue of %1", _queue.size());
+               TIMING ("decoder wakes with queue of %1", _encode_queue.size());
        }
 
-       if (_process_end) {
+       if (_terminate_encoder) {
                return;
        }
 
        /* Only do the processing if we don't already have a file for this frame */
-       if (boost::filesystem::exists (_opt->frame_out_path (_video_frame, false))) {
+       if (boost::filesystem::exists (_film->frame_out_path (_video_frames_out, false))) {
                frame_skipped ();
                return;
        }
 
-       if (same && _last_real_frame) {
-               /* Use the last frame that we encoded.  We need to postpone doing the actual link,
-                  as on windows the link is really a copy and the reference frame might not have
-                  finished encoding yet.
+       if (same && _have_a_real_frame) {
+               /* Use the last frame that we encoded.  We do this by putting a null encoded
+                  frame straight onto the writer's queue.  It will know to duplicate the previous frame
+                  in this case.
                */
-               _links_required.push_back (make_pair (_last_real_frame.get(), _video_frame));
+               boost::mutex::scoped_lock lock2 (_writer_mutex);
+               _write_queue.push_back (make_pair (shared_ptr<EncodedData> (), _video_frames_out));
        } else {
                /* Queue this new frame for encoding */
                pair<string, string> const s = Filter::ffmpeg_strings (_film->filters());
-               TIMING ("adding to queue of %1", _queue.size ());
-               _queue.push_back (boost::shared_ptr<DCPVideoFrame> (
+               TIMING ("adding to queue of %1", _encode_queue.size ());
+               _encode_queue.push_back (boost::shared_ptr<DCPVideoFrame> (
                                          new DCPVideoFrame (
-                                                 image, sub, _opt->out_size, _opt->padding, _film->subtitle_offset(), _film->subtitle_scale(),
-                                                 _film->scaler(), _video_frame, _film->frames_per_second(), s.second,
+                                                 image, sub, _film->format()->dcp_size(), _film->format()->dcp_padding (_film),
+                                                 _film->subtitle_offset(), _film->subtitle_scale(),
+                                                 _film->scaler(), _video_frames_out, _film->frames_per_second(), s.second,
                                                  _film->colour_lut(), _film->j2k_bandwidth(),
                                                  _film->log()
                                                  )
                                          ));
                
                _worker_condition.notify_all ();
-               _last_real_frame = _video_frame;
+               _have_a_real_frame = true;
        }
 
-       ++_video_frame;
+       ++_video_frames_in;
+       ++_video_frames_out;
+
+       if (dfr.repeat) {
+               boost::mutex::scoped_lock lock2 (_writer_mutex);
+               _write_queue.push_back (make_pair (shared_ptr<EncodedData> (), _video_frames_out));
+               ++_video_frames_out;
+       }
 }
 
 void
 Encoder::process_audio (shared_ptr<AudioBuffers> data)
 {
-       if (_opt->audio_range) {
-               shared_ptr<AudioBuffers> trimmed (new AudioBuffers (*data.get ()));
-               
-               /* Range that we are encoding */
-               pair<int64_t, int64_t> required_range = _opt->audio_range.get();
-               /* Range of this block of data */
-               pair<int64_t, int64_t> this_range (_audio_frame, _audio_frame + trimmed->frames());
-
-               if (this_range.second < required_range.first || required_range.second < this_range.first) {
-                       /* No part of this audio is within the required range */
-                       return;
-               } else if (required_range.first >= this_range.first && required_range.first < this_range.second) {
-                       /* Trim start */
-                       int64_t const shift = required_range.first - this_range.first;
-                       trimmed->move (shift, 0, trimmed->frames() - shift);
-                       trimmed->set_frames (trimmed->frames() - shift);
-               } else if (required_range.second >= this_range.first && required_range.second < this_range.second) {
-                       /* Trim end */
-                       trimmed->set_frames (required_range.second - this_range.first);
-               }
-
-               data = trimmed;
-       }
-
 #if HAVE_SWRESAMPLE
        /* Maybe sample-rate convert */
        if (_swr_context) {
@@ -407,7 +408,7 @@ Encoder::process_audio (shared_ptr<AudioBuffers> data)
 
        write_audio (data);
        
-       _audio_frame += data->frames ();
+       _audio_frames_in += data->frames ();
 }
 
 void
@@ -417,7 +418,7 @@ Encoder::write_audio (shared_ptr<const AudioBuffers> audio)
                sf_write_float (_sound_files[i], audio->data(i), audio->frames());
        }
 
-       _audio_frames_written += audio->frames ();
+       _audio_frames_out += audio->frames ();
 }
 
 void
@@ -434,7 +435,7 @@ void
 Encoder::terminate_worker_threads ()
 {
        boost::mutex::scoped_lock lock (_worker_mutex);
-       _process_end = true;
+       _terminate_encoder = true;
        _worker_condition.notify_all ();
        lock.unlock ();
 
@@ -444,6 +445,23 @@ Encoder::terminate_worker_threads ()
        }
 }
 
+void
+Encoder::finish_writer_thread ()
+{
+       if (!_writer_thread) {
+               return;
+       }
+       
+       boost::mutex::scoped_lock lock (_writer_mutex);
+       _finish_writer = true;
+       _writer_condition.notify_all ();
+       lock.unlock ();
+
+       _writer_thread->join ();
+       delete _writer_thread;
+       _writer_thread = 0;
+}
+
 void
 Encoder::encoder_thread (ServerDescription* server)
 {
@@ -457,18 +475,18 @@ Encoder::encoder_thread (ServerDescription* server)
 
                TIMING ("encoder thread %1 sleeps", boost::this_thread::get_id());
                boost::mutex::scoped_lock lock (_worker_mutex);
-               while (_queue.empty () && !_process_end) {
+               while (_encode_queue.empty () && !_terminate_encoder) {
                        _worker_condition.wait (lock);
                }
 
-               if (_process_end) {
+               if (_terminate_encoder) {
                        return;
                }
 
-               TIMING ("encoder thread %1 wakes with queue of %2", boost::this_thread::get_id(), _queue.size());
-               boost::shared_ptr<DCPVideoFrame> vf = _queue.front ();
+               TIMING ("encoder thread %1 wakes with queue of %2", boost::this_thread::get_id(), _encode_queue.size());
+               boost::shared_ptr<DCPVideoFrame> vf = _encode_queue.front ();
                _film->log()->log (String::compose ("Encoder thread %1 pops frame %2 from queue", boost::this_thread::get_id(), vf->frame()), Log::VERBOSE);
-               _queue.pop_front ();
+               _encode_queue.pop_front ();
                
                lock.unlock ();
 
@@ -508,14 +526,15 @@ Encoder::encoder_thread (ServerDescription* server)
                }
 
                if (encoded) {
-                       encoded->write (_opt, vf->frame ());
-                       frame_done ();
+                       boost::mutex::scoped_lock lock2 (_writer_mutex);
+                       _write_queue.push_back (make_pair (encoded, vf->frame ()));
+                       _writer_condition.notify_all ();
                } else {
                        lock.lock ();
                        _film->log()->log (
                                String::compose ("Encoder thread %1 pushes frame %2 back onto queue after failure", boost::this_thread::get_id(), vf->frame())
                                );
-                       _queue.push_front (vf);
+                       _encode_queue.push_front (vf);
                        lock.unlock ();
                }
 
@@ -542,3 +561,95 @@ Encoder::link (string a, string b) const
        boost::filesystem::copy_file (a, b);
 #endif                 
 }
+
+struct WriteQueueSorter
+{
+       bool operator() (pair<shared_ptr<EncodedData>, int> const & a, pair<shared_ptr<EncodedData>, int> const & b) {
+               return a.second < b.second;
+       }
+};
+
+void
+Encoder::writer_thread ()
+{
+       while (1)
+       {
+               boost::mutex::scoped_lock lock (_writer_mutex);
+
+               while (1) {
+                       if (_finish_writer ||
+                           _write_queue.size() > _maximum_frames_in_memory ||
+                           (!_write_queue.empty() && _write_queue.front().second == (_last_written_frame + 1))) {
+                                   
+                                   break;
+                           }
+
+                           TIMING ("writer sleeps with a queue of %1; %2 pending", _write_queue.size(), _pending.size());
+                           _writer_condition.wait (lock);
+                           TIMING ("writer wakes with a queue of %1", _write_queue.size());
+
+                           _write_queue.sort (WriteQueueSorter ());
+               }
+
+               if (_finish_writer && _write_queue.empty() && _pending.empty()) {
+                       return;
+               }
+
+               /* Write any frames that we can write; i.e. those that are in sequence */
+               while (!_write_queue.empty() && _write_queue.front().second == (_last_written_frame + 1)) {
+                       pair<boost::shared_ptr<EncodedData>, int> encoded = _write_queue.front ();
+                       _write_queue.pop_front ();
+
+                       lock.unlock ();
+                       _film->log()->log (String::compose ("Writer writes %1 to MXF", encoded.second));
+                       if (encoded.first) {
+                               _picture_asset_writer->write (encoded.first->data(), encoded.first->size());
+                               _last_written = encoded.first;
+                       } else {
+                               _picture_asset_writer->write (_last_written->data(), _last_written->size());
+                       }
+                       lock.lock ();
+
+                       ++_last_written_frame;
+               }
+
+               while (_write_queue.size() > _maximum_frames_in_memory) {
+                       /* Too many frames in memory which can't yet be written to the stream.
+                          Put some to disk.
+                       */
+
+                       pair<boost::shared_ptr<EncodedData>, int> encoded = _write_queue.back ();
+                       _write_queue.pop_back ();
+                       if (!encoded.first) {
+                               /* This is a `repeat-last' frame, so no need to write it to disk */
+                               continue;
+                       }
+
+                       lock.unlock ();
+                       _film->log()->log (String::compose ("Writer full (awaiting %1); pushes %2 to disk", _last_written_frame + 1, encoded.second));
+                       encoded.first->write (_film, encoded.second);
+                       lock.lock ();
+
+                       _pending.push_back (encoded.second);
+               }
+
+               while (_write_queue.size() < _maximum_frames_in_memory && !_pending.empty()) {
+                       /* We have some space in memory.  Fetch some frames back off disk. */
+
+                       _pending.sort ();
+                       int const fetch = _pending.front ();
+
+                       lock.unlock ();
+                       _film->log()->log (String::compose ("Writer pulls %1 back from disk", fetch));
+                       shared_ptr<EncodedData> encoded;
+                       if (boost::filesystem::exists (_film->frame_out_path (fetch, false))) {
+                               /* It's an actual frame (not a repeat-last); load it in */
+                               encoded.reset (new EncodedData (_film->frame_out_path (fetch, false)));
+                       }
+                       lock.lock ();
+
+                       _write_queue.push_back (make_pair (encoded, fetch));
+                       _pending.remove (fetch);
+               }
+       }
+}