Logging improvements to allow prettier displays in the server GUI.
[dcpomatic.git] / src / lib / writer.cc
1 /*
2     Copyright (C) 2012-2015 Carl Hetherington <cth@carlh.net>
3
4     This program is free software; you can redistribute it and/or modify
5     it under the terms of the GNU General Public License as published by
6     the Free Software Foundation; either version 2 of the License, or
7     (at your option) any later version.
8
9     This program is distributed in the hope that it will be useful,
10     but WITHOUT ANY WARRANTY; without even the implied warranty of
11     MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
12     GNU General Public License for more details.
13
14     You should have received a copy of the GNU General Public License
15     along with this program; if not, write to the Free Software
16     Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA.
17
18 */
19
20 #include "writer.h"
21 #include "compose.hpp"
22 #include "film.h"
23 #include "ratio.h"
24 #include "log.h"
25 #include "dcp_video.h"
26 #include "dcp_content_type.h"
27 #include "audio_mapping.h"
28 #include "config.h"
29 #include "job.h"
30 #include "cross.h"
31 #include "audio_buffers.h"
32 #include "md5_digester.h"
33 #include "data.h"
34 #include "version.h"
35 #include "font.h"
36 #include "util.h"
37 #include <dcp/mono_picture_asset.h>
38 #include <dcp/stereo_picture_asset.h>
39 #include <dcp/sound_asset.h>
40 #include <dcp/sound_asset_writer.h>
41 #include <dcp/reel.h>
42 #include <dcp/reel_mono_picture_asset.h>
43 #include <dcp/reel_stereo_picture_asset.h>
44 #include <dcp/reel_sound_asset.h>
45 #include <dcp/reel_subtitle_asset.h>
46 #include <dcp/dcp.h>
47 #include <dcp/cpl.h>
48 #include <dcp/certificate_chain.h>
49 #include <dcp/interop_subtitle_asset.h>
50 #include <dcp/smpte_subtitle_asset.h>
51 #include <boost/foreach.hpp>
52 #include <fstream>
53 #include <cerrno>
54 #include <iostream>
55
56 #include "i18n.h"
57
58 #define LOG_GENERAL(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_GENERAL);
59 #define LOG_GENERAL_NC(...) _film->log()->log (__VA_ARGS__, LogEntry::TYPE_GENERAL);
60 #define LOG_DEBUG_ENCODE(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_DEBUG_ENCODE);
61 #define LOG_TIMING(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_TIMING);
62 #define LOG_WARNING_NC(...) _film->log()->log (__VA_ARGS__, LogEntry::TYPE_WARNING);
63 #define LOG_WARNING(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_WARNING);
64 #define LOG_ERROR(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_ERROR);
65
66 /* OS X strikes again */
67 #undef set_key
68
69 using std::make_pair;
70 using std::pair;
71 using std::string;
72 using std::list;
73 using std::cout;
74 using boost::shared_ptr;
75 using boost::weak_ptr;
76 using boost::dynamic_pointer_cast;
77
78 int const Writer::_info_size = 48;
79
80 Writer::Writer (shared_ptr<const Film> film, weak_ptr<Job> j)
81         : _film (film)
82         , _job (j)
83         , _first_nonexistant_frame (0)
84         , _thread (0)
85         , _finish (false)
86         , _queued_full_in_memory (0)
87         , _last_written_frame (-1)
88         , _last_written_eyes (EYES_RIGHT)
89         , _maximum_frames_in_memory (0)
90         , _full_written (0)
91         , _fake_written (0)
92         , _repeat_written (0)
93         , _pushed_to_disk (0)
94 {
95         /* Remove any old DCP */
96         boost::filesystem::remove_all (_film->dir (_film->dcp_name ()));
97
98         shared_ptr<Job> job = _job.lock ();
99         DCPOMATIC_ASSERT (job);
100
101         /* Create our picture asset in a subdirectory, named according to those
102            film's parameters which affect the video output.  We will hard-link
103            it into the DCP later.
104         */
105
106         if (_film->three_d ()) {
107                 _picture_asset.reset (new dcp::StereoPictureAsset (dcp::Fraction (_film->video_frame_rate (), 1)));
108         } else {
109                 _picture_asset.reset (new dcp::MonoPictureAsset (dcp::Fraction (_film->video_frame_rate (), 1)));
110         }
111
112         _picture_asset->set_size (_film->frame_size ());
113
114         if (_film->encrypted ()) {
115                 _picture_asset->set_key (_film->key ());
116         }
117
118         _picture_asset->set_file (
119                 _film->internal_video_asset_dir() / _film->internal_video_asset_filename()
120                 );
121
122         job->sub (_("Checking existing image data"));
123         check_existing_picture_asset ();
124
125         _picture_asset_writer = _picture_asset->start_write (
126                 _film->internal_video_asset_dir() / _film->internal_video_asset_filename(),
127                 _film->interop() ? dcp::INTEROP : dcp::SMPTE,
128                 _first_nonexistant_frame > 0
129                 );
130
131         if (_film->audio_channels ()) {
132                 _sound_asset.reset (
133                         new dcp::SoundAsset (dcp::Fraction (_film->video_frame_rate(), 1), _film->audio_frame_rate (), _film->audio_channels ())
134                         );
135
136                 if (_film->encrypted ()) {
137                         _sound_asset->set_key (_film->key ());
138                 }
139
140                 /* Write the sound asset into the film directory so that we leave the creation
141                    of the DCP directory until the last minute.
142                 */
143                 _sound_asset_writer = _sound_asset->start_write (
144                         _film->directory() / audio_asset_filename (_sound_asset),
145                         _film->interop() ? dcp::INTEROP : dcp::SMPTE
146                         );
147         }
148
149         /* Check that the signer is OK if we need one */
150         if (_film->is_signed() && !Config::instance()->signer_chain()->valid ()) {
151                 throw InvalidSignerError ();
152         }
153
154         job->sub (_("Encoding image data"));
155 }
156
157 void
158 Writer::start ()
159 {
160         _thread = new boost::thread (boost::bind (&Writer::thread, this));
161 }
162
163 Writer::~Writer ()
164 {
165         terminate_thread (false);
166 }
167
168 void
169 Writer::write (Data encoded, int frame, Eyes eyes)
170 {
171         boost::mutex::scoped_lock lock (_state_mutex);
172
173         while (_queued_full_in_memory > _maximum_frames_in_memory) {
174                 /* The queue is too big; wait until that is sorted out */
175                 _full_condition.wait (lock);
176         }
177
178         QueueItem qi;
179         qi.type = QueueItem::FULL;
180         qi.encoded = encoded;
181         qi.frame = frame;
182
183         if (_film->three_d() && eyes == EYES_BOTH) {
184                 /* 2D material in a 3D DCP; fake the 3D */
185                 qi.eyes = EYES_LEFT;
186                 _queue.push_back (qi);
187                 ++_queued_full_in_memory;
188                 qi.eyes = EYES_RIGHT;
189                 _queue.push_back (qi);
190                 ++_queued_full_in_memory;
191         } else {
192                 qi.eyes = eyes;
193                 _queue.push_back (qi);
194                 ++_queued_full_in_memory;
195         }
196
197         /* Now there's something to do: wake anything wait()ing on _empty_condition */
198         _empty_condition.notify_all ();
199 }
200
201 void
202 Writer::repeat (int frame, Eyes eyes)
203 {
204         boost::mutex::scoped_lock lock (_state_mutex);
205
206         while (_queued_full_in_memory > _maximum_frames_in_memory) {
207                 /* The queue is too big; wait until that is sorted out */
208                 _full_condition.wait (lock);
209         }
210
211         QueueItem qi;
212         qi.type = QueueItem::REPEAT;
213         qi.frame = frame;
214         if (_film->three_d() && eyes == EYES_BOTH) {
215                 qi.eyes = EYES_LEFT;
216                 _queue.push_back (qi);
217                 qi.eyes = EYES_RIGHT;
218                 _queue.push_back (qi);
219         } else {
220                 qi.eyes = eyes;
221                 _queue.push_back (qi);
222         }
223
224         /* Now there's something to do: wake anything wait()ing on _empty_condition */
225         _empty_condition.notify_all ();
226 }
227
228 void
229 Writer::fake_write (int frame, Eyes eyes)
230 {
231         boost::mutex::scoped_lock lock (_state_mutex);
232
233         while (_queued_full_in_memory > _maximum_frames_in_memory) {
234                 /* The queue is too big; wait until that is sorted out */
235                 _full_condition.wait (lock);
236         }
237
238         FILE* file = fopen_boost (_film->info_file (), "rb");
239         if (!file) {
240                 throw ReadFileError (_film->info_file ());
241         }
242         dcp::FrameInfo info = read_frame_info (file, frame, eyes);
243         fclose (file);
244
245         QueueItem qi;
246         qi.type = QueueItem::FAKE;
247         qi.size = info.size;
248         qi.frame = frame;
249         if (_film->three_d() && eyes == EYES_BOTH) {
250                 qi.eyes = EYES_LEFT;
251                 _queue.push_back (qi);
252                 qi.eyes = EYES_RIGHT;
253                 _queue.push_back (qi);
254         } else {
255                 qi.eyes = eyes;
256                 _queue.push_back (qi);
257         }
258
259         /* Now there's something to do: wake anything wait()ing on _empty_condition */
260         _empty_condition.notify_all ();
261 }
262
263 /** This method is not thread safe */
264 void
265 Writer::write (shared_ptr<const AudioBuffers> audio)
266 {
267         if (_sound_asset_writer) {
268                 _sound_asset_writer->write (audio->data(), audio->frames());
269         }
270 }
271
272 /** This must be called from Writer::thread() with an appropriate lock held */
273 bool
274 Writer::have_sequenced_image_at_queue_head ()
275 {
276         if (_queue.empty ()) {
277                 return false;
278         }
279
280         _queue.sort ();
281
282         /* The queue should contain only EYES_LEFT/EYES_RIGHT pairs or EYES_BOTH */
283
284         if (_queue.front().eyes == EYES_BOTH) {
285                 /* 2D */
286                 return _queue.front().frame == (_last_written_frame + 1);
287         }
288
289         /* 3D */
290
291         if (_last_written_eyes == EYES_LEFT && _queue.front().frame == _last_written_frame && _queue.front().eyes == EYES_RIGHT) {
292                 return true;
293         }
294
295         if (_last_written_eyes == EYES_RIGHT && _queue.front().frame == (_last_written_frame + 1) && _queue.front().eyes == EYES_LEFT) {
296                 return true;
297         }
298
299         return false;
300 }
301
302 void
303 Writer::write_frame_info (int frame, Eyes eyes, dcp::FrameInfo info) const
304 {
305         FILE* file = 0;
306         if (boost::filesystem::exists (_film->info_file ())) {
307                 file = fopen_boost (_film->info_file(), "r+b");
308         } else {
309                 file = fopen_boost (_film->info_file(), "wb");
310         }
311         if (!file) {
312                 throw OpenFileError (_film->info_file ());
313         }
314         dcpomatic_fseek (file, frame_info_position (frame, eyes), SEEK_SET);
315         fwrite (&info.offset, sizeof (info.offset), 1, file);
316         fwrite (&info.size, sizeof (info.size), 1, file);
317         fwrite (info.hash.c_str(), 1, info.hash.size(), file);
318         fclose (file);
319 }
320
321 void
322 Writer::thread ()
323 try
324 {
325         while (true)
326         {
327                 boost::mutex::scoped_lock lock (_state_mutex);
328
329                 while (true) {
330
331                         if (_finish || _queued_full_in_memory > _maximum_frames_in_memory || have_sequenced_image_at_queue_head ()) {
332                                 /* We've got something to do: go and do it */
333                                 break;
334                         }
335
336                         /* Nothing to do: wait until something happens which may indicate that we do */
337                         LOG_TIMING (N_("writer-sleep queue=%1"), _queue.size());
338                         _empty_condition.wait (lock);
339                         LOG_TIMING (N_("writer-wake queue=%1"), _queue.size());
340                 }
341
342                 if (_finish && _queue.empty()) {
343                         return;
344                 }
345
346                 /* We stop here if we have been asked to finish, and if either the queue
347                    is empty or we do not have a sequenced image at its head (if this is the
348                    case we will never terminate as no new frames will be sent once
349                    _finish is true).
350                 */
351                 if (_finish && (!have_sequenced_image_at_queue_head() || _queue.empty())) {
352                         /* (Hopefully temporarily) log anything that was not written */
353                         if (!_queue.empty() && !have_sequenced_image_at_queue_head()) {
354                                 LOG_WARNING (N_("Finishing writer with a left-over queue of %1:"), _queue.size());
355                                 for (list<QueueItem>::const_iterator i = _queue.begin(); i != _queue.end(); ++i) {
356                                         if (i->type == QueueItem::FULL) {
357                                                 LOG_WARNING (N_("- type FULL, frame %1, eyes %2"), i->frame, i->eyes);
358                                         } else {
359                                                 LOG_WARNING (N_("- type FAKE, size %1, frame %2, eyes %3"), i->size, i->frame, i->eyes);
360                                         }
361                                 }
362                                 LOG_WARNING (N_("Last written frame %1, last written eyes %2"), _last_written_frame, _last_written_eyes);
363                         }
364                         return;
365                 }
366                 /* Write any frames that we can write; i.e. those that are in sequence. */
367                 while (have_sequenced_image_at_queue_head ()) {
368                         QueueItem qi = _queue.front ();
369                         _queue.pop_front ();
370                         if (qi.type == QueueItem::FULL && qi.encoded) {
371                                 --_queued_full_in_memory;
372                         }
373
374                         lock.unlock ();
375                         switch (qi.type) {
376                         case QueueItem::FULL:
377                         {
378                                 LOG_DEBUG_ENCODE (N_("Writer FULL-writes %1 (%2)"), qi.frame, qi.eyes);
379                                 if (!qi.encoded) {
380                                         qi.encoded = Data (_film->j2c_path (qi.frame, qi.eyes, false));
381                                 }
382
383                                 dcp::FrameInfo fin = _picture_asset_writer->write (qi.encoded->data().get (), qi.encoded->size());
384                                 write_frame_info (qi.frame, qi.eyes, fin);
385                                 _last_written[qi.eyes] = qi.encoded;
386                                 ++_full_written;
387                                 break;
388                         }
389                         case QueueItem::FAKE:
390                                 LOG_DEBUG_ENCODE (N_("Writer FAKE-writes %1"), qi.frame);
391                                 _picture_asset_writer->fake_write (qi.size);
392                                 _last_written[qi.eyes].reset ();
393                                 ++_fake_written;
394                                 break;
395                         case QueueItem::REPEAT:
396                                 LOG_DEBUG_ENCODE (N_("Writer REPEAT-writes %1"), qi.frame);
397                                 dcp::FrameInfo fin = _picture_asset_writer->write (
398                                         _last_written[qi.eyes]->data().get(),
399                                         _last_written[qi.eyes]->size()
400                                         );
401                                 write_frame_info (qi.frame, qi.eyes, fin);
402                                 ++_repeat_written;
403                                 break;
404                         }
405                         lock.lock ();
406
407                         _last_written_frame = qi.frame;
408                         _last_written_eyes = qi.eyes;
409
410                         shared_ptr<Job> job = _job.lock ();
411                         DCPOMATIC_ASSERT (job);
412                         int64_t total = _film->length().frames_round (_film->video_frame_rate ());
413                         if (_film->three_d ()) {
414                                 /* _full_written and so on are incremented for each eye, so we need to double the total
415                                    frames to get the correct progress.
416                                 */
417                                 total *= 2;
418                         }
419                         if (total) {
420                                 job->set_progress (float (_full_written + _fake_written + _repeat_written) / total);
421                         }
422                 }
423
424                 while (_queued_full_in_memory > _maximum_frames_in_memory) {
425                         /* Too many frames in memory which can't yet be written to the stream.
426                            Write some FULL frames to disk.
427                         */
428
429                         /* Find one from the back of the queue */
430                         _queue.sort ();
431                         list<QueueItem>::reverse_iterator i = _queue.rbegin ();
432                         while (i != _queue.rend() && (i->type != QueueItem::FULL || !i->encoded)) {
433                                 ++i;
434                         }
435
436                         DCPOMATIC_ASSERT (i != _queue.rend());
437                         ++_pushed_to_disk;
438                         lock.unlock ();
439
440                         /* i is valid here, even though we don't hold a lock on the mutex,
441                            since list iterators are unaffected by insertion and only this
442                            thread could erase the last item in the list.
443                         */
444
445                         LOG_GENERAL (
446                                 "Writer full (awaiting %1 [last eye was %2]); pushes %3 to disk",
447                                 _last_written_frame + 1,
448                                 _last_written_eyes, i->frame
449                                 );
450
451                         i->encoded->write_via_temp (_film->j2c_path (i->frame, i->eyes, true), _film->j2c_path (i->frame, i->eyes, false));
452
453                         lock.lock ();
454                         i->encoded.reset ();
455                         --_queued_full_in_memory;
456                 }
457
458                 /* The queue has probably just gone down a bit; notify anything wait()ing on _full_condition */
459                 _full_condition.notify_all ();
460         }
461 }
462 catch (...)
463 {
464         store_current ();
465 }
466
467 void
468 Writer::terminate_thread (bool can_throw)
469 {
470         boost::mutex::scoped_lock lock (_state_mutex);
471         if (_thread == 0) {
472                 return;
473         }
474
475         _finish = true;
476         _empty_condition.notify_all ();
477         _full_condition.notify_all ();
478         lock.unlock ();
479
480         DCPOMATIC_ASSERT (_thread->joinable ());
481         _thread->join ();
482         if (can_throw) {
483                 rethrow ();
484         }
485
486         delete _thread;
487         _thread = 0;
488 }
489
490 void
491 Writer::finish ()
492 {
493         if (!_thread) {
494                 return;
495         }
496
497         terminate_thread (true);
498
499         if (!_picture_asset_writer->finalize ()) {
500                 /* Nothing was written to the picture asset */
501                 _picture_asset.reset ();
502         }
503
504         if (_sound_asset_writer) {
505                 if (!_sound_asset_writer->finalize ()) {
506                         /* Nothing was written to the sound asset */
507                         _sound_asset.reset ();
508                 }
509         }
510
511         /* Hard-link any video asset file into the DCP */
512         if (_picture_asset) {
513                 boost::filesystem::path video_from = _picture_asset->file ();
514                 boost::filesystem::path video_to;
515                 video_to /= _film->dir (_film->dcp_name());
516                 video_to /= video_asset_filename (_picture_asset);
517
518                 boost::system::error_code ec;
519                 boost::filesystem::create_hard_link (video_from, video_to, ec);
520                 if (ec) {
521                         LOG_WARNING_NC ("Hard-link failed; copying instead");
522                         boost::filesystem::copy_file (video_from, video_to, ec);
523                         if (ec) {
524                                 LOG_ERROR ("Failed to copy video file from %1 to %2 (%3)", video_from.string(), video_to.string(), ec.message ());
525                                 throw FileError (ec.message(), video_from);
526                         }
527                 }
528
529                 _picture_asset->set_file (video_to);
530         }
531
532         /* Move the audio asset into the DCP */
533         if (_sound_asset) {
534                 boost::filesystem::path audio_to;
535                 audio_to /= _film->dir (_film->dcp_name ());
536                 audio_to /= audio_asset_filename (_sound_asset);
537
538                 boost::system::error_code ec;
539                 boost::filesystem::rename (_film->file (audio_asset_filename (_sound_asset)), audio_to, ec);
540                 if (ec) {
541                         throw FileError (
542                                 String::compose (_("could not move audio asset into the DCP (%1)"), ec.value ()), audio_asset_filename (_sound_asset)
543                                 );
544                 }
545
546                 _sound_asset->set_file (audio_to);
547         }
548
549         dcp::DCP dcp (_film->dir (_film->dcp_name()));
550
551         shared_ptr<dcp::CPL> cpl (
552                 new dcp::CPL (
553                         _film->dcp_name(),
554                         _film->dcp_content_type()->libdcp_kind ()
555                         )
556                 );
557
558         dcp.add (cpl);
559
560         shared_ptr<dcp::Reel> reel (new dcp::Reel ());
561
562         shared_ptr<dcp::ReelPictureAsset> reel_picture_asset;
563
564         if (_picture_asset) {
565                 /* We have made a picture asset of our own.  Put it into the reel */
566                 shared_ptr<dcp::MonoPictureAsset> mono = dynamic_pointer_cast<dcp::MonoPictureAsset> (_picture_asset);
567                 if (mono) {
568                         reel_picture_asset.reset (new dcp::ReelMonoPictureAsset (mono, 0));
569                 }
570
571                 shared_ptr<dcp::StereoPictureAsset> stereo = dynamic_pointer_cast<dcp::StereoPictureAsset> (_picture_asset);
572                 if (stereo && boost::filesystem::exists (stereo->file ())) {
573                         reel_picture_asset.reset (new dcp::ReelStereoPictureAsset (stereo, 0));
574                 }
575         } else {
576                 /* We don't have a picture asset of our own; maybe we need to reference one */
577                 /* XXX: this is all a hack */
578                 BOOST_FOREACH (shared_ptr<dcp::ReelAsset> i, _reel_assets) {
579                         shared_ptr<dcp::ReelPictureAsset> j = dynamic_pointer_cast<dcp::ReelPictureAsset> (i);
580                         if (j) {
581                                 reel_picture_asset = j;
582                         }
583                 }
584         }
585
586         reel->add (reel_picture_asset);
587
588         if (_sound_asset) {
589                 /* We have made a sound asset of our own.  Put it into the reel */
590                 reel->add (shared_ptr<dcp::ReelSoundAsset> (new dcp::ReelSoundAsset (_sound_asset, 0)));
591         } else {
592                 /* We don't have a sound asset of our own; maybe we need to reference one */
593                 /* XXX: this is all a hack */
594                 BOOST_FOREACH (shared_ptr<dcp::ReelAsset> i, _reel_assets) {
595                         if (dynamic_pointer_cast<dcp::ReelSoundAsset> (i)) {
596                                 reel->add (i);
597                         }
598                 }
599         }
600
601         if (_subtitle_asset) {
602                 boost::filesystem::path liberation;
603                 try {
604                         liberation = shared_path () / "LiberationSans-Regular.ttf";
605                 } catch (boost::filesystem::filesystem_error& e) {
606                         /* Hack: try the debian/ubuntu location if getting the shared path failed */
607                         liberation = "/usr/share/fonts/truetype/liberation/LiberationSans-Regular.ttf";
608                 }
609
610                 /* Add all the fonts to the subtitle content */
611                 BOOST_FOREACH (shared_ptr<Font> i, _fonts) {
612                         _subtitle_asset->add_font (i->id(), i->file().get_value_or (liberation));
613                 }
614
615                 if (dynamic_pointer_cast<dcp::InteropSubtitleAsset> (_subtitle_asset)) {
616                         boost::filesystem::path directory = _film->dir (_film->dcp_name ()) / _subtitle_asset->id ();
617                         boost::filesystem::create_directories (directory);
618                         _subtitle_asset->write (directory / ("sub_" + _subtitle_asset->id() + ".xml"));
619                 } else {
620                         /* All our assets should be the same length; use the picture asset length here
621                            as a reference to set the subtitle one.
622                         */
623                         dynamic_pointer_cast<dcp::SMPTESubtitleAsset>(_subtitle_asset)->set_intrinsic_duration (
624                                 reel_picture_asset->intrinsic_duration ()
625                                 );
626
627                         _subtitle_asset->write (
628                                 _film->dir (_film->dcp_name ()) / ("sub_" + _subtitle_asset->id() + ".mxf")
629                                 );
630                 }
631
632                 reel->add (shared_ptr<dcp::ReelSubtitleAsset> (
633                                    new dcp::ReelSubtitleAsset (
634                                            _subtitle_asset,
635                                            dcp::Fraction (_film->video_frame_rate(), 1),
636                                            reel_picture_asset->intrinsic_duration (),
637                                            0
638                                            )
639                                    ));
640         } else {
641                 /* We don't have a subtitle asset of our own; maybe we need to reference one */
642                 /* XXX: this is all a hack */
643                 BOOST_FOREACH (shared_ptr<dcp::ReelAsset> i, _reel_assets) {
644                         if (dynamic_pointer_cast<dcp::ReelSubtitleAsset> (i)) {
645                                 reel->add (i);
646                         }
647                 }
648         }
649
650         cpl->add (reel);
651
652         shared_ptr<Job> job = _job.lock ();
653         DCPOMATIC_ASSERT (job);
654
655         job->sub (_("Computing image digest"));
656         if (_picture_asset) {
657                 _picture_asset->hash (boost::bind (&Job::set_progress, job.get(), _1, false));
658         }
659
660         if (_sound_asset) {
661                 job->sub (_("Computing audio digest"));
662                 _sound_asset->hash (boost::bind (&Job::set_progress, job.get(), _1, false));
663         }
664
665         dcp::XMLMetadata meta;
666         meta.creator = Config::instance()->dcp_creator ();
667         if (meta.creator.empty ()) {
668                 meta.creator = String::compose ("DCP-o-matic %1 %2", dcpomatic_version, dcpomatic_git_commit);
669         }
670         meta.issuer = Config::instance()->dcp_issuer ();
671         if (meta.issuer.empty ()) {
672                 meta.issuer = String::compose ("DCP-o-matic %1 %2", dcpomatic_version, dcpomatic_git_commit);
673         }
674         meta.set_issue_date_now ();
675
676         cpl->set_metadata (meta);
677
678         shared_ptr<const dcp::CertificateChain> signer;
679         if (_film->is_signed ()) {
680                 signer = Config::instance()->signer_chain ();
681                 /* We did check earlier, but check again here to be on the safe side */
682                 if (!signer->valid ()) {
683                         throw InvalidSignerError ();
684                 }
685         }
686
687         dcp.write_xml (_film->interop () ? dcp::INTEROP : dcp::SMPTE, meta, signer);
688
689         LOG_GENERAL (
690                 N_("Wrote %1 FULL, %2 FAKE, %3 REPEAT, %4 pushed to disk"), _full_written, _fake_written, _repeat_written, _pushed_to_disk
691                 );
692 }
693
694 void
695 Writer::check_existing_picture_asset ()
696 {
697         /* Try to open the existing asset */
698         FILE* asset_file = fopen_boost (_picture_asset->file(), "rb");
699         if (!asset_file) {
700                 LOG_GENERAL ("Could not open existing asset at %1 (errno=%2)", _picture_asset->file().string(), errno);
701                 return;
702         }
703
704         /* Offset of the last dcp::FrameInfo in the info file */
705         int const n = (boost::filesystem::file_size (_film->info_file ()) / _info_size) - 1;
706
707         FILE* info_file = fopen_boost (_film->info_file (), "rb");
708         if (!info_file) {
709                 LOG_GENERAL_NC ("Could not open film info file");
710                 fclose (asset_file);
711                 return;
712         }
713
714         if (_film->three_d ()) {
715                 /* Start looking at the last left frame */
716                 _first_nonexistant_frame = n / 2;
717         } else {
718                 _first_nonexistant_frame = n;
719         }
720
721         bool ok = false;
722
723         while (!ok) {
724                 /* Read the data from the info file; for 3D we just check the left
725                    frames until we find a good one.
726                 */
727                 dcp::FrameInfo info = read_frame_info (info_file, _first_nonexistant_frame, _film->three_d () ? EYES_LEFT : EYES_BOTH);
728
729                 ok = true;
730
731                 /* Read the data from the asset and hash it */
732                 dcpomatic_fseek (asset_file, info.offset, SEEK_SET);
733                 Data data (info.size);
734                 size_t const read = fread (data.data().get(), 1, data.size(), asset_file);
735                 if (read != static_cast<size_t> (data.size ())) {
736                         LOG_GENERAL ("Existing frame %1 is incomplete", _first_nonexistant_frame);
737                         ok = false;
738                 } else {
739                         MD5Digester digester;
740                         digester.add (data.data().get(), data.size());
741                         if (digester.get() != info.hash) {
742                                 LOG_GENERAL ("Existing frame %1 failed hash check", _first_nonexistant_frame);
743                                 ok = false;
744                         }
745                 }
746
747                 if (!ok) {
748                         --_first_nonexistant_frame;
749                 }
750         }
751
752         if (!_film->three_d ()) {
753                 /* If we are doing 3D we might have found a good L frame with no R, so only
754                    do this if we're in 2D and we've just found a good B(oth) frame.
755                 */
756                 ++_first_nonexistant_frame;
757         }
758
759         fclose (asset_file);
760         fclose (info_file);
761 }
762
763 /** @param frame Frame index.
764  *  @return true if we can fake-write this frame.
765  */
766 bool
767 Writer::can_fake_write (int frame) const
768 {
769         /* We have to do a proper write of the first frame so that we can set up the JPEG2000
770            parameters in the asset writer.
771         */
772         return (frame != 0 && frame < _first_nonexistant_frame);
773 }
774
775 void
776 Writer::write (PlayerSubtitles subs)
777 {
778         if (subs.text.empty ()) {
779                 return;
780         }
781
782         if (!_subtitle_asset) {
783                 string lang = _film->subtitle_language ();
784                 if (lang.empty ()) {
785                         lang = "Unknown";
786                 }
787                 if (_film->interop ()) {
788                         shared_ptr<dcp::InteropSubtitleAsset> s (new dcp::InteropSubtitleAsset ());
789                         s->set_movie_title (_film->name ());
790                         s->set_language (lang);
791                         s->set_reel_number ("1");
792                         _subtitle_asset = s;
793                 } else {
794                         shared_ptr<dcp::SMPTESubtitleAsset> s (new dcp::SMPTESubtitleAsset ());
795                         s->set_content_title_text (_film->name ());
796                         s->set_language (lang);
797                         s->set_edit_rate (dcp::Fraction (_film->video_frame_rate (), 1));
798                         s->set_reel_number (1);
799                         s->set_time_code_rate (_film->video_frame_rate ());
800                         s->set_start_time (dcp::Time ());
801                         _subtitle_asset = s;
802                 }
803         }
804
805         for (list<dcp::SubtitleString>::const_iterator i = subs.text.begin(); i != subs.text.end(); ++i) {
806                 _subtitle_asset->add (*i);
807         }
808 }
809
810 void
811 Writer::write (list<shared_ptr<Font> > fonts)
812 {
813         /* Just keep a list of fonts and we'll deal with them in ::finish */
814         copy (fonts.begin (), fonts.end (), back_inserter (_fonts));
815 }
816
817 bool
818 operator< (QueueItem const & a, QueueItem const & b)
819 {
820         if (a.frame != b.frame) {
821                 return a.frame < b.frame;
822         }
823
824         return static_cast<int> (a.eyes) < static_cast<int> (b.eyes);
825 }
826
827 bool
828 operator== (QueueItem const & a, QueueItem const & b)
829 {
830         return a.frame == b.frame && a.eyes == b.eyes;
831 }
832
833 void
834 Writer::set_encoder_threads (int threads)
835 {
836         _maximum_frames_in_memory = lrint (threads * 1.1);
837 }
838
839 long
840 Writer::frame_info_position (int frame, Eyes eyes) const
841 {
842         switch (eyes) {
843         case EYES_BOTH:
844                 return frame * _info_size;
845         case EYES_LEFT:
846                 return frame * _info_size * 2;
847         case EYES_RIGHT:
848                 return frame * _info_size * 2 + _info_size;
849         default:
850                 DCPOMATIC_ASSERT (false);
851         }
852
853         DCPOMATIC_ASSERT (false);
854 }
855
856 dcp::FrameInfo
857 Writer::read_frame_info (FILE* file, int frame, Eyes eyes) const
858 {
859         dcp::FrameInfo info;
860         dcpomatic_fseek (file, frame_info_position (frame, eyes), SEEK_SET);
861         fread (&info.offset, sizeof (info.offset), 1, file);
862         fread (&info.size, sizeof (info.size), 1, file);
863
864         char hash_buffer[33];
865         fread (hash_buffer, 1, 32, file);
866         hash_buffer[32] = '\0';
867         info.hash = hash_buffer;
868
869         return info;
870 }
871
872 void
873 Writer::write (shared_ptr<dcp::ReelAsset> asset)
874 {
875         _reel_assets.push_back (asset);
876 }