Catch CPLNotFoundError more nicely.
[dcpomatic.git] / src / lib / job.cc
index dba21f91cdf031362116468df543cca9eda19062..8ce63ced0213d66ea2c03dce79bd3a29579562d0 100644 (file)
@@ -1,5 +1,5 @@
 /*
-    Copyright (C) 2012-2016 Carl Hetherington <cth@carlh.net>
+    Copyright (C) 2012-2021 Carl Hetherington <cth@carlh.net>
 
     This file is part of DCP-o-matic.
 
 
 */
 
+
 /** @file  src/job.cc
  *  @brief A parent class to represent long-running tasks which are run in their own thread.
  */
 
-#include "job.h"
-#include "util.h"
+
+#include "compose.hpp"
 #include "cross.h"
+#include "dcpomatic_log.h"
 #include "exceptions.h"
 #include "film.h"
+#include "job.h"
 #include "log.h"
-#include "compose.hpp"
+#include "util.h"
 #include <dcp/exceptions.h>
 #include <sub/exceptions.h>
-#include <boost/thread.hpp>
-#include <boost/filesystem.hpp>
-#include <boost/foreach.hpp>
 #include <boost/date_time/posix_time/posix_time.hpp>
+#include <boost/filesystem.hpp>
+#include <boost/thread.hpp>
 #include <iostream>
 
 #include "i18n.h"
 
-using std::string;
-using std::list;
+
 using std::cout;
-using boost::shared_ptr;
+using std::function;
+using std::list;
+using std::shared_ptr;
+using std::string;
 using boost::optional;
-using boost::function;
+using namespace dcpomatic;
 
-#define LOG_ERROR_NC(...) if (_film) { _film->log()->log (__VA_ARGS__, LogEntry::TYPE_ERROR); }
-#define LOG_GENERAL(...) if (_film) { _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_GENERAL); }
 
 /** @param film Associated film, or 0 */
 Job::Job (shared_ptr<const Film> film)
        : _film (film)
-       , _thread (0)
        , _state (NEW)
        , _start_time (0)
        , _sub_start_time (0)
@@ -62,23 +63,28 @@ Job::Job (shared_ptr<const Film> film)
 
 }
 
+
 Job::~Job ()
 {
-       if (_thread) {
-               _thread->interrupt ();
-               /* We can't use DCPOMATIC_ASSERT here as it may throw an exception */
-               if (_thread->joinable ()) {
-                       try {
-                               _thread->join ();
-                       } catch (...) {
-                               /* Too late to do anything about this */
-                       }
-               }
-       }
+#ifdef DCPOMATIC_DEBUG
+       /* Any subclass should have called stop_thread in its destructor */
+       assert (!_thread.joinable());
+#endif
+}
+
+
+void
+Job::stop_thread ()
+{
+       boost::this_thread::disable_interruption dis;
 
-       delete _thread;
+       _thread.interrupt ();
+       try {
+               _thread.join ();
+       } catch (...) {}
 }
 
+
 /** Start the job in a separate thread, returning immediately */
 void
 Job::start ()
@@ -86,13 +92,19 @@ Job::start ()
        set_state (RUNNING);
        _start_time = time (0);
        _sub_start_time = time (0);
-       _thread = new boost::thread (boost::bind (&Job::run_wrapper, this));
+       _thread = boost::thread (boost::bind(&Job::run_wrapper, this));
+#ifdef DCPOMATIC_LINUX
+       pthread_setname_np (_thread.native_handle(), "job-wrapper");
+#endif
 }
 
+
 /** A wrapper for the ::run() method to catch exceptions */
 void
 Job::run_wrapper ()
 {
+       start_of_thread (String::compose("Job-%1", json_name()));
+
        try {
 
                run ();
@@ -102,7 +114,7 @@ Job::run_wrapper ()
                string m = String::compose (_("An error occurred whilst handling the file %1."), boost::filesystem::path (e.filename()).leaf());
 
                try {
-                       boost::filesystem::space_info const s = boost::filesystem::space (e.filename());
+                       auto const s = boost::filesystem::space (e.filename());
                        if (s.available < pow (1024, 3)) {
                                m += N_("\n\n");
                                m += _("The drive that the film is stored on is low in disc space.  Free some more space and try again.");
@@ -115,13 +127,50 @@ Job::run_wrapper ()
                set_progress (1);
                set_state (FINISHED_ERROR);
 
+       } catch (dcp::StartCompressionError& e) {
+
+               bool done = false;
+
+#ifdef DCPOMATIC_WINDOWS
+#if (__GNUC__ && !__x86_64__)
+               /* 32-bit */
+               set_error (
+                       _("Failed to encode the DCP."),
+                       _("This error has probably occurred because you are running the 32-bit version of DCP-o-matic and "
+                         "trying to use too many encoding threads.  Please reduce the 'number of threads DCP-o-matic should "
+                         "use' in the General tab of Preferences and try again.")
+                       );
+               done = true;
+#else
+               /* 64-bit */
+               if (running_32_on_64()) {
+                       set_error (
+                               _("Failed to encode the DCP."),
+                               _("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.")
+                               );
+                       done = true;
+               }
+#endif
+#endif
+
+               if (!done) {
+                       set_error (
+                               e.what (),
+                               string (_("It is not known what caused this error.")) + "  " + REPORT_PROBLEM
+                               );
+               }
+
+               set_progress (1);
+               set_state (FINISHED_ERROR);
+
        } catch (OpenFileError& e) {
 
                set_error (
                        String::compose (_("Could not open %1"), e.file().string()),
                        String::compose (
-                               _("DCP-o-matic could not open the file %1.  Perhaps it does not exist or is in an unexpected format."),
-                               boost::filesystem::absolute (e.file()).string()
+                               _("DCP-o-matic could not open the file %1 (%2).  Perhaps it does not exist or is in an unexpected format."),
+                               boost::filesystem::absolute (e.file()).string(),
+                               e.what()
                                )
                        );
 
@@ -134,8 +183,9 @@ Job::run_wrapper ()
                        set_error (
                                String::compose (_("Could not open %1"), e.path1().string ()),
                                String::compose (
-                                       _("DCP-o-matic could not open the file %1.  Perhaps it does not exist or is in an unexpected format."),
-                                       boost::filesystem::absolute (e.path1()).string()
+                                       _("DCP-o-matic could not open the file %1 (%2).  Perhaps it does not exist or is in an unexpected format."),
+                                       boost::filesystem::absolute (e.path1()).string(),
+                                       e.what()
                                        )
                                );
                } else {
@@ -149,13 +199,11 @@ Job::run_wrapper ()
                set_state (FINISHED_ERROR);
 
        } catch (boost::thread_interrupted &) {
-
-               set_state (FINISHED_CANCELLED);
-
+               /* The job was cancelled; there's nothing else we need to do here */
        } catch (sub::SubripError& e) {
 
                string extra = "Error is near:\n";
-               BOOST_FOREACH (string i, e.context()) {
+               for (auto i: e.context()) {
                        extra += i + "\n";
                }
 
@@ -169,6 +217,30 @@ Job::run_wrapper ()
                set_progress (1);
                set_state (FINISHED_ERROR);
 
+       } catch (dcp::ReadError& e) {
+
+               set_error (e.message(), e.detail().get_value_or(""));
+               set_progress (1);
+               set_state (FINISHED_ERROR);
+
+       } catch (KDMError& e) {
+
+               set_error (e.summary(), e.detail());
+               set_progress (1);
+               set_state (FINISHED_ERROR);
+
+       } catch (FileError& e) {
+
+               set_error (e.what(), e.what());
+               set_progress (1);
+               set_state (FINISHED_ERROR);
+
+       } catch (CPLNotFoundError& e) {
+
+               set_error(e.what());
+               set_progress(1);
+               set_state(FINISHED_ERROR);
+
        } catch (std::exception& e) {
 
                set_error (
@@ -191,6 +263,7 @@ Job::run_wrapper ()
        }
 }
 
+
 /** @return true if this job is new (ie has not started running) */
 bool
 Job::is_new () const
@@ -199,6 +272,7 @@ Job::is_new () const
        return _state == NEW;
 }
 
+
 /** @return true if the job is running */
 bool
 Job::running () const
@@ -207,6 +281,7 @@ Job::running () const
        return _state == RUNNING;
 }
 
+
 /** @return true if the job has finished (either successfully or unsuccessfully) */
 bool
 Job::finished () const
@@ -215,6 +290,7 @@ Job::finished () const
        return _state == FINISHED_OK || _state == FINISHED_ERROR || _state == FINISHED_CANCELLED;
 }
 
+
 /** @return true if the job has finished successfully */
 bool
 Job::finished_ok () const
@@ -223,6 +299,7 @@ Job::finished_ok () const
        return _state == FINISHED_OK;
 }
 
+
 /** @return true if the job has finished unsuccessfully */
 bool
 Job::finished_in_error () const
@@ -231,6 +308,7 @@ Job::finished_in_error () const
        return _state == FINISHED_ERROR;
 }
 
+
 bool
 Job::finished_cancelled () const
 {
@@ -238,13 +316,23 @@ Job::finished_cancelled () const
        return _state == FINISHED_CANCELLED;
 }
 
+
+bool
+Job::paused_by_user () const
+{
+       boost::mutex::scoped_lock lm (_state_mutex);
+       return _state == PAUSED_BY_USER;
+}
+
+
 bool
-Job::paused () const
+Job::paused_by_priority () const
 {
        boost::mutex::scoped_lock lm (_state_mutex);
-       return _state == PAUSED;
+       return _state == PAUSED_BY_PRIORITY;
 }
 
+
 /** Set the state of this job.
  *  @param s New state.
  */
@@ -266,9 +354,11 @@ Job::set_state (State s)
 
        if (finished) {
                emit (boost::bind (boost::ref (Finished)));
+               FinishedImmediate ();
        }
 }
 
+
 /** @return DCPTime (in seconds) that this sub-job has been running */
 int
 Job::elapsed_sub_time () const
@@ -280,6 +370,7 @@ Job::elapsed_sub_time () const
        return time (0) - _sub_start_time;
 }
 
+
 /** Check to see if this job has been interrupted or paused */
 void
 Job::check_for_interruption_or_pause ()
@@ -287,14 +378,31 @@ Job::check_for_interruption_or_pause ()
        boost::this_thread::interruption_point ();
 
        boost::mutex::scoped_lock lm (_state_mutex);
-       while (_state == PAUSED) {
+       while (_state == PAUSED_BY_USER || _state == PAUSED_BY_PRIORITY) {
                emit (boost::bind (boost::ref (Progress)));
                _pause_changed.wait (lm);
        }
 }
 
+
+optional<float>
+Job::seconds_since_last_progress_update () const
+{
+       boost::mutex::scoped_lock lm (_progress_mutex);
+       if (!_last_progress_update) {
+               return {};
+       }
+
+       struct timeval now;
+       gettimeofday (&now, 0);
+
+       return seconds(now) - seconds(*_last_progress_update);
+}
+
+
 /** Set the progress of the current part of the job.
  *  @param p Progress (from 0 to 1)
+ *  @param force Do not ignore this update, even if it hasn't been long since the last one.
  */
 void
 Job::set_progress (float p, bool force)
@@ -307,8 +415,7 @@ Job::set_progress (float p, bool force)
                struct timeval now;
                gettimeofday (&now, 0);
                if (_last_progress_update && _last_progress_update->tv_sec > 0) {
-                       double const elapsed = (now.tv_sec + now.tv_usec / 1000000.0)
-                               - (_last_progress_update->tv_sec + _last_progress_update->tv_usec / 1000000.0);
+                       double const elapsed = seconds(now) - seconds(*_last_progress_update);
                        if (elapsed < 0.5) {
                                return;
                        }
@@ -319,6 +426,7 @@ Job::set_progress (float p, bool force)
        set_progress_common (p);
 }
 
+
 void
 Job::set_progress_common (optional<float> p)
 {
@@ -330,6 +438,7 @@ Job::set_progress_common (optional<float> p)
        emit (boost::bind (boost::ref (Progress)));
 }
 
+
 /** @return fractional progress of the current sub-job, if known */
 optional<float>
 Job::progress () const
@@ -338,6 +447,7 @@ Job::progress () const
        return _progress;
 }
 
+
 void
 Job::sub (string n)
 {
@@ -351,6 +461,7 @@ Job::sub (string n)
        _sub_start_time = time (0);
 }
 
+
 string
 Job::error_details () const
 {
@@ -358,6 +469,7 @@ Job::error_details () const
        return _error_details;
 }
 
+
 /** @return A summary of any error that the job has generated */
 string
 Job::error_summary () const
@@ -366,15 +478,15 @@ Job::error_summary () const
        return _error_summary;
 }
 
+
 /** Set the current error string.
- *  @param e New error string.
+ *  @param s New error string.
+ *  @param d New error detail string.
  */
 void
 Job::set_error (string s, string d)
 {
        if (_film) {
-               LOG_ERROR_NC (s);
-               LOG_ERROR_NC (d);
                _film->log()->log (String::compose ("Error in job: %1 (%2)", s, d), LogEntry::TYPE_ERROR);
        }
 
@@ -383,6 +495,7 @@ Job::set_error (string s, string d)
        _error_details = d;
 }
 
+
 /** Say that this job's progress will be unknown until further notice */
 void
 Job::set_progress_unknown ()
@@ -391,6 +504,7 @@ Job::set_progress_unknown ()
        set_progress_common (optional<float> ());
 }
 
+
 /** @return Human-readable status of this job */
 string
 Job::status () const
@@ -412,15 +526,15 @@ Job::status () const
                s += buffer;
 
                if (t > 10 && r > 0) {
-                       boost::posix_time::ptime now = boost::posix_time::second_clock::local_time();
-                       boost::posix_time::ptime finish = now + boost::posix_time::seconds(r);
-                       char finish_string[6];
-                       snprintf (finish_string, sizeof(finish_string), "%02d:%02d", finish.time_of_day().hours(), finish.time_of_day().minutes());
+                       auto now = boost::posix_time::second_clock::local_time();
+                       auto finish = now + boost::posix_time::seconds(r);
+                       char finish_string[16];
+                       snprintf (finish_string, sizeof(finish_string), "%02d:%02d", int(finish.time_of_day().hours()), int(finish.time_of_day().minutes()));
                        string day;
                        if (now.date() != finish.date()) {
                                /// TRANSLATORS: the %1 in this string will be filled in with a day of the week
                                /// to say what day a job will finish.
-                               day = String::compose (_(" on %1"), finish.date().day_of_week().as_long_string());
+                               day = String::compose (_(" on %1"), day_of_week_to_string(finish.date().day_of_week()));
                        }
                        /// TRANSLATORS: "remaining; finishing at" here follows an amount of time that is remaining
                        /// on an operation; after it is an estimated wall-clock completion time.
@@ -440,6 +554,7 @@ Job::status () const
        return s;
 }
 
+
 string
 Job::json_status () const
 {
@@ -450,7 +565,8 @@ Job::json_status () const
                return N_("new");
        case RUNNING:
                return N_("running");
-       case PAUSED:
+       case PAUSED_BY_USER:
+       case PAUSED_BY_PRIORITY:
                return N_("paused");
        case FINISHED_OK:
                return N_("finished_ok");
@@ -463,6 +579,7 @@ Job::json_status () const
        return "";
 }
 
+
 /** @return An estimate of the remaining time for this sub-job, in seconds */
 int
 Job::remaining_time () const
@@ -474,42 +591,65 @@ Job::remaining_time () const
        return elapsed_sub_time() / progress().get() - elapsed_sub_time();
 }
 
+
 void
 Job::cancel ()
 {
-       if (!_thread) {
-               return;
+       if (_thread.joinable()) {
+               resume();
+
+               _thread.interrupt ();
+               _thread.join ();
        }
 
-       if (paused ()) {
-               resume ();
+       set_state (FINISHED_CANCELLED);
+}
+
+
+/** @return true if the job was paused, false if it was not running */
+bool
+Job::pause_by_user ()
+{
+       bool paused = false;
+       {
+               boost::mutex::scoped_lock lm (_state_mutex);
+               /* We can set _state here directly because we have a lock and we aren't
+                  setting the job to FINISHED_*
+               */
+               if (_state == RUNNING) {
+                       paused = true;
+                       _state = PAUSED_BY_USER;
+               }
        }
 
-       _thread->interrupt ();
-       DCPOMATIC_ASSERT (_thread->joinable ());
-       _thread->join ();
-       delete _thread;
-       _thread = 0;
+       if (paused) {
+               _pause_changed.notify_all ();
+       }
+
+       return paused;
 }
 
+
 void
-Job::pause ()
+Job::pause_by_priority ()
 {
        if (running ()) {
-               set_state (PAUSED);
+               set_state (PAUSED_BY_PRIORITY);
                _pause_changed.notify_all ();
        }
 }
 
+
 void
 Job::resume ()
 {
-       if (paused ()) {
+       if (paused_by_user() || paused_by_priority()) {
                set_state (RUNNING);
                _pause_changed.notify_all ();
        }
 }
 
+
 void
 Job::when_finished (boost::signals2::connection& connection, function<void()> finished)
 {
@@ -520,3 +660,19 @@ Job::when_finished (boost::signals2::connection& connection, function<void()> fi
                connection = Finished.connect (finished);
        }
 }
+
+
+optional<string>
+Job::message () const
+{
+       boost::mutex::scoped_lock lm (_state_mutex);
+       return _message;
+}
+
+
+void
+Job::set_message (string m)
+{
+       boost::mutex::scoped_lock lm (_state_mutex);
+       _message = m;
+}