src/tools/dcpomatic_disk_writer.cc

   1 /*
   2     Copyright (C) 2019-2020 Carl Hetherington <cth@carlh.net>
   3
   4     This file is part of DCP-o-matic.
   5
   6     DCP-o-matic is free software; you can redistribute it and/or modify
   7     it under the terms of the GNU General Public License as published by
   8     the Free Software Foundation; either version 2 of the License, or
   9     (at your option) any later version.
  10
  11     DCP-o-matic is distributed in the hope that it will be useful,
  12     but WITHOUT ANY WARRANTY; without even the implied warranty of
  13     MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  14     GNU General Public License for more details.
  15
  16     You should have received a copy of the GNU General Public License
  17     along with DCP-o-matic.  If not, see <http://www.gnu.org/licenses/>.
  18
  19 */
  20
  21 #include "lib/version.h"
  22 #include "lib/disk_writer_messages.h"
  23 #include "lib/compose.hpp"
  24 #include "lib/exceptions.h"
  25 #include "lib/cross.h"
  26 #include "lib/digester.h"
  27 #include "lib/file_log.h"
  28 #include "lib/dcpomatic_log.h"
  29 #include "lib/nanomsg.h"
  30 #include "lib/warnings.h"
  31 extern "C" {
  32 #include <lwext4/ext4_mbr.h>
  33 #include <lwext4/ext4_fs.h>
  34 #include <lwext4/ext4_mkfs.h>
  35 #include <lwext4/ext4_errno.h>
  36 #include <lwext4/ext4_debug.h>
  37 #include <lwext4/ext4.h>
  38 }
  39
  40 #ifdef DCPOMATIC_POSIX
  41 #include <sys/ioctl.h>
  42 #include <sys/types.h>
  43 #include <sys/stat.h>
  44 #endif
  45
  46 #ifdef DCPOMATIC_OSX
  47 #include "lib/stdout_log.h"
  48 #undef nil
  49 extern "C" {
  50 #include <lwext4/file_dev.h>
  51 }
  52 #include <xpc/xpc.h>
  53 #endif
  54
  55 #ifdef DCPOMATIC_LINUX
  56 #include <linux/fs.h>
  57 #include <polkit/polkit.h>
  58 extern "C" {
  59 #include <lwext4/file_dev.h>
  60 }
  61 #include <poll.h>
  62 #endif
  63
  64 #ifdef DCPOMATIC_WINDOWS
  65 extern "C" {
  66 #include <lwext4/file_windows.h>
  67 }
  68 #endif
  69
  70 DCPOMATIC_DISABLE_WARNINGS
  71 #include <glibmm.h>
  72 DCPOMATIC_ENABLE_WARNINGS
  73
  74 #include <unistd.h>
  75 #include <sys/types.h>
  76 #include <boost/filesystem.hpp>
  77 #include <boost/algorithm/string.hpp>
  78 #include <boost/foreach.hpp>
  79 #include <iostream>
  80 #include <stdlib.h>
  81
  82 using std::bad_alloc;
  83 using std::cin;
  84 using std::min;
  85 using std::string;
  86 using std::runtime_error;
  87 using std::exception;
  88 using std::vector;
  89 using boost::optional;
  90
  91 #ifdef DCPOMATIC_LINUX
  92 static PolkitAuthority* polkit_authority = 0;
  93 #endif
  94 static uint64_t const block_size = 4096 * 4096;
  95 static Nanomsg* nanomsg = 0;
  96
  97 #define SHORT_TIMEOUT 100
  98 #define LONG_TIMEOUT 2000
  99
 100 static
 101 void
 102 count (boost::filesystem::path dir, uint64_t& total_bytes)
 103 {
 104         using namespace boost::filesystem;
 105         for (directory_iterator i = directory_iterator(dir); i != directory_iterator(); ++i) {
 106                 if (is_directory(*i)) {
 107                         count (*i, total_bytes);
 108                 } else {
 109                         total_bytes += file_size (*i);
 110                 }
 111         }
 112 }
 113
 114 static
 115 string
 116 write (boost::filesystem::path from, boost::filesystem::path to, uint64_t& total_remaining, uint64_t total)
 117 {
 118         ext4_file out;
 119         int r = ext4_fopen(&out, to.generic_string().c_str(), "wb");
 120         if (r != EOK) {
 121                 throw CopyError (String::compose("Failed to open file %1", to.generic_string()), r);
 122         }
 123
 124         FILE* in = fopen_boost (from, "rb");
 125         if (!in) {
 126                 ext4_fclose (&out);
 127                 throw CopyError (String::compose("Failed to open file %1", from.string()), 0);
 128         }
 129
 130         uint8_t* buffer = reinterpret_cast<uint8_t*> (dcpomatic_aligned_alloc(block_size, 4096));
 131         if (!buffer) {
 132                 throw bad_alloc();
 133         }
 134         Digester digester;
 135
 136         int progress_frequency = 1;
 137         int progress_count = 0;
 138         uint64_t remaining = file_size (from);
 139         while (remaining > 0) {
 140                 std::cout << "write " << from << " " << remaining << " / " << total << "\n";
 141                 uint64_t const this_time = min(remaining, block_size);
 142                 size_t read = fread (buffer, 1, this_time, in);
 143                 if (read != this_time) {
 144                         fclose (in);
 145                         ext4_fclose (&out);
 146                         dcpomatic_aligned_free (buffer);
 147                         throw CopyError (String::compose("Short read; expected %1 but read %2", this_time, read), 0);
 148                 }
 149
 150                 digester.add (buffer, this_time);
 151
 152                 size_t written;
 153                 r = ext4_fwrite (&out, buffer, this_time, &written);
 154                 if (r != EOK) {
 155                         fclose (in);
 156                         ext4_fclose (&out);
 157                         dcpomatic_aligned_free (buffer);
 158                         throw CopyError ("Write failed", r);
 159                 }
 160                 if (written != this_time) {
 161                         fclose (in);
 162                         ext4_fclose (&out);
 163                         dcpomatic_aligned_free (buffer);
 164                         throw CopyError (String::compose("Short write; expected %1 but wrote %2", this_time, written), 0);
 165                 }
 166                 remaining -= this_time;
 167                 total_remaining -= this_time;
 168
 169                 ++progress_count;
 170                 if ((progress_count % progress_frequency) == 0) {
 171                         nanomsg->send(String::compose(DISK_WRITER_COPY_PROGRESS "\n%1\n", (1 - float(total_remaining) / total)), SHORT_TIMEOUT);
 172                 }
 173         }
 174
 175         fclose (in);
 176         ext4_fclose (&out);
 177         dcpomatic_aligned_free (buffer);
 178
 179         return digester.get ();
 180 }
 181
 182 static
 183 string
 184 read (boost::filesystem::path from, boost::filesystem::path to, uint64_t& total_remaining, uint64_t total)
 185 {
 186         ext4_file in;
 187         LOG_DISK("Opening %1 for read", to.generic_string());
 188         int r = ext4_fopen(&in, to.generic_string().c_str(), "rb");
 189         if (r != EOK) {
 190                 throw VerifyError (String::compose("Failed to open file %1", to.generic_string()), r);
 191         }
 192         LOG_DISK("Opened %1 for read", to.generic_string());
 193
 194         uint8_t* buffer = new uint8_t[block_size];
 195         Digester digester;
 196
 197         uint64_t remaining = file_size (from);
 198         while (remaining > 0) {
 199                 uint64_t const this_time = min(remaining, block_size);
 200                 size_t read;
 201                 r = ext4_fread (&in, buffer, this_time, &read);
 202                 if (read != this_time) {
 203                         ext4_fclose (&in);
 204                         delete[] buffer;
 205                         throw VerifyError (String::compose("Short read; expected %1 but read %2", this_time, read), 0);
 206                 }
 207
 208                 digester.add (buffer, this_time);
 209                 remaining -= this_time;
 210                 total_remaining -= this_time;
 211                 nanomsg->send(String::compose(DISK_WRITER_VERIFY_PROGRESS "\n%1\n", (1 - float(total_remaining) / total)), SHORT_TIMEOUT);
 212         }
 213
 214         ext4_fclose (&in);
 215         delete[] buffer;
 216
 217         return digester.get ();
 218 }
 219
 220
 221 class CopiedFile
 222 {
 223 public:
 224         CopiedFile (boost::filesystem::path from_, boost::filesystem::path to_, string write_digest_)
 225                 : from (from_)
 226                 , to (to_)
 227                 , write_digest (write_digest_)
 228         {}
 229
 230         boost::filesystem::path from;
 231         boost::filesystem::path to;
 232         /** digest calculated from data as it was read from the source during write */
 233         string write_digest;
 234 };
 235
 236
 237 /** @param from File to copy from.
 238  *  @param to Directory to copy to.
 239  */
 240 static
 241 void
 242 copy (boost::filesystem::path from, boost::filesystem::path to, uint64_t& total_remaining, uint64_t total, vector<CopiedFile>& copied_files)
 243 {
 244         LOG_DISK ("Copy %1 -> %2", from.string(), to.generic_string());
 245
 246         using namespace boost::filesystem;
 247
 248         path const cr = to / from.filename();
 249
 250         if (is_directory(from)) {
 251                 int r = ext4_dir_mk (cr.generic_string().c_str());
 252                 if (r != EOK) {
 253                         throw CopyError (String::compose("Failed to create directory %1", cr.generic_string()), r);
 254                 }
 255
 256                 for (directory_iterator i = directory_iterator(from); i != directory_iterator(); ++i) {
 257                         copy (i->path(), cr, total_remaining, total, copied_files);
 258                 }
 259         } else {
 260                 string const write_digest = write (from, cr, total_remaining, total);
 261                 LOG_DISK ("Wrote %1 %2 with %3", from.string(), cr.generic_string(), write_digest);
 262                 copied_files.push_back (CopiedFile(from, cr, write_digest));
 263         }
 264 }
 265
 266
 267 static
 268 void
 269 verify (vector<CopiedFile> const& copied_files, uint64_t total)
 270 {
 271         uint64_t total_remaining = total;
 272         BOOST_FOREACH (CopiedFile const& i, copied_files) {
 273                 string const read_digest = read (i.from, i.to, total_remaining, total);
 274                 LOG_DISK ("Read %1 %2 was %3 on write, now %4", i.from.string(), i.to.generic_string(), i.write_digest, read_digest);
 275                 if (read_digest != i.write_digest) {
 276                         throw VerifyError ("Hash of written data is incorrect", 0);
 277                 }
 278         }
 279 }
 280
 281
 282 static
 283 void
 284 write (boost::filesystem::path dcp_path, string device)
 285 try
 286 {
 287         ext4_dmask_set (DEBUG_ALL);
 288
 289         /* We rely on static initialization for these */
 290         static struct ext4_fs fs;
 291         static struct ext4_mkfs_info info;
 292         info.block_size = 4096;
 293         info.inode_size = 128;
 294         info.journal = false;
 295
 296 #ifdef WIN32
 297         file_windows_name_set(device.c_str());
 298         struct ext4_blockdev* bd = file_windows_dev_get();
 299 #else
 300         file_dev_name_set (device.c_str());
 301         struct ext4_blockdev* bd = file_dev_get ();
 302 #endif
 303
 304         if (!bd) {
 305                 throw CopyError ("Failed to open drive", 0);
 306         }
 307         LOG_DISK_NC ("Opened drive");
 308
 309         struct ext4_mbr_parts parts;
 310         parts.division[0] = 100;
 311         parts.division[1] = 0;
 312         parts.division[2] = 0;
 313         parts.division[3] = 0;
 314
 315 #ifdef DCPOMATIC_LINUX
 316         PrivilegeEscalator e;
 317 #endif
 318
 319         /* XXX: not sure if disk_id matters */
 320         int r = ext4_mbr_write (bd, &parts, 0);
 321         if (r) {
 322                 throw CopyError ("Failed to write MBR", r);
 323         }
 324         LOG_DISK_NC ("Wrote MBR");
 325
 326         struct ext4_mbr_bdevs bdevs;
 327         r = ext4_mbr_scan (bd, &bdevs);
 328         if (r != EOK) {
 329                 throw CopyError ("Failed to read MBR", r);
 330         }
 331
 332 #ifdef DCPOMATIC_WINDOWS
 333         file_windows_partition_set (bdevs.partitions[0].part_offset, bdevs.partitions[0].part_size);
 334 #endif
 335
 336         LOG_DISK ("Writing to partition at %1 size %2; bd part size is %3", bdevs.partitions[0].part_offset, bdevs.partitions[0].part_size, bd->part_size);
 337
 338 #ifdef DCPOMATIC_LINUX
 339         /* Re-read the partition table */
 340         int fd = open(device.c_str(), O_RDONLY);
 341         ioctl(fd, BLKRRPART, NULL);
 342         close(fd);
 343 #endif
 344
 345 #ifdef DCPOMATIC_LINUX
 346         string partition = device;
 347         /* XXX: don't know if this logic is sensible */
 348         if (partition.size() > 0 && isdigit(partition[partition.length() - 1])) {
 349                 partition += "p1";
 350         } else {
 351                 partition += "1";
 352         }
 353         file_dev_name_set (partition.c_str());
 354         bd = file_dev_get ();
 355 #endif
 356
 357 #ifdef DCPOMATIC_OSX
 358         string partition = device + "s1";
 359         file_dev_name_set (partition.c_str());
 360         bd = file_dev_get ();
 361 #endif
 362
 363         if (!bd) {
 364                 throw CopyError ("Failed to open partition", 0);
 365         }
 366         LOG_DISK_NC ("Opened partition");
 367
 368         nanomsg->send(DISK_WRITER_FORMATTING "\n", SHORT_TIMEOUT);
 369
 370         r = ext4_mkfs(&fs, bd, &info, F_SET_EXT2);
 371         if (r != EOK) {
 372                 throw CopyError ("Failed to make filesystem", r);
 373         }
 374         LOG_DISK_NC ("Made filesystem");
 375
 376         r = ext4_device_register(bd, "ext4_fs");
 377         if (r != EOK) {
 378                 throw CopyError ("Failed to register device", r);
 379         }
 380         LOG_DISK_NC ("Registered device");
 381
 382         r = ext4_mount("ext4_fs", "/mp/", false);
 383         if (r != EOK) {
 384                 throw CopyError ("Failed to mount device", r);
 385         }
 386         LOG_DISK_NC ("Mounted device");
 387
 388         uint64_t total_bytes = 0;
 389         count (dcp_path, total_bytes);
 390
 391         uint64_t total_remaining = total_bytes;
 392         vector<CopiedFile> copied_files;
 393         copy (dcp_path, "/mp", total_remaining, total_bytes, copied_files);
 394
 395         /* Unmount and re-mount to make sure the write has finished */
 396         r = ext4_umount("/mp/");
 397         if (r != EOK) {
 398                 throw CopyError ("Failed to unmount device", r);
 399         }
 400         r = ext4_mount("ext4_fs", "/mp/", false);
 401         if (r != EOK) {
 402                 throw CopyError ("Failed to mount device", r);
 403         }
 404         LOG_DISK_NC ("Re-mounted device");
 405
 406         verify (copied_files, total_bytes);
 407
 408         r = ext4_umount("/mp/");
 409         if (r != EOK) {
 410                 throw CopyError ("Failed to unmount device", r);
 411         }
 412
 413         ext4_device_unregister("ext4_fs");
 414         if (!nanomsg->send(DISK_WRITER_OK "\n", LONG_TIMEOUT)) {
 415                 throw CommunicationFailedError ();
 416         }
 417
 418         disk_write_finished ();
 419 } catch (CopyError& e) {
 420         LOG_DISK("CopyError (from write): %1 %2", e.message(), e.number().get_value_or(0));
 421         nanomsg->send(String::compose(DISK_WRITER_ERROR "\n%1\n%2\n", e.message(), e.number().get_value_or(0)), LONG_TIMEOUT);
 422 } catch (VerifyError& e) {
 423         LOG_DISK("VerifyError (from write): %1 %2", e.message(), e.number());
 424         nanomsg->send(String::compose(DISK_WRITER_ERROR "\n%1\n%2\n", e.message(), e.number()), LONG_TIMEOUT);
 425 } catch (exception& e) {
 426         LOG_DISK("Exception (from write): %1", e.what());
 427         nanomsg->send(String::compose(DISK_WRITER_ERROR "\n%1\n0\n", e.what()), LONG_TIMEOUT);
 428 }
 429
 430 struct Parameters
 431 {
 432         boost::filesystem::path dcp_path;
 433         std::string device;
 434 };
 435
 436 #ifdef DCPOMATIC_LINUX
 437 static
 438 void
 439 polkit_callback (GObject *, GAsyncResult* res, gpointer data)
 440 {
 441         Parameters* parameters = reinterpret_cast<Parameters*> (data);
 442         PolkitAuthorizationResult* result = polkit_authority_check_authorization_finish (polkit_authority, res, 0);
 443         if (result && polkit_authorization_result_get_is_authorized(result)) {
 444                 write (parameters->dcp_path, parameters->device);
 445         }
 446         delete parameters;
 447         if (result) {
 448                 g_object_unref (result);
 449         }
 450 }
 451 #endif
 452
 453
 454 bool
 455 idle ()
 456 try
 457 {
 458         using namespace boost::algorithm;
 459
 460         optional<string> s = nanomsg->receive (0);
 461         if (!s) {
 462                 return true;
 463         }
 464
 465         LOG_DISK("Writer receives command: %1", *s);
 466
 467         if (*s == DISK_WRITER_QUIT) {
 468                 exit (EXIT_SUCCESS);
 469         } else if (*s == DISK_WRITER_UNMOUNT) {
 470                 /* XXX: should do Linux polkit stuff here */
 471                 optional<string> xml_head = nanomsg->receive (LONG_TIMEOUT);
 472                 optional<string> xml_body = nanomsg->receive (LONG_TIMEOUT);
 473                 if (!xml_head || !xml_body) {
 474                         LOG_DISK_NC("Failed to receive unmount request");
 475                         throw CommunicationFailedError ();
 476                 }
 477                 bool const success = Drive(*xml_head + *xml_body).unmount();
 478                 if (!nanomsg->send (success ? (DISK_WRITER_OK "\n") : (DISK_WRITER_ERROR "\n"), LONG_TIMEOUT)) {
 479                         LOG_DISK_NC("CommunicationFailedError in unmount_finished");
 480                         throw CommunicationFailedError ();
 481                 }
 482         } else if (*s == DISK_WRITER_WRITE) {
 483                 optional<string> dcp_path = nanomsg->receive (LONG_TIMEOUT);
 484                 optional<string> device = nanomsg->receive (LONG_TIMEOUT);
 485                 if (!dcp_path || !device) {
 486                         LOG_DISK_NC("Failed to receive write request");
 487                         throw CommunicationFailedError();
 488                 }
 489
 490                 /* Do some basic sanity checks; this is a bit belt-and-braces but it can't hurt... */
 491
 492 #ifdef DCPOMATIC_OSX
 493                 if (!starts_with(*device, "/dev/disk")) {
 494                         LOG_DISK ("Will not write to %1", *device);
 495                         nanomsg->send(DISK_WRITER_ERROR "\nRefusing to write to this drive\n1\n", LONG_TIMEOUT);
 496                         return true;
 497                 }
 498 #endif
 499 #ifdef DCPOMATIC_LINUX
 500                 if (!starts_with(*device, "/dev/sd") && !starts_with(*device, "/dev/hd")) {
 501                         LOG_DISK ("Will not write to %1", *device);
 502                         nanomsg->send(DISK_WRITER_ERROR "\nRefusing to write to this drive\n1\n", LONG_TIMEOUT);
 503                         return true;
 504                 }
 505 #endif
 506 #ifdef DCPOMATIC_WINDOWS
 507                 if (!starts_with(*device, "\\\\.\\PHYSICALDRIVE")) {
 508                         LOG_DISK ("Will not write to %1", *device);
 509                         nanomsg->send(DISK_WRITER_ERROR "\nRefusing to write to this drive\n1\n", LONG_TIMEOUT);
 510                         return true;
 511                 }
 512 #endif
 513
 514                 bool on_drive_list = false;
 515                 bool mounted = false;
 516                 for (auto const& i: Drive::get()) {
 517                         if (i.device() == *device) {
 518                                 on_drive_list = true;
 519                                 mounted = i.mounted();
 520                         }
 521                 }
 522
 523                 if (!on_drive_list) {
 524                         LOG_DISK ("Will not write to %1 as it's not recognised as a drive", *device);
 525                         nanomsg->send(DISK_WRITER_ERROR "\nRefusing to write to this drive\n1\n", LONG_TIMEOUT);
 526                         return true;
 527                 }
 528                 if (mounted) {
 529                         LOG_DISK ("Will not write to %1 as it's mounted", *device);
 530                         nanomsg->send(DISK_WRITER_ERROR "\nRefusing to write to this drive\n1\n", LONG_TIMEOUT);
 531                         return true;
 532                 }
 533
 534                 LOG_DISK ("Here we go writing %1 to %2", *dcp_path, *device);
 535
 536 #ifdef DCPOMATIC_LINUX
 537                 polkit_authority = polkit_authority_get_sync (0, 0);
 538                 PolkitSubject* subject = polkit_unix_process_new_for_owner (getppid(), 0, -1);
 539                 Parameters* parameters = new Parameters;
 540                 parameters->dcp_path = *dcp_path;
 541                 parameters->device = *device;
 542                 polkit_authority_check_authorization (
 543                                 polkit_authority, subject, "com.dcpomatic.write-drive", 0, POLKIT_CHECK_AUTHORIZATION_FLAGS_ALLOW_USER_INTERACTION, 0, polkit_callback, parameters
 544                                 );
 545 #else
 546                 write (*dcp_path, *device);
 547 #endif
 548         }
 549
 550         return true;
 551 } catch (exception& e) {
 552         LOG_DISK("Exception (from idle): %1", e.what());
 553         return true;
 554 }
 555
 556 int
 557 main ()
 558 {
 559 #ifdef DCPOMATIC_OSX
 560         /* On macOS this is running as root, so config_path() will be somewhere in root's
 561          * home.  Instead, just write to stdout as the macOS process control stuff will
 562          * redirect this to a file in /var/log
 563          */
 564         dcpomatic_log.reset(new StdoutLog(LogEntry::TYPE_DISK));
 565         LOG_DISK("dcpomatic_disk_writer %1 started", dcpomatic_git_commit);
 566 #else
 567         /* XXX: this is a hack, but I expect we'll need logs and I'm not sure if there's
 568          * a better place to put them.
 569          */
 570         dcpomatic_log.reset(new FileLog(config_path() / "disk_writer.log", LogEntry::TYPE_DISK));
 571         LOG_DISK_NC("dcpomatic_disk_writer started");
 572 #endif
 573
 574 #ifdef DCPOMATIC_OSX
 575         /* I *think* this confumes the notifyd event that we used to start the process, so we only
 576          * get started once per notification.
 577          */
 578         xpc_set_event_stream_handler("com.apple.notifyd.matching", DISPATCH_TARGET_QUEUE_DEFAULT, ^(xpc_object_t) {});
 579 #endif
 580
 581         try {
 582                 nanomsg = new Nanomsg (false);
 583         } catch (runtime_error& e) {
 584                 LOG_DISK_NC("Could not set up nanomsg socket");
 585                 exit (EXIT_FAILURE);
 586         }
 587
 588         Glib::RefPtr<Glib::MainLoop> ml = Glib::MainLoop::create ();
 589         Glib::signal_timeout().connect(sigc::ptr_fun(&idle), 500);
 590         ml->run ();
 591 }