src/lib/job.cc

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