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