X-Git-Url: https://main.carlh.net/gitweb/?p=dcpomatic.git;a=blobdiff_plain;f=src%2Flib%2Fwriter.cc;h=0653daa57b497c820f76f27fc9f59c4a63b70b1f;hp=5c711ef9224db8c422198d65361feb002ebc7b71;hb=aeb835a18c8df347e0ed68fb24631b320abeb611;hpb=7cd7b360169493d864206e2cdfb4f688cf5a12cf diff --git a/src/lib/writer.cc b/src/lib/writer.cc index 5c711ef92..0653daa57 100644 --- a/src/lib/writer.cc +++ b/src/lib/writer.cc @@ -45,22 +45,23 @@ #include #include #include -#include +#include #include #include #include #include #include +#include #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 f, weak_ptr j) - : _film (f) +int const Writer::_info_size = 48; + +Writer::Writer (shared_ptr film, weak_ptr j) + : _film (film) , _job (j) , _first_nonexistant_frame (0) , _thread (0) @@ -118,7 +121,7 @@ Writer::Writer (shared_ptr f, weak_ptr 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 f, weak_ptr 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 f, weak_ptr 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.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 reel (new dcp::Reel ()); - shared_ptr mono = dynamic_pointer_cast (_picture_asset); - if (mono) { - reel->add (shared_ptr (new dcp::ReelMonoPictureAsset (mono, 0))); - } + shared_ptr reel_picture_asset; + + if (_picture_asset) { + /* We have made a picture asset of our own. Put it into the reel */ + shared_ptr mono = dynamic_pointer_cast (_picture_asset); + if (mono) { + reel_picture_asset.reset (new dcp::ReelMonoPictureAsset (mono, 0)); + } - shared_ptr stereo = dynamic_pointer_cast (_picture_asset); - if (stereo) { - reel->add (shared_ptr (new dcp::ReelStereoPictureAsset (stereo, 0))); + shared_ptr stereo = dynamic_pointer_cast (_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 i, _reel_assets) { + shared_ptr j = dynamic_pointer_cast (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 (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 i, _reel_assets) { + if (dynamic_pointer_cast (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 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(_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 ( 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 i, _reel_assets) { + if (dynamic_pointer_cast (i)) { + reel->add (i); + } + } } - + cpl->add (reel); shared_ptr 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 signer; + cpl->set_metadata (meta); + + shared_ptr 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 (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.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 (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::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 asset) +{ + _reel_assets.push_back (asset); +}