src/lib/job.cc

   1 /*
   2     Copyright (C) 2012-2021 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 /** @file  src/job.cc
  22  *  @brief A parent class to represent long-running tasks which are run in their own thread.
  23  */
  24
  25 #include "job.h"
  26 #include "util.h"
  27 #include "cross.h"
  28 #include "exceptions.h"
  29 #include "film.h"
  30 #include "log.h"
  31 #include "dcpomatic_log.h"
  32 #include "compose.hpp"
  33 #include <dcp/exceptions.h>
  34 #include <sub/exceptions.h>
  35 #include <boost/thread.hpp>
  36 #include <boost/filesystem.hpp>
  37 #include <boost/date_time/posix_time/posix_time.hpp>
  38 #include <iostream>
  39
  40 #include "i18n.h"
  41
  42 using std::string;
  43 using std::list;
  44 using std::cout;
  45 using std::shared_ptr;
  46 using boost::optional;
  47 using boost::function;
  48 using namespace dcpomatic;
  49
  50 /** @param film Associated film, or 0 */
  51 Job::Job (shared_ptr<const Film> film)
  52         : _film (film)
  53         , _state (NEW)
  54         , _start_time (0)
  55         , _sub_start_time (0)
  56         , _progress (0)
  57         , _ran_for (0)
  58 {
  59
  60 }
  61
  62 Job::~Job ()
  63 {
  64 #ifdef DCPOMATIC_DEBUG
  65         /* Any subclass should have called stop_thread in its destructor */
  66         assert (!_thread.joinable());
  67 #endif
  68 }
  69
  70 void
  71 Job::stop_thread ()
  72 {
  73         boost::this_thread::disable_interruption dis;
  74
  75         _thread.interrupt ();
  76         try {
  77                 _thread.join ();
  78         } catch (...) {}
  79 }
  80
  81 /** Start the job in a separate thread, returning immediately */
  82 void
  83 Job::start ()
  84 {
  85         set_state (RUNNING);
  86         _start_time = time (0);
  87         _sub_start_time = time (0);
  88         _thread = boost::thread (boost::bind(&Job::run_wrapper, this));
  89 #ifdef DCPOMATIC_LINUX
  90         pthread_setname_np (_thread.native_handle(), "job-wrapper");
  91 #endif
  92 }
  93
  94 /** A wrapper for the ::run() method to catch exceptions */
  95 void
  96 Job::run_wrapper ()
  97 {
  98         try {
  99
 100                 run ();
 101
 102         } catch (dcp::FileError& e) {
 103
 104                 string m = String::compose (_("An error occurred whilst handling the file %1."), boost::filesystem::path (e.filename()).leaf());
 105
 106                 try {
 107                         auto const s = boost::filesystem::space (e.filename());
 108                         if (s.available < pow (1024, 3)) {
 109                                 m += N_("\n\n");
 110                                 m += _("The drive that the film is stored on is low in disc space.  Free some more space and try again.");
 111                         }
 112                 } catch (...) {
 113
 114                 }
 115
 116                 set_error (e.what(), m);
 117                 set_progress (1);
 118                 set_state (FINISHED_ERROR);
 119
 120         } catch (dcp::StartCompressionError& e) {
 121
 122                 bool done = false;
 123
 124 #ifdef DCPOMATIC_WINDOWS
 125 #if (__GNUC__ && !__x86_64__)
 126                 /* 32-bit */
 127                 set_error (
 128                         _("Failed to encode the DCP."),
 129                         _("This error has probably occurred because you are running the 32-bit version of DCP-o-matic and "
 130                           "trying to use too many encoding threads.  Please reduce the 'number of threads DCP-o-matic should "
 131                           "use' in the General tab of Preferences and try again.")
 132                         );
 133                 done = true;
 134 #else
 135                 /* 64-bit */
 136                 if (running_32_on_64()) {
 137                         set_error (
 138                                 _("Failed to encode the DCP."),
 139                                 _("This error has probably occurred because you are running the 32-bit version of DCP-o-matic.  Please re-install DCP-o-matic with the 64-bit installer and try again.")
 140                                 );
 141                         done = true;
 142                 }
 143 #endif
 144 #endif
 145
 146                 if (!done) {
 147                         set_error (
 148                                 e.what (),
 149                                 string (_("It is not known what caused this error.")) + "  " + REPORT_PROBLEM
 150                                 );
 151                 }
 152
 153                 set_progress (1);
 154                 set_state (FINISHED_ERROR);
 155
 156         } catch (OpenFileError& e) {
 157
 158                 set_error (
 159                         String::compose (_("Could not open %1"), e.file().string()),
 160                         String::compose (
 161                                 _("DCP-o-matic could not open the file %1 (%2).  Perhaps it does not exist or is in an unexpected format."),
 162                                 boost::filesystem::absolute (e.file()).string(),
 163                                 e.what()
 164                                 )
 165                         );
 166
 167                 set_progress (1);
 168                 set_state (FINISHED_ERROR);
 169
 170         } catch (boost::filesystem::filesystem_error& e) {
 171
 172                 if (e.code() == boost::system::errc::no_such_file_or_directory) {
 173                         set_error (
 174                                 String::compose (_("Could not open %1"), e.path1().string ()),
 175                                 String::compose (
 176                                         _("DCP-o-matic could not open the file %1 (%2).  Perhaps it does not exist or is in an unexpected format."),
 177                                         boost::filesystem::absolute (e.path1()).string(),
 178                                         e.what()
 179                                         )
 180                                 );
 181                 } else {
 182                         set_error (
 183                                 e.what (),
 184                                 string (_("It is not known what caused this error.")) + "  " + REPORT_PROBLEM
 185                                 );
 186                 }
 187
 188                 set_progress (1);
 189                 set_state (FINISHED_ERROR);
 190
 191         } catch (boost::thread_interrupted &) {
 192
 193                 set_state (FINISHED_CANCELLED);
 194
 195         } catch (sub::SubripError& e) {
 196
 197                 string extra = "Error is near:\n";
 198                 for (auto i: e.context()) {
 199                         extra += i + "\n";
 200                 }
 201
 202                 set_error (e.what (), extra);
 203                 set_progress (1);
 204                 set_state (FINISHED_ERROR);
 205
 206         } catch (std::bad_alloc& e) {
 207
 208                 set_error (_("Out of memory"), _("There was not enough memory to do this.  If you are running a 32-bit operating system try reducing the number of encoding threads in the General tab of Preferences."));
 209                 set_progress (1);
 210                 set_state (FINISHED_ERROR);
 211
 212         } catch (dcp::ReadError& e) {
 213
 214                 set_error (e.message(), e.detail().get_value_or(""));
 215                 set_progress (1);
 216                 set_state (FINISHED_ERROR);
 217
 218         } catch (KDMError& e) {
 219
 220                 set_error (e.summary(), e.detail());
 221                 set_progress (1);
 222                 set_state (FINISHED_ERROR);
 223
 224         } catch (FileError& e) {
 225
 226                 set_error (e.what(), e.what());
 227                 set_progress (1);
 228                 set_state (FINISHED_ERROR);
 229
 230         } catch (std::exception& e) {
 231
 232                 set_error (
 233                         e.what (),
 234                         string (_("It is not known what caused this error.")) + "  " + REPORT_PROBLEM
 235                         );
 236
 237                 set_progress (1);
 238                 set_state (FINISHED_ERROR);
 239
 240         } catch (...) {
 241
 242                 set_error (
 243                         _("Unknown error"),
 244                         string (_("It is not known what caused this error.")) + "  " + REPORT_PROBLEM
 245                         );
 246
 247                 set_progress (1);
 248                 set_state (FINISHED_ERROR);
 249         }
 250 }
 251
 252 /** @return true if this job is new (ie has not started running) */
 253 bool
 254 Job::is_new () const
 255 {
 256         boost::mutex::scoped_lock lm (_state_mutex);
 257         return _state == NEW;
 258 }
 259
 260 /** @return true if the job is running */
 261 bool
 262 Job::running () const
 263 {
 264         boost::mutex::scoped_lock lm (_state_mutex);
 265         return _state == RUNNING;
 266 }
 267
 268 /** @return true if the job has finished (either successfully or unsuccessfully) */
 269 bool
 270 Job::finished () const
 271 {
 272         boost::mutex::scoped_lock lm (_state_mutex);
 273         return _state == FINISHED_OK || _state == FINISHED_ERROR || _state == FINISHED_CANCELLED;
 274 }
 275
 276 /** @return true if the job has finished successfully */
 277 bool
 278 Job::finished_ok () const
 279 {
 280         boost::mutex::scoped_lock lm (_state_mutex);
 281         return _state == FINISHED_OK;
 282 }
 283
 284 /** @return true if the job has finished unsuccessfully */
 285 bool
 286 Job::finished_in_error () const
 287 {
 288         boost::mutex::scoped_lock lm (_state_mutex);
 289         return _state == FINISHED_ERROR;
 290 }
 291
 292 bool
 293 Job::finished_cancelled () const
 294 {
 295         boost::mutex::scoped_lock lm (_state_mutex);
 296         return _state == FINISHED_CANCELLED;
 297 }
 298
 299 bool
 300 Job::paused_by_user () const
 301 {
 302         boost::mutex::scoped_lock lm (_state_mutex);
 303         return _state == PAUSED_BY_USER;
 304 }
 305
 306 bool
 307 Job::paused_by_priority () const
 308 {
 309         boost::mutex::scoped_lock lm (_state_mutex);
 310         return _state == PAUSED_BY_PRIORITY;
 311 }
 312
 313 /** Set the state of this job.
 314  *  @param s New state.
 315  */
 316 void
 317 Job::set_state (State s)
 318 {
 319         bool finished = false;
 320
 321         {
 322                 boost::mutex::scoped_lock lm (_state_mutex);
 323                 _state = s;
 324
 325                 if (_state == FINISHED_OK || _state == FINISHED_ERROR || _state == FINISHED_CANCELLED) {
 326                         _ran_for = time(0) - _start_time;
 327                         finished = true;
 328                         _sub_name.clear ();
 329                 }
 330         }
 331
 332         if (finished) {
 333                 emit (boost::bind (boost::ref (Finished)));
 334                 FinishedImmediate ();
 335         }
 336 }
 337
 338 /** @return DCPTime (in seconds) that this sub-job has been running */
 339 int
 340 Job::elapsed_sub_time () const
 341 {
 342         if (_sub_start_time == 0) {
 343                 return 0;
 344         }
 345
 346         return time (0) - _sub_start_time;
 347 }
 348
 349 /** Check to see if this job has been interrupted or paused */
 350 void
 351 Job::check_for_interruption_or_pause ()
 352 {
 353         boost::this_thread::interruption_point ();
 354
 355         boost::mutex::scoped_lock lm (_state_mutex);
 356         while (_state == PAUSED_BY_USER || _state == PAUSED_BY_PRIORITY) {
 357                 emit (boost::bind (boost::ref (Progress)));
 358                 _pause_changed.wait (lm);
 359         }
 360 }
 361
 362 /** Set the progress of the current part of the job.
 363  *  @param p Progress (from 0 to 1)
 364  *  @param force Do not ignore this update, even if it hasn't been long since the last one.
 365  */
 366 void
 367 Job::set_progress (float p, bool force)
 368 {
 369         check_for_interruption_or_pause ();
 370
 371         if (!force) {
 372                 /* Check for excessively frequent progress reporting */
 373                 boost::mutex::scoped_lock lm (_progress_mutex);
 374                 struct timeval now;
 375                 gettimeofday (&now, 0);
 376                 if (_last_progress_update && _last_progress_update->tv_sec > 0) {
 377                         double const elapsed = (now.tv_sec + now.tv_usec / 1000000.0)
 378                                 - (_last_progress_update->tv_sec + _last_progress_update->tv_usec / 1000000.0);
 379                         if (elapsed < 0.5) {
 380                                 return;
 381                         }
 382                 }
 383                 _last_progress_update = now;
 384         }
 385
 386         set_progress_common (p);
 387 }
 388
 389 void
 390 Job::set_progress_common (optional<float> p)
 391 {
 392         {
 393                 boost::mutex::scoped_lock lm (_progress_mutex);
 394                 _progress = p;
 395         }
 396
 397         emit (boost::bind (boost::ref (Progress)));
 398 }
 399
 400 /** @return fractional progress of the current sub-job, if known */
 401 optional<float>
 402 Job::progress () const
 403 {
 404         boost::mutex::scoped_lock lm (_progress_mutex);
 405         return _progress;
 406 }
 407
 408 void
 409 Job::sub (string n)
 410 {
 411         {
 412                 boost::mutex::scoped_lock lm (_progress_mutex);
 413                 LOG_GENERAL ("Sub-job %1 starting", n);
 414                 _sub_name = n;
 415         }
 416
 417         set_progress (0, true);
 418         _sub_start_time = time (0);
 419 }
 420
 421 string
 422 Job::error_details () const
 423 {
 424         boost::mutex::scoped_lock lm (_state_mutex);
 425         return _error_details;
 426 }
 427
 428 /** @return A summary of any error that the job has generated */
 429 string
 430 Job::error_summary () const
 431 {
 432         boost::mutex::scoped_lock lm (_state_mutex);
 433         return _error_summary;
 434 }
 435
 436 /** Set the current error string.
 437  *  @param s New error string.
 438  *  @param d New error detail string.
 439  */
 440 void
 441 Job::set_error (string s, string d)
 442 {
 443         if (_film) {
 444                 _film->log()->log (String::compose ("Error in job: %1 (%2)", s, d), LogEntry::TYPE_ERROR);
 445         }
 446
 447         boost::mutex::scoped_lock lm (_state_mutex);
 448         _error_summary = s;
 449         _error_details = d;
 450 }
 451
 452 /** Say that this job's progress will be unknown until further notice */
 453 void
 454 Job::set_progress_unknown ()
 455 {
 456         check_for_interruption_or_pause ();
 457         set_progress_common (optional<float> ());
 458 }
 459
 460 /** @return Human-readable status of this job */
 461 string
 462 Job::status () const
 463 {
 464         optional<float> p = progress ();
 465         int const t = elapsed_sub_time ();
 466         int const r = remaining_time ();
 467
 468         string s;
 469         if (!finished () && p) {
 470                 int pc = lrintf (p.get() * 100);
 471                 if (pc == 100) {
 472                         /* 100% makes it sound like we've finished when we haven't */
 473                         pc = 99;
 474                 }
 475
 476                 char buffer[64];
 477                 snprintf (buffer, sizeof(buffer), "%d%%", pc);
 478                 s += buffer;
 479
 480                 if (t > 10 && r > 0) {
 481                         auto now = boost::posix_time::second_clock::local_time();
 482                         auto finish = now + boost::posix_time::seconds(r);
 483                         char finish_string[16];
 484                         snprintf (finish_string, sizeof(finish_string), "%02d:%02d", int(finish.time_of_day().hours()), int(finish.time_of_day().minutes()));
 485                         string day;
 486                         if (now.date() != finish.date()) {
 487                                 /// TRANSLATORS: the %1 in this string will be filled in with a day of the week
 488                                 /// to say what day a job will finish.
 489                                 day = String::compose (_(" on %1"), day_of_week_to_string(finish.date().day_of_week()));
 490                         }
 491                         /// TRANSLATORS: "remaining; finishing at" here follows an amount of time that is remaining
 492                         /// on an operation; after it is an estimated wall-clock completion time.
 493                         s += String::compose(
 494                                 _("; %1 remaining; finishing at %2%3"),
 495                                 seconds_to_approximate_hms(r), finish_string, day
 496                                 );
 497                 }
 498         } else if (finished_ok ()) {
 499                 s = String::compose (_("OK (ran for %1)"), seconds_to_hms (_ran_for));
 500         } else if (finished_in_error ()) {
 501                 s = String::compose (_("Error: %1"), error_summary ());
 502         } else if (finished_cancelled ()) {
 503                 s = _("Cancelled");
 504         }
 505
 506         return s;
 507 }
 508
 509 string
 510 Job::json_status () const
 511 {
 512         boost::mutex::scoped_lock lm (_state_mutex);
 513
 514         switch (_state) {
 515         case NEW:
 516                 return N_("new");
 517         case RUNNING:
 518                 return N_("running");
 519         case PAUSED_BY_USER:
 520         case PAUSED_BY_PRIORITY:
 521                 return N_("paused");
 522         case FINISHED_OK:
 523                 return N_("finished_ok");
 524         case FINISHED_ERROR:
 525                 return N_("finished_error");
 526         case FINISHED_CANCELLED:
 527                 return N_("finished_cancelled");
 528         }
 529
 530         return "";
 531 }
 532
 533 /** @return An estimate of the remaining time for this sub-job, in seconds */
 534 int
 535 Job::remaining_time () const
 536 {
 537         if (progress().get_value_or(0) == 0) {
 538                 return elapsed_sub_time ();
 539         }
 540
 541         return elapsed_sub_time() / progress().get() - elapsed_sub_time();
 542 }
 543
 544 void
 545 Job::cancel ()
 546 {
 547         if (!_thread.joinable()) {
 548                 return;
 549         }
 550
 551         if (paused_by_user() || paused_by_priority()) {
 552                 resume ();
 553         }
 554
 555         _thread.interrupt ();
 556         _thread.join ();
 557 }
 558
 559 /** @return true if the job was paused, false if it was not running */
 560 bool
 561 Job::pause_by_user ()
 562 {
 563         bool paused = false;
 564         {
 565                 boost::mutex::scoped_lock lm (_state_mutex);
 566                 /* We can set _state here directly because we have a lock and we aren't
 567                    setting the job to FINISHED_*
 568                 */
 569                 if (_state == RUNNING) {
 570                         paused = true;
 571                         _state = PAUSED_BY_USER;
 572                 }
 573         }
 574
 575         if (paused) {
 576                 _pause_changed.notify_all ();
 577         }
 578
 579         return paused;
 580 }
 581
 582 void
 583 Job::pause_by_priority ()
 584 {
 585         if (running ()) {
 586                 set_state (PAUSED_BY_PRIORITY);
 587                 _pause_changed.notify_all ();
 588         }
 589 }
 590
 591 void
 592 Job::resume ()
 593 {
 594         if (paused_by_user() || paused_by_priority()) {
 595                 set_state (RUNNING);
 596                 _pause_changed.notify_all ();
 597         }
 598 }
 599
 600 void
 601 Job::when_finished (boost::signals2::connection& connection, function<void()> finished)
 602 {
 603         boost::mutex::scoped_lock lm (_state_mutex);
 604         if (_state == FINISHED_OK || _state == FINISHED_ERROR || _state == FINISHED_CANCELLED) {
 605                 finished ();
 606         } else {
 607                 connection = Finished.connect (finished);
 608         }
 609 }
 610
 611 optional<string>
 612 Job::message () const
 613 {
 614         boost::mutex::scoped_lock lm (_state_mutex);
 615         return _message;
 616 }
 617
 618 void
 619 Job::set_message (string m)
 620 {
 621         boost::mutex::scoped_lock lm (_state_mutex);
 622         _message = m;
 623 }