From 9bdf75cc619740246c2c413d204f26e228e75bb1 Mon Sep 17 00:00:00 2001 From: Carl Hetherington Date: Sun, 3 May 2020 00:41:24 +0200 Subject: [PATCH] Do all writes then do all verification and report progress for each separately (#1743) --- src/lib/copy_to_drive_job.cc | 29 ++++++++++---- src/lib/disk_writer_messages.h | 12 ++++-- src/tools/dcpomatic_disk_writer.cc | 64 ++++++++++++++++++++++++------ 3 files changed, 82 insertions(+), 23 deletions(-) diff --git a/src/lib/copy_to_drive_job.cc b/src/lib/copy_to_drive_job.cc index 7760c072f..0fb41f856 100644 --- a/src/lib/copy_to_drive_job.cc +++ b/src/lib/copy_to_drive_job.cc @@ -70,7 +70,13 @@ CopyToDriveJob::run () throw CommunicationFailedError (); } - bool formatting = false; + enum State { + SETUP, + FORMAT, + COPY, + VERIFY + } state = SETUP; + while (true) { optional s = _nanomsg.receive (10000); if (!s) { @@ -84,13 +90,22 @@ CopyToDriveJob::run () optional const n = _nanomsg.receive (500); throw CopyError (m.get_value_or("Unknown"), raw_convert(n.get_value_or("0"))); } else if (*s == DISK_WRITER_FORMATTING) { - sub ("Formatting drive"); + sub (_("Formatting drive")); set_progress_unknown (); - formatting = true; - } else if (*s == DISK_WRITER_PROGRESS) { - if (formatting) { - sub ("Copying DCP"); - formatting = false; + state = FORMAT; + } else if (*s == DISK_WRITER_COPY_PROGRESS) { + if (state == FORMAT) { + sub (_("Copying DCP")); + state = COPY; + } + optional progress = _nanomsg.receive (500); + if (progress) { + set_progress (raw_convert(*progress)); + } + } else if (*s == DISK_WRITER_VERIFY_PROGRESS) { + if (state == COPY) { + sub (_("Verifying copied files")); + state = VERIFY; } optional progress = _nanomsg.receive (500); if (progress) { diff --git a/src/lib/disk_writer_messages.h b/src/lib/disk_writer_messages.h index 9d8196374..8d0306754 100644 --- a/src/lib/disk_writer_messages.h +++ b/src/lib/disk_writer_messages.h @@ -26,7 +26,7 @@ /* REQUEST TO WRITE DCP */ // Front-end sends: - + #define DISK_WRITER_WRITE "W" // DCP pathname // Internal name of the drive to write to @@ -41,13 +41,17 @@ // Error message // Error number -// the drive is being formatted +// the drive is being formatted #define DISK_WRITER_FORMATTING "F" // data is being copied, 30% done -#define DISK_WRITER_PROGRESS "P" +#define DISK_WRITER_COPY_PROGRESS "C" // 0.3\n +// data is being veriried, 60% done +#define DISK_WRITER_VERIFY_PROGRESS "V" +// 0.6\n + /* REQUEST TO QUIT */ @@ -59,7 +63,7 @@ // Front-end sends: #define DISK_WRITER_UNMOUNT "U" -// XML representation of Drive object to unmount +// XML representation of Drive object to unmount // Back-end responds: // DISK_WRITER_OK diff --git a/src/tools/dcpomatic_disk_writer.cc b/src/tools/dcpomatic_disk_writer.cc index d5599f25b..bac5f9084 100644 --- a/src/tools/dcpomatic_disk_writer.cc +++ b/src/tools/dcpomatic_disk_writer.cc @@ -71,6 +71,7 @@ extern "C" { #include #include #include +#include #include using std::cin; @@ -78,6 +79,7 @@ using std::min; using std::string; using std::runtime_error; using std::exception; +using std::vector; using boost::optional; #ifdef DCPOMATIC_LINUX @@ -156,7 +158,7 @@ write (boost::filesystem::path from, boost::filesystem::path to, uint64_t& total ++progress_count; if ((progress_count % progress_frequency) == 0) { - nanomsg->send(String::compose(DISK_WRITER_PROGRESS "\n%1\n", (1 - float(total_remaining) / total)), SHORT_TIMEOUT); + nanomsg->send(String::compose(DISK_WRITER_COPY_PROGRESS "\n%1\n", (1 - float(total_remaining) / total)), SHORT_TIMEOUT); } } @@ -196,7 +198,7 @@ read (boost::filesystem::path from, boost::filesystem::path to, uint64_t& total_ digester.add (buffer, this_time); remaining -= this_time; total_remaining -= this_time; - nanomsg->send(String::compose(DISK_WRITER_PROGRESS "\n%1\n", (1 - float(total_remaining) / total)), SHORT_TIMEOUT); + nanomsg->send(String::compose(DISK_WRITER_VERIFY_PROGRESS "\n%1\n", (1 - float(total_remaining) / total)), SHORT_TIMEOUT); } ext4_fclose (&in); @@ -206,12 +208,28 @@ read (boost::filesystem::path from, boost::filesystem::path to, uint64_t& total_ } +class CopiedFile +{ +public: + CopiedFile (boost::filesystem::path from_, boost::filesystem::path to_, string write_digest_) + : from (from_) + , to (to_) + , write_digest (write_digest_) + {} + + boost::filesystem::path from; + boost::filesystem::path to; + /** digest calculated from data as it was read from the source during write */ + string write_digest; +}; + + /** @param from File to copy from. * @param to Directory to copy to. */ static void -copy (boost::filesystem::path from, boost::filesystem::path to, uint64_t& total_remaining, uint64_t total) +copy (boost::filesystem::path from, boost::filesystem::path to, uint64_t& total_remaining, uint64_t total, vector& copied_files) { LOG_DISK ("Copy %1 -> %2", from.string(), to.generic_string()); @@ -226,14 +244,25 @@ copy (boost::filesystem::path from, boost::filesystem::path to, uint64_t& total_ } for (directory_iterator i = directory_iterator(from); i != directory_iterator(); ++i) { - copy (i->path(), cr, total_remaining, total); + copy (i->path(), cr, total_remaining, total, copied_files); } } else { string const write_digest = write (from, cr, total_remaining, total); LOG_DISK ("Wrote %1 %2 with %3", from.string(), cr.generic_string(), write_digest); - string const read_digest = read (from, cr, total_remaining, total); - LOG_DISK ("Read %1 %2 with %3", from.string(), cr.generic_string(), write_digest); - if (write_digest != read_digest) { + copied_files.push_back (CopiedFile(from, cr, write_digest)); + } +} + + +static +void +verify (vector const& copied_files, uint64_t total) +{ + uint64_t total_remaining = total; + BOOST_FOREACH (CopiedFile const& i, copied_files) { + string const read_digest = read (i.from, i.to, total_remaining, total); + LOG_DISK ("Read %1 %2 was %3 on write, now %4", i.from.string(), i.to.generic_string(), i.write_digest, read_digest); + if (read_digest != i.write_digest) { throw VerifyError ("Hash of written data is incorrect", 0); } } @@ -349,11 +378,22 @@ try uint64_t total_bytes = 0; count (dcp_path, total_bytes); - /* XXX: this is a hack. We are going to "treat" every byte twice; write it, and then verify it. Double the - * bytes totals so that progress works itself out (assuming write is the same speed as read). - */ - total_bytes *= 2; - copy (dcp_path, "/mp", total_bytes, total_bytes); + uint64_t total_remaining = total_bytes; + vector copied_files; + copy (dcp_path, "/mp", total_remaining, total_bytes, copied_files); + + /* Unmount and re-mount to make sure the write has finished */ + r = ext4_umount("/mp/"); + if (r != EOK) { + throw CopyError ("Failed to unmount device", r); + } + r = ext4_mount("ext4_fs", "/mp/", false); + if (r != EOK) { + throw CopyError ("Failed to mount device", r); + } + LOG_DISK_NC ("Re-mounted device"); + + verify (copied_files, total_bytes); r = ext4_umount("/mp/"); if (r != EOK) { -- 2.30.2