Optimise checking of existing image data.

When checking existing image data go from the end backwards until
a good hash is found rather than from the start forwards until
a bad hash is found.  This is a lot quicker for long files but
may miss a corrupted frame somewhere (however unlikely this is).

diff --git a/ChangeLog b/ChangeLog
index d808ddf3e703577b5f5561a590985234820bdd9c..ee9ebfcb93332a743f70ae7649535ebf64574546 100644 (file)
--- a/ChangeLog
+++ b/ChangeLog
@@ -1,5 +1,12 @@
 2015-09-03  c.hetherington  <cth@carlh.net>
 
+       * Quicker, though slightly less safe,
+       check for existing picture data; go back
+       from the last frame written until we
+       find a good one rather than going
+       through from the beginning until we find
+       a bad one (#519, #504).
+
        * Add frame counter to progress
        when transcoding (#111).
 

diff --git a/src/lib/writer.cc b/src/lib/writer.cc
index 3bee0e963455df8501a423b129fd63fa21569146..ccf47ed340f09115f17f7e9c51fbe213cf91eabb 100644 (file)
--- a/src/lib/writer.cc
+++ b/src/lib/writer.cc
@@ -55,6 +55,7 @@
 #include "i18n.h"
 
 #define LOG_GENERAL(...) _film->log()->log (String::compose (__VA_ARGS__), Log::TYPE_GENERAL);
+#define LOG_GENERAL_NC(...) _film->log()->log (__VA_ARGS__, Log::TYPE_GENERAL);
 #define LOG_DEBUG_ENCODE(...) _film->log()->log (String::compose (__VA_ARGS__), Log::TYPE_DEBUG_ENCODE);
 #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);
@@ -73,6 +74,8 @@ using boost::shared_ptr;
 using boost::weak_ptr;
 using boost::dynamic_pointer_cast;
 
+int const Writer::_info_size = 48;
+
 Writer::Writer (shared_ptr<const Film> film, weak_ptr<Job> j)
        : _film (film)
        , _job (j)
@@ -636,77 +639,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;
+       }
+
+       if (_film->three_d ()) {
+               /* Start looking at the last left frame */
+               _first_nonexistant_frame = n / 2;
+       } else {
+               _first_nonexistant_frame = n;
+       }
 
-               job->set_progress_unknown ();
+       bool ok = false;
 
-               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;
-                       }
+       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_DEBUG_ENCODE ("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.
@@ -788,15 +787,13 @@ Writer::set_encoder_threads (int threads)
 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);
        }

diff --git a/src/lib/writer.h b/src/lib/writer.h
index cec6ba527b07a49f98ddcf4765e450c1a6ab4ae5..120e1f338fb8b32e885bf214010d91d614e755a5 100644 (file)
--- a/src/lib/writer.h
+++ b/src/lib/writer.h
@@ -116,7 +116,6 @@ private:
        void thread ();
        void terminate_thread (bool);
        void check_existing_picture_asset ();
-       bool check_existing_picture_asset_frame (FILE *, int, Eyes);
        bool have_sequenced_image_at_queue_head ();
        void write_frame_info (int frame, Eyes eyes, dcp::FrameInfo info) const;
        long frame_info_position (int frame, Eyes eyes) const;
@@ -169,4 +168,6 @@ private:
        boost::shared_ptr<dcp::SubtitleAsset> _subtitle_asset;
 
        std::list<boost::shared_ptr<Font> > _fonts;
+
+       static int const _info_size;
 };

diff --git a/test/recover_test.cc b/test/recover_test.cc
index a70357e94d1709a094416c93182009efec01473b..45791ae0d393d7fae527e7588946695258d97cf8 100644 (file)
--- a/test/recover_test.cc
+++ b/test/recover_test.cc
@@ -21,13 +21,15 @@
  *  @brief Test recovery of a DCP transcode after a crash.
  */
 
-#include <boost/test/unit_test.hpp>
-#include <dcp/stereo_picture_asset.h>
+#include "test.h"
 #include "lib/film.h"
 #include "lib/dcp_content_type.h"
 #include "lib/image_content.h"
+#include "lib/ffmpeg_content.h"
 #include "lib/ratio.h"
-#include "test.h"
+#include <dcp/mono_picture_asset.h>
+#include <dcp/stereo_picture_asset.h>
+#include <boost/test/unit_test.hpp>
 
 using std::cout;
 using std::string;
@@ -41,9 +43,42 @@ note (dcp::NoteType t, string n)
        }
 }
 
-BOOST_AUTO_TEST_CASE (recover_test)
+BOOST_AUTO_TEST_CASE (recover_test_2d)
+{
+       shared_ptr<Film> film = new_test_film ("recover_test_2d");
+       film->set_dcp_content_type (DCPContentType::from_isdcf_name ("FTR"));
+       film->set_container (Ratio::from_id ("185"));
+       film->set_name ("recover_test");
+
+       shared_ptr<FFmpegContent> content (new FFmpegContent (film, "test/data/count300bd24.m2ts"));
+       film->examine_and_add_content (content);
+       wait_for_jobs ();
+
+       film->make_dcp ();
+       wait_for_jobs ();
+
+       boost::filesystem::path const video = "build/test/recover_test_2d/video/185_2K_d2b23c22cff43b0247c7108dcd32323c_24_100000000_P_S.mxf";
+
+       boost::filesystem::copy_file (
+               video,
+               "build/test/recover_test_2d/original.mxf"
+               );
+
+       boost::filesystem::resize_file (video, 2 * 1024 * 1024);
+
+       film->make_dcp ();
+       wait_for_jobs ();
+
+       shared_ptr<dcp::MonoPictureAsset> A (new dcp::MonoPictureAsset ("build/test/recover_test_2d/original.mxf"));
+       shared_ptr<dcp::MonoPictureAsset> B (new dcp::MonoPictureAsset (video));
+
+       dcp::EqualityOptions eq;
+       BOOST_CHECK (A->equals (B, eq, boost::bind (&note, _1, _2)));
+}
+
+BOOST_AUTO_TEST_CASE (recover_test_3d)
 {
-       shared_ptr<Film> film = new_test_film ("recover_test");
+       shared_ptr<Film> film = new_test_film ("recover_test_3d");
        film->set_dcp_content_type (DCPContentType::from_isdcf_name ("FTR"));
        film->set_container (Ratio::from_id ("185"));
        film->set_name ("recover_test");
@@ -57,11 +92,11 @@ BOOST_AUTO_TEST_CASE (recover_test)
        film->make_dcp ();
        wait_for_jobs ();
 
-       boost::filesystem::path const video = "build/test/recover_test/video/185_2K_961f053444e90c5ddbf978eb0ebfa772_24_100000000_P_S_3D.mxf";
+       boost::filesystem::path const video = "build/test/recover_test_3d/video/185_2K_961f053444e90c5ddbf978eb0ebfa772_24_100000000_P_S_3D.mxf";
 
        boost::filesystem::copy_file (
                video,
-               "build/test/recover_test/original.mxf"
+               "build/test/recover_test_3d/original.mxf"
                );
 
        boost::filesystem::resize_file (video, 2 * 1024 * 1024);
@@ -69,7 +104,7 @@ BOOST_AUTO_TEST_CASE (recover_test)
        film->make_dcp ();
        wait_for_jobs ();
 
-       shared_ptr<dcp::StereoPictureAsset> A (new dcp::StereoPictureAsset ("build/test/recover_test/original.mxf"));
+       shared_ptr<dcp::StereoPictureAsset> A (new dcp::StereoPictureAsset ("build/test/recover_test_3d/original.mxf"));
        shared_ptr<dcp::StereoPictureAsset> B (new dcp::StereoPictureAsset (video));
 
        dcp::EqualityOptions eq;