More player debugging for butler video-full states.
[dcpomatic.git] / src / lib / reel_writer.cc
index 27f10d1ed4bc874f492428522569a470183d14ae..8ed085dbd18480bf528904406087a73a54466eab 100644 (file)
@@ -1,5 +1,5 @@
 /*
-    Copyright (C) 2012-2016 Carl Hetherington <cth@carlh.net>
+    Copyright (C) 2012-2018 Carl Hetherington <cth@carlh.net>
 
     This file is part of DCP-o-matic.
 
 #include "cross.h"
 #include "job.h"
 #include "log.h"
+#include "dcpomatic_log.h"
 #include "digester.h"
 #include "font.h"
 #include "compose.hpp"
 #include "audio_buffers.h"
+#include "image.h"
 #include <dcp/mono_picture_asset.h>
 #include <dcp/stereo_picture_asset.h>
 #include <dcp/sound_asset.h>
 #include <dcp/reel_stereo_picture_asset.h>
 #include <dcp/reel_sound_asset.h>
 #include <dcp/reel_subtitle_asset.h>
+#include <dcp/reel_closed_caption_asset.h>
 #include <dcp/dcp.h>
 #include <dcp/cpl.h>
 #include <dcp/certificate_chain.h>
 #include <dcp/interop_subtitle_asset.h>
 #include <dcp/smpte_subtitle_asset.h>
+#include <dcp/raw_convert.h>
+#include <dcp/subtitle_image.h>
 #include <boost/foreach.hpp>
 
 #include "i18n.h"
 
-#define LOG_GENERAL(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_GENERAL);
-#define LOG_GENERAL_NC(...) _film->log()->log (__VA_ARGS__, LogEntry::TYPE_GENERAL);
-#define LOG_WARNING_NC(...) _film->log()->log (__VA_ARGS__, LogEntry::TYPE_WARNING);
-#define LOG_ERROR(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_ERROR);
-
 using std::list;
 using std::string;
 using std::cout;
+using std::map;
 using boost::shared_ptr;
 using boost::optional;
 using boost::dynamic_pointer_cast;
 using dcp::Data;
+using dcp::raw_convert;
 
 int const ReelWriter::_info_size = 48;
 
@@ -65,10 +67,8 @@ ReelWriter::ReelWriter (
        )
        : _film (film)
        , _period (period)
-       , _first_nonexistant_frame (0)
        , _last_written_video_frame (-1)
        , _last_written_eyes (EYES_RIGHT)
-       , _total_written_audio_frames (0)
        , _reel_index (reel_index)
        , _reel_count (reel_count)
        , _content_summary (content_summary)
@@ -78,10 +78,12 @@ ReelWriter::ReelWriter (
           it into the DCP later.
        */
 
+       dcp::Standard const standard = _film->interop() ? dcp::INTEROP : dcp::SMPTE;
+
        if (_film->three_d ()) {
-               _picture_asset.reset (new dcp::StereoPictureAsset (dcp::Fraction (_film->video_frame_rate (), 1)));
+               _picture_asset.reset (new dcp::StereoPictureAsset (dcp::Fraction (_film->video_frame_rate(), 1), standard));
        } else {
-               _picture_asset.reset (new dcp::MonoPictureAsset (dcp::Fraction (_film->video_frame_rate (), 1)));
+               _picture_asset.reset (new dcp::MonoPictureAsset (dcp::Fraction (_film->video_frame_rate(), 1), standard));
        }
 
        _picture_asset->set_size (_film->frame_size ());
@@ -96,17 +98,16 @@ ReelWriter::ReelWriter (
                );
 
        job->sub (_("Checking existing image data"));
-       check_existing_picture_asset ();
+       _first_nonexistant_frame = check_existing_picture_asset ();
 
        _picture_asset_writer = _picture_asset->start_write (
                _film->internal_video_asset_dir() / _film->internal_video_asset_filename(_period),
-               _film->interop() ? dcp::INTEROP : dcp::SMPTE,
                _first_nonexistant_frame > 0
                );
 
        if (_film->audio_channels ()) {
                _sound_asset.reset (
-                       new dcp::SoundAsset (dcp::Fraction (_film->video_frame_rate(), 1), _film->audio_frame_rate (), _film->audio_channels ())
+                       new dcp::SoundAsset (dcp::Fraction (_film->video_frame_rate(), 1), _film->audio_frame_rate (), _film->audio_channels (), standard)
                        );
 
                if (_film->encrypted ()) {
@@ -119,8 +120,7 @@ ReelWriter::ReelWriter (
                   of the DCP directory until the last minute.
                */
                _sound_asset_writer = _sound_asset->start_write (
-                       _film->directory().get() / audio_asset_filename (_sound_asset, _reel_index, _reel_count, _content_summary),
-                       _film->interop() ? dcp::INTEROP : dcp::SMPTE
+                       _film->directory().get() / audio_asset_filename (_sound_asset, _reel_index, _reel_count, _content_summary)
                        );
        }
 }
@@ -134,17 +134,6 @@ ReelWriter::write_frame_info (Frame frame, Eyes eyes, dcp::FrameInfo info) const
 
        bool const read = boost::filesystem::exists (info_file);
 
-#ifdef DCPOMATIC_WINDOWS
-       if (read) {
-               LOG_GENERAL (
-                       "Checked %1 (which exists) length is %2 perms are %3",
-                       info_file, boost::filesystem::file_size (info_file), int(boost::filesystem::status(info_file).permissions())
-                       );
-       } else {
-               LOG_GENERAL ("Checked %1 (which does not exist)", info_file);
-       }
-#endif
-
        if (read) {
                file = fopen_boost (info_file, "r+b");
        } else {
@@ -154,9 +143,9 @@ ReelWriter::write_frame_info (Frame frame, Eyes eyes, dcp::FrameInfo info) const
                throw OpenFileError (info_file, errno, read);
        }
        dcpomatic_fseek (file, frame_info_position (frame, eyes), SEEK_SET);
-       fwrite (&info.offset, sizeof (info.offset), 1, file);
-       fwrite (&info.size, sizeof (info.size), 1, file);
-       fwrite (info.hash.c_str(), 1, info.hash.size(), file);
+       checked_fwrite (&info.offset, sizeof (info.offset), file, info_file);
+       checked_fwrite (&info.size, sizeof (info.size), file, info_file);
+       checked_fwrite (info.hash.c_str(), info.hash.size(), file, info_file);
        fclose (file);
 }
 
@@ -165,11 +154,11 @@ ReelWriter::read_frame_info (FILE* file, Frame frame, Eyes eyes) const
 {
        dcp::FrameInfo info;
        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);
+       checked_fread (&info.offset, sizeof(info.offset), file, _film->info_file(_period));
+       checked_fread (&info.size, sizeof(info.size), file, _film->info_file(_period));
 
        char hash_buffer[33];
-       fread (hash_buffer, 1, 32, file);
+       checked_fread (hash_buffer, 32, file, _film->info_file(_period));
        hash_buffer[32] = '\0';
        info.hash = hash_buffer;
 
@@ -193,17 +182,29 @@ ReelWriter::frame_info_position (Frame frame, Eyes eyes) const
        DCPOMATIC_ASSERT (false);
 }
 
-void
+Frame
 ReelWriter::check_existing_picture_asset ()
 {
-       /* Try to open the existing asset */
        DCPOMATIC_ASSERT (_picture_asset->file());
-       FILE* asset_file = fopen_boost (_picture_asset->file().get(), "rb");
+       boost::filesystem::path asset = _picture_asset->file().get();
+
+       /* If there is an existing asset, break any hard links to it as we are about to change its contents
+          (if only by changing the IDs); see #1126.
+       */
+
+       if (boost::filesystem::exists(asset) && boost::filesystem::hard_link_count(asset) > 1) {
+               boost::filesystem::copy_file (asset, asset.string() + ".tmp");
+               boost::filesystem::remove (asset);
+               boost::filesystem::rename (asset.string() + ".tmp", asset);
+       }
+
+       /* Try to open the existing asset */
+       FILE* asset_file = fopen_boost (asset, "rb");
        if (!asset_file) {
-               LOG_GENERAL ("Could not open existing asset at %1 (errno=%2)", _picture_asset->file()->string(), errno);
-               return;
+               LOG_GENERAL ("Could not open existing asset at %1 (errno=%2)", asset.string(), errno);
+               return 0;
        } else {
-               LOG_GENERAL ("Opened existing asset at %1", _picture_asset->file()->string());
+               LOG_GENERAL ("Opened existing asset at %1", asset.string());
        }
 
        /* Offset of the last dcp::FrameInfo in the info file */
@@ -214,31 +215,34 @@ ReelWriter::check_existing_picture_asset ()
        if (!info_file) {
                LOG_GENERAL_NC ("Could not open film info file");
                fclose (asset_file);
-               return;
+               return 0;
        }
 
+       Frame first_nonexistant_frame;
        if (_film->three_d ()) {
                /* Start looking at the last left frame */
-               _first_nonexistant_frame = n / 2;
+               first_nonexistant_frame = n / 2;
        } else {
-               _first_nonexistant_frame = n;
+               first_nonexistant_frame = n;
        }
 
-       while (!existing_picture_frame_ok(asset_file, info_file) && _first_nonexistant_frame > 0) {
-               --_first_nonexistant_frame;
+       while (!existing_picture_frame_ok(asset_file, info_file, first_nonexistant_frame) && first_nonexistant_frame > 0) {
+               --first_nonexistant_frame;
        }
 
-       if (!_film->three_d() && _first_nonexistant_frame > 0) {
+       if (!_film->three_d() && first_nonexistant_frame > 0) {
                /* 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;
+               ++first_nonexistant_frame;
        }
 
-       LOG_GENERAL ("Proceeding with first nonexistant frame %1", _first_nonexistant_frame);
+       LOG_GENERAL ("Proceeding with first nonexistant frame %1", first_nonexistant_frame);
 
        fclose (asset_file);
        fclose (info_file);
+
+       return first_nonexistant_frame;
 }
 
 void
@@ -326,6 +330,95 @@ ReelWriter::finish ()
        }
 }
 
+template <class T>
+shared_ptr<T>
+maybe_add_text (
+       shared_ptr<dcp::SubtitleAsset> asset,
+       int64_t picture_duration,
+       shared_ptr<dcp::Reel> reel,
+       list<ReferencedReelAsset> const & refs,
+       list<shared_ptr<Font> > const & fonts,
+       shared_ptr<const Film> film,
+       DCPTimePeriod period
+       )
+{
+       Frame const period_duration = period.duration().frames_round(film->video_frame_rate());
+
+       shared_ptr<T> reel_asset;
+
+       if (asset) {
+               boost::filesystem::path liberation_normal;
+               try {
+                       liberation_normal = shared_path() / "LiberationSans-Regular.ttf";
+                       if (!boost::filesystem::exists (liberation_normal)) {
+                               /* Hack for unit tests */
+                               liberation_normal = shared_path() / "fonts" / "LiberationSans-Regular.ttf";
+                       }
+               } catch (boost::filesystem::filesystem_error& e) {
+
+               }
+
+               if (!boost::filesystem::exists(liberation_normal)) {
+                       liberation_normal = "/usr/share/fonts/truetype/liberation/LiberationSans-Regular.ttf";
+               }
+
+               /* Add the font to the subtitle content */
+               BOOST_FOREACH (shared_ptr<Font> j, fonts) {
+                       asset->add_font (j->id(), j->file().get_value_or(liberation_normal));
+               }
+
+               if (dynamic_pointer_cast<dcp::InteropSubtitleAsset> (asset)) {
+                       boost::filesystem::path directory = film->dir (film->dcp_name ()) / asset->id ();
+                       boost::filesystem::create_directories (directory);
+                       asset->write (directory / ("sub_" + 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.  We'll use the duration rather than
+                          the intrinsic duration; we don't care if the picture asset has been trimmed, we're
+                          just interested in its presentation length.
+                       */
+                       dynamic_pointer_cast<dcp::SMPTESubtitleAsset>(asset)->set_intrinsic_duration (picture_duration);
+
+                       asset->write (
+                               film->dir(film->dcp_name()) / ("sub_" + asset->id() + ".mxf")
+                               );
+               }
+
+               reel_asset.reset (
+                       new T (
+                               asset,
+                               dcp::Fraction (film->video_frame_rate(), 1),
+                               picture_duration,
+                               0
+                               )
+                       );
+       } else {
+               /* We don't have a subtitle asset of our own; hopefully we have one to reference */
+               BOOST_FOREACH (ReferencedReelAsset j, refs) {
+                       shared_ptr<T> k = dynamic_pointer_cast<T> (j.asset);
+                       if (k && j.period == period) {
+                               reel_asset = k;
+                               /* If we have a hash for this asset in the CPL, assume that it is correct */
+                               if (k->hash()) {
+                                       k->asset_ref()->set_hash (k->hash().get());
+                               }
+                       }
+               }
+       }
+
+       if (reel_asset) {
+               if (reel_asset->duration() != period_duration) {
+                       throw ProgrammingError (
+                               __FILE__, __LINE__,
+                               String::compose ("%1 vs %2", reel_asset->duration(), period_duration)
+                               );
+               }
+               reel->add (reel_asset);
+       }
+
+       return reel_asset;
+}
+
 shared_ptr<dcp::Reel>
 ReelWriter::create_reel (list<ReferencedReelAsset> const & refs, list<shared_ptr<Font> > const & fonts)
 {
@@ -360,11 +453,13 @@ ReelWriter::create_reel (list<ReferencedReelAsset> const & refs, list<shared_ptr
 
        LOG_GENERAL ("create_reel for %1-%2; %3 of %4", _period.from.get(), _period.to.get(), _reel_index, _reel_count);
 
+       Frame const period_duration = _period.duration().frames_round(_film->video_frame_rate());
+
        DCPOMATIC_ASSERT (reel_picture_asset);
-       if (reel_picture_asset->duration() != _period.duration().frames_round (_film->video_frame_rate ())) {
+       if (reel_picture_asset->duration() != period_duration) {
                throw ProgrammingError (
                        __FILE__, __LINE__,
-                       String::compose ("%1 vs %2", reel_picture_asset->duration(), _period.duration().frames_round (_film->video_frame_rate ()))
+                       String::compose ("%1 vs %2", reel_picture_asset->duration(), period_duration)
                        );
        }
        reel->add (reel_picture_asset);
@@ -394,83 +489,29 @@ ReelWriter::create_reel (list<ReferencedReelAsset> const & refs, list<shared_ptr
        }
 
        DCPOMATIC_ASSERT (reel_sound_asset);
-       if (reel_sound_asset->duration() != _period.duration().frames_round (_film->video_frame_rate ())) {
+       if (reel_sound_asset->duration() != period_duration) {
                LOG_ERROR (
                        "Reel sound asset has length %1 but reel period is %2",
                        reel_sound_asset->duration(),
-                       _period.duration().frames_round(_film->video_frame_rate())
+                       period_duration
                        );
-               DCPOMATIC_ASSERT (reel_sound_asset->duration() == _period.duration().frames_round (_film->video_frame_rate ()));
-       }
-       reel->add (reel_sound_asset);
-
-       shared_ptr<dcp::ReelSubtitleAsset> reel_subtitle_asset;
-
-       if (_subtitle_asset) {
-
-               boost::filesystem::path liberation_normal;
-               try {
-                       liberation_normal = shared_path() / "LiberationSans-Regular.ttf";
-                       if (!boost::filesystem::exists (liberation_normal)) {
-                               /* Hack for unit tests */
-                               liberation_normal = shared_path() / "fonts" / "LiberationSans-Regular.ttf";
-                       }
-               } catch (boost::filesystem::filesystem_error& e) {
-
-               }
-
-               if (!boost::filesystem::exists(liberation_normal)) {
-                       liberation_normal = "/usr/share/fonts/truetype/liberation/LiberationSans-Regular.ttf";
-               }
-
-               /* Add all the fonts to the subtitle content */
-               BOOST_FOREACH (shared_ptr<Font> j, fonts) {
-                       _subtitle_asset->add_font (j->id(), j->file(FontFiles::NORMAL).get_value_or(liberation_normal));
-               }
-
-               if (dynamic_pointer_cast<dcp::InteropSubtitleAsset> (_subtitle_asset)) {
-                       boost::filesystem::path directory = _film->dir (_film->dcp_name ()) / _subtitle_asset->id ();
-                       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")
+               if (reel_sound_asset->duration() != period_duration) {
+                       throw ProgrammingError (
+                               __FILE__, __LINE__,
+                               String::compose ("%1 vs %2", reel_sound_asset->duration(), period_duration)
                                );
                }
 
-               reel_subtitle_asset.reset (
-                       new dcp::ReelSubtitleAsset (
-                               _subtitle_asset,
-                               dcp::Fraction (_film->video_frame_rate(), 1),
-                               reel_picture_asset->intrinsic_duration (),
-                               0
-                               )
-                       );
-       } else {
-               /* We don't have a subtitle asset of our own; hopefully we have one to reference */
-               BOOST_FOREACH (ReferencedReelAsset j, refs) {
-                       shared_ptr<dcp::ReelSubtitleAsset> k = dynamic_pointer_cast<dcp::ReelSubtitleAsset> (j.asset);
-                       if (k && j.period == _period) {
-                               reel_subtitle_asset = k;
-                               /* If we have a hash for this asset in the CPL, assume that it is correct */
-                               if (k->hash()) {
-                                       k->asset_ref()->set_hash (k->hash().get());
-                               }
-                       }
-               }
        }
+       reel->add (reel_sound_asset);
 
-       if (reel_subtitle_asset) {
-               DCPOMATIC_ASSERT (reel_subtitle_asset->duration() == _period.duration().frames_round (_film->video_frame_rate ()));
-               reel->add (reel_subtitle_asset);
+       maybe_add_text<dcp::ReelSubtitleAsset> (_subtitle_asset, reel_picture_asset->duration(), reel, refs, fonts, _film, _period);
+       for (map<DCPTextTrack, shared_ptr<dcp::SubtitleAsset> >::const_iterator i = _closed_caption_assets.begin(); i != _closed_caption_assets.end(); ++i) {
+               shared_ptr<dcp::ReelClosedCaptionAsset> a = maybe_add_text<dcp::ReelClosedCaptionAsset> (
+                       i->second, reel_picture_asset->duration(), reel, refs, fonts, _film, _period
+                       );
+               a->set_annotation_text (i->first.name);
+               a->set_language (i->first.language);
        }
 
        return reel;
@@ -502,58 +543,99 @@ ReelWriter::write (shared_ptr<const AudioBuffers> audio)
                return;
        }
 
-       if (audio) {
-               _sound_asset_writer->write (audio->data(), audio->frames());
-       }
-
-       _total_written_audio_frames += audio->frames ();
+       DCPOMATIC_ASSERT (audio);
+       _sound_asset_writer->write (audio->data(), audio->frames());
 }
 
 void
-ReelWriter::write (PlayerSubtitles subs)
+ReelWriter::write (PlayerText subs, TextType type, optional<DCPTextTrack> track, DCPTimePeriod period)
 {
-       if (!_subtitle_asset) {
+       shared_ptr<dcp::SubtitleAsset> asset;
+
+       switch (type) {
+       case TEXT_OPEN_SUBTITLE:
+               asset = _subtitle_asset;
+               break;
+       case TEXT_CLOSED_CAPTION:
+               DCPOMATIC_ASSERT (track);
+               asset = _closed_caption_assets[*track];
+               break;
+       default:
+               DCPOMATIC_ASSERT (false);
+       }
+
+       if (!asset) {
                string lang = _film->subtitle_language ();
-               if (lang.empty ()) {
-                       lang = "Unknown";
-               }
                if (_film->interop ()) {
                        shared_ptr<dcp::InteropSubtitleAsset> s (new dcp::InteropSubtitleAsset ());
                        s->set_movie_title (_film->name ());
-                       s->set_language (lang);
-                       s->set_reel_number ("1");
-                       _subtitle_asset = s;
+                       if (lang.empty()) {
+                               s->set_language ("Unknown");
+                       } else {
+                               s->set_language (lang);
+                       }
+                       s->set_reel_number (raw_convert<string> (_reel_index + 1));
+                       asset = s;
                } else {
                        shared_ptr<dcp::SMPTESubtitleAsset> s (new dcp::SMPTESubtitleAsset ());
                        s->set_content_title_text (_film->name ());
-                       s->set_language (lang);
+                       if (!lang.empty()) {
+                               s->set_language (lang);
+                       }
                        s->set_edit_rate (dcp::Fraction (_film->video_frame_rate (), 1));
-                       s->set_reel_number (1);
+                       s->set_reel_number (_reel_index + 1);
                        s->set_time_code_rate (_film->video_frame_rate ());
                        s->set_start_time (dcp::Time ());
                        if (_film->encrypted ()) {
                                s->set_key (_film->key ());
                        }
-                       _subtitle_asset = s;
+                       asset = s;
                }
        }
 
-       BOOST_FOREACH (SubtitleString i, subs.text) {
+       switch (type) {
+       case TEXT_OPEN_SUBTITLE:
+               _subtitle_asset = asset;
+               break;
+       case TEXT_CLOSED_CAPTION:
+               DCPOMATIC_ASSERT (track);
+               _closed_caption_assets[*track] = asset;
+               break;
+       default:
+               DCPOMATIC_ASSERT (false);
+       }
+
+       BOOST_FOREACH (StringText i, subs.string) {
+               /* XXX: couldn't / shouldn't we use period here rather than getting time from the subtitle? */
                i.set_in  (i.in()  - dcp::Time (_period.from.seconds(), i.in().tcr));
                i.set_out (i.out() - dcp::Time (_period.from.seconds(), i.out().tcr));
-               _subtitle_asset->add (i);
+               asset->add (shared_ptr<dcp::Subtitle>(new dcp::SubtitleString(i)));
+       }
+
+       BOOST_FOREACH (BitmapText i, subs.bitmap) {
+               asset->add (
+                       shared_ptr<dcp::Subtitle>(
+                               new dcp::SubtitleImage(
+                                       i.image->as_png(),
+                                       dcp::Time(period.from.seconds(), _film->video_frame_rate()),
+                                       dcp::Time(period.to.seconds(), _film->video_frame_rate()),
+                                       i.rectangle.x, dcp::HALIGN_LEFT, i.rectangle.y, dcp::VALIGN_TOP,
+                                       dcp::Time(), dcp::Time()
+                                       )
+                               )
+                       );
        }
 }
 
 bool
-ReelWriter::existing_picture_frame_ok (FILE* asset_file, FILE* info_file) const
+ReelWriter::existing_picture_frame_ok (FILE* asset_file, FILE* info_file, Frame frame) const
 {
-       LOG_GENERAL ("Checking existing picture frame %1", _first_nonexistant_frame);
+       LOG_GENERAL ("Checking existing picture frame %1", frame);
 
        /* Read the data from the info file; for 3D we just check the left
           frames until we find a good one.
        */
-       dcp::FrameInfo const info = read_frame_info (info_file, _first_nonexistant_frame, _film->three_d () ? EYES_LEFT : EYES_BOTH);
+       dcp::FrameInfo const info = read_frame_info (info_file, frame, _film->three_d () ? EYES_LEFT : EYES_BOTH);
 
        bool ok = true;
 
@@ -563,14 +645,14 @@ ReelWriter::existing_picture_frame_ok (FILE* asset_file, FILE* info_file) const
        size_t const read = fread (data.data().get(), 1, data.size(), asset_file);
        LOG_GENERAL ("Read %1 bytes of asset data; wanted %2", read, info.size);
        if (read != static_cast<size_t> (data.size ())) {
-               LOG_GENERAL ("Existing frame %1 is incomplete", _first_nonexistant_frame);
+               LOG_GENERAL ("Existing frame %1 is incomplete", frame);
                ok = false;
        } else {
                Digester digester;
                digester.add (data.data().get(), data.size());
                LOG_GENERAL ("Hash %1 vs %2", digester.get(), info.hash);
                if (digester.get() != info.hash) {
-                       LOG_GENERAL ("Existing frame %1 failed hash check", _first_nonexistant_frame);
+                       LOG_GENERAL ("Existing frame %1 failed hash check", frame);
                        ok = false;
                }
        }