Logging improvements to allow prettier displays in the server GUI.
[dcpomatic.git] / src / lib / writer.cc
index 5c711ef9224db8c422198d65361feb002ebc7b71..0653daa57b497c820f76f27fc9f59c4a63b70b1f 100644 (file)
 #include <dcp/reel_subtitle_asset.h>
 #include <dcp/dcp.h>
 #include <dcp/cpl.h>
-#include <dcp/signer.h>
+#include <dcp/certificate_chain.h>
 #include <dcp/interop_subtitle_asset.h>
 #include <dcp/smpte_subtitle_asset.h>
 #include <boost/foreach.hpp>
 #include <fstream>
 #include <cerrno>
+#include <iostream>
 
 #include "i18n.h"
 
-#define LOG_GENERAL(...) _film->log()->log (String::compose (__VA_ARGS__), Log::TYPE_GENERAL);
-#define LOG_TIMING(...) _film->log()->microsecond_log (String::compose (__VA_ARGS__), Log::TYPE_TIMING);
-#define LOG_WARNING_NC(...) _film->log()->log (__VA_ARGS__, Log::TYPE_WARNING);
-#define LOG_WARNING(...) _film->log()->log (String::compose (__VA_ARGS__), Log::TYPE_WARNING);
-#define LOG_ERROR(...) _film->log()->log (String::compose (__VA_ARGS__), Log::TYPE_ERROR);
-#define LOG_DEBUG(...) _film->log()->log (String::compose (__VA_ARGS__), Log::TYPE_DEBUG);
-#define LOG_DEBUG_NC(...) _film->log()->log (__VA_ARGS__, Log::TYPE_DEBUG);
+#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
@@ -74,8 +75,10 @@ using boost::shared_ptr;
 using boost::weak_ptr;
 using boost::dynamic_pointer_cast;
 
-Writer::Writer (shared_ptr<const Film> f, weak_ptr<Job> j)
-       : _film (f)
+int const Writer::_info_size = 48;
+
+Writer::Writer (shared_ptr<const Film> film, weak_ptr<Job> j)
+       : _film (film)
        , _job (j)
        , _first_nonexistant_frame (0)
        , _thread (0)
@@ -118,7 +121,7 @@ Writer::Writer (shared_ptr<const Film> f, weak_ptr<Job> j)
 
        job->sub (_("Checking existing image data"));
        check_existing_picture_asset ();
-       
+
        _picture_asset_writer = _picture_asset->start_write (
                _film->internal_video_asset_dir() / _film->internal_video_asset_filename(),
                _film->interop() ? dcp::INTEROP : dcp::SMPTE,
@@ -133,7 +136,7 @@ Writer::Writer (shared_ptr<const Film> f, weak_ptr<Job> j)
                if (_film->encrypted ()) {
                        _sound_asset->set_key (_film->key ());
                }
-       
+
                /* Write the sound asset into the film directory so that we leave the creation
                   of the DCP directory until the last minute.
                */
@@ -144,15 +147,19 @@ Writer::Writer (shared_ptr<const Film> f, weak_ptr<Job> j)
        }
 
        /* Check that the signer is OK if we need one */
-       if (_film->is_signed() && !Config::instance()->signer()->valid ()) {
+       if (_film->is_signed() && !Config::instance()->signer_chain()->valid ()) {
                throw InvalidSignerError ();
        }
 
-       _thread = new boost::thread (boost::bind (&Writer::thread, this));
-
        job->sub (_("Encoding image data"));
 }
 
+void
+Writer::start ()
+{
+       _thread = new boost::thread (boost::bind (&Writer::thread, this));
+}
+
 Writer::~Writer ()
 {
        terminate_thread (false);
@@ -161,7 +168,7 @@ Writer::~Writer ()
 void
 Writer::write (Data encoded, int frame, Eyes eyes)
 {
-       boost::mutex::scoped_lock lock (_mutex);
+       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 */
@@ -194,7 +201,7 @@ Writer::write (Data encoded, int frame, Eyes eyes)
 void
 Writer::repeat (int frame, Eyes eyes)
 {
-       boost::mutex::scoped_lock lock (_mutex);
+       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 */
@@ -221,20 +228,20 @@ Writer::repeat (int frame, Eyes eyes)
 void
 Writer::fake_write (int frame, Eyes eyes)
 {
-       boost::mutex::scoped_lock lock (_mutex);
+       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 */
                _full_condition.wait (lock);
        }
-       
+
        FILE* file = fopen_boost (_film->info_file (), "rb");
        if (!file) {
                throw ReadFileError (_film->info_file ());
        }
        dcp::FrameInfo info = read_frame_info (file, frame, eyes);
        fclose (file);
-       
+
        QueueItem qi;
        qi.type = QueueItem::FAKE;
        qi.size = info.size;
@@ -295,7 +302,12 @@ Writer::have_sequenced_image_at_queue_head ()
 void
 Writer::write_frame_info (int frame, Eyes eyes, dcp::FrameInfo info) const
 {
-       FILE* file = fopen_boost (_film->info_file(), "ab");
+       FILE* file = 0;
+       if (boost::filesystem::exists (_film->info_file ())) {
+               file = fopen_boost (_film->info_file(), "r+b");
+       } else {
+               file = fopen_boost (_film->info_file(), "wb");
+       }
        if (!file) {
                throw OpenFileError (_film->info_file ());
        }
@@ -312,22 +324,19 @@ try
 {
        while (true)
        {
-               boost::mutex::scoped_lock lock (_mutex);
-
-               /* This is for debugging only */
-               bool done_something = false;
+               boost::mutex::scoped_lock lock (_state_mutex);
 
                while (true) {
-                       
+
                        if (_finish || _queued_full_in_memory > _maximum_frames_in_memory || have_sequenced_image_at_queue_head ()) {
                                /* We've got something to do: go and do it */
                                break;
                        }
 
                        /* Nothing to do: wait until something happens which may indicate that we do */
-                       LOG_TIMING (N_("writer sleeps with a queue of %1"), _queue.size());
+                       LOG_TIMING (N_("writer-sleep queue=%1"), _queue.size());
                        _empty_condition.wait (lock);
-                       LOG_TIMING (N_("writer wakes with a queue of %1"), _queue.size());
+                       LOG_TIMING (N_("writer-wake queue=%1"), _queue.size());
                }
 
                if (_finish && _queue.empty()) {
@@ -340,7 +349,6 @@ try
                   _finish is true).
                */
                if (_finish && (!have_sequenced_image_at_queue_head() || _queue.empty())) {
-                       done_something = true;
                        /* (Hopefully temporarily) log anything that was not written */
                        if (!_queue.empty() && !have_sequenced_image_at_queue_head()) {
                                LOG_WARNING (N_("Finishing writer with a left-over queue of %1:"), _queue.size());
@@ -349,7 +357,7 @@ try
                                                LOG_WARNING (N_("- type FULL, frame %1, eyes %2"), i->frame, i->eyes);
                                        } else {
                                                LOG_WARNING (N_("- type FAKE, size %1, frame %2, eyes %3"), i->size, i->frame, i->eyes);
-                                       }                                               
+                                       }
                                }
                                LOG_WARNING (N_("Last written frame %1, last written eyes %2"), _last_written_frame, _last_written_eyes);
                        }
@@ -357,7 +365,6 @@ try
                }
                /* Write any frames that we can write; i.e. those that are in sequence. */
                while (have_sequenced_image_at_queue_head ()) {
-                       done_something = true;
                        QueueItem qi = _queue.front ();
                        _queue.pop_front ();
                        if (qi.type == QueueItem::FULL && qi.encoded) {
@@ -368,7 +375,7 @@ try
                        switch (qi.type) {
                        case QueueItem::FULL:
                        {
-                               LOG_GENERAL (N_("Writer FULL-writes %1 (%2)"), qi.frame, qi.eyes);
+                               LOG_DEBUG_ENCODE (N_("Writer FULL-writes %1 (%2)"), qi.frame, qi.eyes);
                                if (!qi.encoded) {
                                        qi.encoded = Data (_film->j2c_path (qi.frame, qi.eyes, false));
                                }
@@ -380,13 +387,13 @@ try
                                break;
                        }
                        case QueueItem::FAKE:
-                               LOG_GENERAL (N_("Writer FAKE-writes %1"), qi.frame);
+                               LOG_DEBUG_ENCODE (N_("Writer FAKE-writes %1"), qi.frame);
                                _picture_asset_writer->fake_write (qi.size);
                                _last_written[qi.eyes].reset ();
                                ++_fake_written;
                                break;
                        case QueueItem::REPEAT:
-                               LOG_GENERAL (N_("Writer REPEAT-writes %1"), qi.frame);
+                               LOG_DEBUG_ENCODE (N_("Writer REPEAT-writes %1"), qi.frame);
                                dcp::FrameInfo fin = _picture_asset_writer->write (
                                        _last_written[qi.eyes]->data().get(),
                                        _last_written[qi.eyes]->size()
@@ -399,10 +406,10 @@ try
 
                        _last_written_frame = qi.frame;
                        _last_written_eyes = qi.eyes;
-                       
+
                        shared_ptr<Job> job = _job.lock ();
                        DCPOMATIC_ASSERT (job);
-                       int64_t total = _film->length().frames (_film->video_frame_rate ());
+                       int64_t total = _film->length().frames_round (_film->video_frame_rate ());
                        if (_film->three_d ()) {
                                /* _full_written and so on are incremented for each eye, so we need to double the total
                                   frames to get the correct progress.
@@ -410,12 +417,11 @@ try
                                total *= 2;
                        }
                        if (total) {
-                               job->set_progress (float (_full_written + _fake_written) / total);
+                               job->set_progress (float (_full_written + _fake_written + _repeat_written) / total);
                        }
                }
 
                while (_queued_full_in_memory > _maximum_frames_in_memory) {
-                       done_something = true;
                        /* Too many frames in memory which can't yet be written to the stream.
                           Write some FULL frames to disk.
                        */
@@ -443,20 +449,12 @@ try
                                );
 
                        i->encoded->write_via_temp (_film->j2c_path (i->frame, i->eyes, true), _film->j2c_path (i->frame, i->eyes, false));
-                       
+
                        lock.lock ();
                        i->encoded.reset ();
                        --_queued_full_in_memory;
                }
 
-               if (!done_something) {
-                       LOG_DEBUG_NC ("Writer loop ran without doing anything");
-                       LOG_DEBUG ("_queued_full_in_memory=%1", _queued_full_in_memory);
-                       LOG_DEBUG ("_queue_size=%1", _queue.size ());
-                       LOG_DEBUG ("_finish=%1", _finish);
-                       LOG_DEBUG ("_last_written_frame=%1", _last_written_frame);
-               }
-
                /* The queue has probably just gone down a bit; notify anything wait()ing on _full_condition */
                _full_condition.notify_all ();
        }
@@ -469,24 +467,25 @@ catch (...)
 void
 Writer::terminate_thread (bool can_throw)
 {
-       boost::mutex::scoped_lock lock (_mutex);
+       boost::mutex::scoped_lock lock (_state_mutex);
        if (_thread == 0) {
                return;
        }
-       
+
        _finish = true;
        _empty_condition.notify_all ();
        _full_condition.notify_all ();
        lock.unlock ();
 
+       DCPOMATIC_ASSERT (_thread->joinable ());
        _thread->join ();
        if (can_throw) {
                rethrow ();
        }
-       
+
        delete _thread;
        _thread = 0;
-}      
+}
 
 void
 Writer::finish ()
@@ -494,41 +493,49 @@ Writer::finish ()
        if (!_thread) {
                return;
        }
-       
+
        terminate_thread (true);
 
-       _picture_asset_writer->finalize ();
+       if (!_picture_asset_writer->finalize ()) {
+               /* Nothing was written to the picture asset */
+               _picture_asset.reset ();
+       }
+
        if (_sound_asset_writer) {
-               _sound_asset_writer->finalize ();
-       }
-       
-       /* Hard-link the video asset into the DCP */
-       boost::filesystem::path video_from = _picture_asset->file ();
-       
-       boost::filesystem::path video_to;
-       video_to /= _film->dir (_film->dcp_name());
-       video_to /= video_asset_filename (_picture_asset);
-
-       boost::system::error_code ec;
-       boost::filesystem::create_hard_link (video_from, video_to, ec);
-       if (ec) {
-               LOG_WARNING_NC ("Hard-link failed; copying instead");
-               boost::filesystem::copy_file (video_from, video_to, ec);
-               if (ec) {
-                       LOG_ERROR ("Failed to copy video file from %1 to %2 (%3)", video_from.string(), video_to.string(), ec.message ());
-                       throw FileError (ec.message(), video_from);
+               if (!_sound_asset_writer->finalize ()) {
+                       /* Nothing was written to the sound asset */
+                       _sound_asset.reset ();
                }
        }
 
-       _picture_asset->set_file (video_to);
+       /* Hard-link any video asset file into the DCP */
+       if (_picture_asset) {
+               boost::filesystem::path video_from = _picture_asset->file ();
+               boost::filesystem::path video_to;
+               video_to /= _film->dir (_film->dcp_name());
+               video_to /= video_asset_filename (_picture_asset);
 
-       /* Move the audio asset into the DCP */
+               boost::system::error_code ec;
+               boost::filesystem::create_hard_link (video_from, video_to, ec);
+               if (ec) {
+                       LOG_WARNING_NC ("Hard-link failed; copying instead");
+                       boost::filesystem::copy_file (video_from, video_to, ec);
+                       if (ec) {
+                               LOG_ERROR ("Failed to copy video file from %1 to %2 (%3)", video_from.string(), video_to.string(), ec.message ());
+                               throw FileError (ec.message(), video_from);
+                       }
+               }
+
+               _picture_asset->set_file (video_to);
+       }
 
+       /* Move the audio asset into the DCP */
        if (_sound_asset) {
                boost::filesystem::path audio_to;
                audio_to /= _film->dir (_film->dcp_name ());
                audio_to /= audio_asset_filename (_sound_asset);
-               
+
+               boost::system::error_code ec;
                boost::filesystem::rename (_film->file (audio_asset_filename (_sound_asset)), audio_to, ec);
                if (ec) {
                        throw FileError (
@@ -547,27 +554,58 @@ Writer::finish ()
                        _film->dcp_content_type()->libdcp_kind ()
                        )
                );
-       
+
        dcp.add (cpl);
 
        shared_ptr<dcp::Reel> reel (new dcp::Reel ());
 
-       shared_ptr<dcp::MonoPictureAsset> mono = dynamic_pointer_cast<dcp::MonoPictureAsset> (_picture_asset);
-       if (mono) {
-               reel->add (shared_ptr<dcp::ReelPictureAsset> (new dcp::ReelMonoPictureAsset (mono, 0)));
-       }
+       shared_ptr<dcp::ReelPictureAsset> reel_picture_asset;
+
+       if (_picture_asset) {
+               /* We have made a picture asset of our own.  Put it into the reel */
+               shared_ptr<dcp::MonoPictureAsset> mono = dynamic_pointer_cast<dcp::MonoPictureAsset> (_picture_asset);
+               if (mono) {
+                       reel_picture_asset.reset (new dcp::ReelMonoPictureAsset (mono, 0));
+               }
 
-       shared_ptr<dcp::StereoPictureAsset> stereo = dynamic_pointer_cast<dcp::StereoPictureAsset> (_picture_asset);
-       if (stereo) {
-               reel->add (shared_ptr<dcp::ReelPictureAsset> (new dcp::ReelStereoPictureAsset (stereo, 0)));
+               shared_ptr<dcp::StereoPictureAsset> stereo = dynamic_pointer_cast<dcp::StereoPictureAsset> (_picture_asset);
+               if (stereo && boost::filesystem::exists (stereo->file ())) {
+                       reel_picture_asset.reset (new dcp::ReelStereoPictureAsset (stereo, 0));
+               }
+       } else {
+               /* We don't have a picture asset of our own; maybe we need to reference one */
+               /* XXX: this is all a hack */
+               BOOST_FOREACH (shared_ptr<dcp::ReelAsset> i, _reel_assets) {
+                       shared_ptr<dcp::ReelPictureAsset> j = dynamic_pointer_cast<dcp::ReelPictureAsset> (i);
+                       if (j) {
+                               reel_picture_asset = j;
+                       }
+               }
        }
 
+       reel->add (reel_picture_asset);
+
        if (_sound_asset) {
+               /* We have made a sound asset of our own.  Put it into the reel */
                reel->add (shared_ptr<dcp::ReelSoundAsset> (new dcp::ReelSoundAsset (_sound_asset, 0)));
+       } else {
+               /* We don't have a sound asset of our own; maybe we need to reference one */
+               /* XXX: this is all a hack */
+               BOOST_FOREACH (shared_ptr<dcp::ReelAsset> i, _reel_assets) {
+                       if (dynamic_pointer_cast<dcp::ReelSoundAsset> (i)) {
+                               reel->add (i);
+                       }
+               }
        }
 
        if (_subtitle_asset) {
-               boost::filesystem::path const liberation = shared_path () / "LiberationSans-Regular.ttf";
+               boost::filesystem::path liberation;
+               try {
+                       liberation = shared_path () / "LiberationSans-Regular.ttf";
+               } catch (boost::filesystem::filesystem_error& e) {
+                       /* Hack: try the debian/ubuntu location if getting the shared path failed */
+                       liberation = "/usr/share/fonts/truetype/liberation/LiberationSans-Regular.ttf";
+               }
 
                /* Add all the fonts to the subtitle content */
                BOOST_FOREACH (shared_ptr<Font> i, _fonts) {
@@ -579,28 +617,45 @@ Writer::finish ()
                        boost::filesystem::create_directories (directory);
                        _subtitle_asset->write (directory / ("sub_" + _subtitle_asset->id() + ".xml"));
                } else {
+                       /* All our assets should be the same length; use the picture asset length here
+                          as a reference to set the subtitle one.
+                       */
+                       dynamic_pointer_cast<dcp::SMPTESubtitleAsset>(_subtitle_asset)->set_intrinsic_duration (
+                               reel_picture_asset->intrinsic_duration ()
+                               );
+
                        _subtitle_asset->write (
                                _film->dir (_film->dcp_name ()) / ("sub_" + _subtitle_asset->id() + ".mxf")
                                );
                }
-               
+
                reel->add (shared_ptr<dcp::ReelSubtitleAsset> (
                                   new dcp::ReelSubtitleAsset (
                                           _subtitle_asset,
                                           dcp::Fraction (_film->video_frame_rate(), 1),
-                                          _picture_asset->intrinsic_duration (),
+                                          reel_picture_asset->intrinsic_duration (),
                                           0
                                           )
                                   ));
+       } else {
+               /* We don't have a subtitle asset of our own; maybe we need to reference one */
+               /* XXX: this is all a hack */
+               BOOST_FOREACH (shared_ptr<dcp::ReelAsset> i, _reel_assets) {
+                       if (dynamic_pointer_cast<dcp::ReelSubtitleAsset> (i)) {
+                               reel->add (i);
+                       }
+               }
        }
-       
+
        cpl->add (reel);
 
        shared_ptr<Job> job = _job.lock ();
        DCPOMATIC_ASSERT (job);
 
        job->sub (_("Computing image digest"));
-       _picture_asset->hash (boost::bind (&Job::set_progress, job.get(), _1, false));
+       if (_picture_asset) {
+               _picture_asset->hash (boost::bind (&Job::set_progress, job.get(), _1, false));
+       }
 
        if (_sound_asset) {
                job->sub (_("Computing audio digest"));
@@ -608,13 +663,21 @@ Writer::finish ()
        }
 
        dcp::XMLMetadata meta;
+       meta.creator = Config::instance()->dcp_creator ();
+       if (meta.creator.empty ()) {
+               meta.creator = String::compose ("DCP-o-matic %1 %2", dcpomatic_version, dcpomatic_git_commit);
+       }
        meta.issuer = Config::instance()->dcp_issuer ();
-       meta.creator = String::compose ("DCP-o-matic %1 %2", dcpomatic_version, dcpomatic_git_commit);
+       if (meta.issuer.empty ()) {
+               meta.issuer = String::compose ("DCP-o-matic %1 %2", dcpomatic_version, dcpomatic_git_commit);
+       }
        meta.set_issue_date_now ();
 
-       shared_ptr<const dcp::Signer> signer;
+       cpl->set_metadata (meta);
+
+       shared_ptr<const dcp::CertificateChain> signer;
        if (_film->is_signed ()) {
-               signer = Config::instance()->signer ();
+               signer = Config::instance()->signer_chain ();
                /* We did check earlier, but check again here to be on the safe side */
                if (!signer->valid ()) {
                        throw InvalidSignerError ();
@@ -628,77 +691,73 @@ Writer::finish ()
                );
 }
 
-bool
-Writer::check_existing_picture_asset_frame (FILE* asset, int f, Eyes eyes)
-{
-       /* Read the frame info as written */
-       FILE* file = fopen_boost (_film->info_file (), "rb");
-       if (!file) {
-               LOG_GENERAL ("Existing frame %1 has no info file", f);
-               return false;
-       }
-       
-       dcp::FrameInfo info = read_frame_info (file, f, eyes);
-       fclose (file);
-       if (info.size == 0) {
-               LOG_GENERAL ("Existing frame %1 has no info file", f);
-               return false;
-       }
-       
-       /* Read the data from the asset and hash it */
-       dcpomatic_fseek (asset, info.offset, SEEK_SET);
-       Data data (info.size);
-       size_t const read = fread (data.data().get(), 1, data.size(), asset);
-       if (read != static_cast<size_t> (data.size ())) {
-               LOG_GENERAL ("Existing frame %1 is incomplete", f);
-               return false;
-       }
-
-       MD5Digester digester;
-       digester.add (data.data().get(), data.size());
-       if (digester.get() != info.hash) {
-               LOG_GENERAL ("Existing frame %1 failed hash check", f);
-               return false;
-       }
-
-       return true;
-}
-
 void
 Writer::check_existing_picture_asset ()
 {
        /* Try to open the existing asset */
-       FILE* asset = fopen_boost (_picture_asset->file(), "rb");
-       if (!asset) {
+       FILE* asset_file = fopen_boost (_picture_asset->file(), "rb");
+       if (!asset_file) {
                LOG_GENERAL ("Could not open existing asset at %1 (errno=%2)", _picture_asset->file().string(), errno);
                return;
        }
 
-       while (true) {
+       /* Offset of the last dcp::FrameInfo in the info file */
+       int const n = (boost::filesystem::file_size (_film->info_file ()) / _info_size) - 1;
 
-               shared_ptr<Job> job = _job.lock ();
-               DCPOMATIC_ASSERT (job);
+       FILE* info_file = fopen_boost (_film->info_file (), "rb");
+       if (!info_file) {
+               LOG_GENERAL_NC ("Could not open film info file");
+               fclose (asset_file);
+               return;
+       }
 
-               job->set_progress_unknown ();
+       if (_film->three_d ()) {
+               /* Start looking at the last left frame */
+               _first_nonexistant_frame = n / 2;
+       } else {
+               _first_nonexistant_frame = n;
+       }
 
-               if (_film->three_d ()) {
-                       if (!check_existing_picture_asset_frame (asset, _first_nonexistant_frame, EYES_LEFT)) {
-                               break;
-                       }
-                       if (!check_existing_picture_asset_frame (asset, _first_nonexistant_frame, EYES_RIGHT)) {
-                               break;
-                       }
+       bool ok = false;
+
+       while (!ok) {
+               /* Read the data from the info file; for 3D we just check the left
+                  frames until we find a good one.
+               */
+               dcp::FrameInfo info = read_frame_info (info_file, _first_nonexistant_frame, _film->three_d () ? EYES_LEFT : EYES_BOTH);
+
+               ok = true;
+
+               /* Read the data from the asset and hash it */
+               dcpomatic_fseek (asset_file, info.offset, SEEK_SET);
+               Data data (info.size);
+               size_t const read = fread (data.data().get(), 1, data.size(), asset_file);
+               if (read != static_cast<size_t> (data.size ())) {
+                       LOG_GENERAL ("Existing frame %1 is incomplete", _first_nonexistant_frame);
+                       ok = false;
                } else {
-                       if (!check_existing_picture_asset_frame (asset, _first_nonexistant_frame, EYES_BOTH)) {
-                               break;
+                       MD5Digester digester;
+                       digester.add (data.data().get(), data.size());
+                       if (digester.get() != info.hash) {
+                               LOG_GENERAL ("Existing frame %1 failed hash check", _first_nonexistant_frame);
+                               ok = false;
                        }
                }
 
-               LOG_GENERAL ("Have existing frame %1", _first_nonexistant_frame);
+               if (!ok) {
+                       --_first_nonexistant_frame;
+               }
+       }
+
+       if (!_film->three_d ()) {
+               /* If we are doing 3D we might have found a good L frame with no R, so only
+                  do this if we're in 2D and we've just found a good B(oth) frame.
+               */
                ++_first_nonexistant_frame;
        }
 
-       fclose (asset);
+       fclose (asset_file);
+       fclose (info_file);
 }
 
 /** @param frame Frame index.
@@ -736,11 +795,13 @@ Writer::write (PlayerSubtitles subs)
                        s->set_content_title_text (_film->name ());
                        s->set_language (lang);
                        s->set_edit_rate (dcp::Fraction (_film->video_frame_rate (), 1));
+                       s->set_reel_number (1);
                        s->set_time_code_rate (_film->video_frame_rate ());
+                       s->set_start_time (dcp::Time ());
                        _subtitle_asset = s;
-               }                       
+               }
        }
-       
+
        for (list<dcp::SubtitleString>::const_iterator i = subs.text.begin(); i != subs.text.end(); ++i) {
                _subtitle_asset->add (*i);
        }
@@ -772,25 +833,22 @@ operator== (QueueItem const & a, QueueItem const & b)
 void
 Writer::set_encoder_threads (int threads)
 {
-       _maximum_frames_in_memory = rint (threads * 1.1);
+       _maximum_frames_in_memory = lrint (threads * 1.1);
 }
 
 long
 Writer::frame_info_position (int frame, Eyes eyes) const
 {
-       static int const info_size = 48;
-       
        switch (eyes) {
        case EYES_BOTH:
-               return frame * info_size;
+               return frame * _info_size;
        case EYES_LEFT:
-               return frame * info_size * 2;
+               return frame * _info_size * 2;
        case EYES_RIGHT:
-               return frame * info_size * 2 + info_size;
+               return frame * _info_size * 2 + _info_size;
        default:
                DCPOMATIC_ASSERT (false);
        }
-       
 
        DCPOMATIC_ASSERT (false);
 }
@@ -802,7 +860,7 @@ Writer::read_frame_info (FILE* file, int frame, Eyes eyes) const
        dcpomatic_fseek (file, frame_info_position (frame, eyes), SEEK_SET);
        fread (&info.offset, sizeof (info.offset), 1, file);
        fread (&info.size, sizeof (info.size), 1, file);
-       
+
        char hash_buffer[33];
        fread (hash_buffer, 1, 32, file);
        hash_buffer[32] = '\0';
@@ -810,3 +868,9 @@ Writer::read_frame_info (FILE* file, int frame, Eyes eyes) const
 
        return info;
 }
+
+void
+Writer::write (shared_ptr<dcp::ReelAsset> asset)
+{
+       _reel_assets.push_back (asset);
+}