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