Accessor for ClosedCaptionsDialog.
[dcpomatic.git] / src / lib / job.cc
index 37bf462fca0a3b1ffb65063a008f9b572df18982..8966a65e700eb84b8f3945eb7d81987d8c88f7b5 100644 (file)
@@ -1,19 +1,20 @@
 /*
-    Copyright (C) 2012-2015 Carl Hetherington <cth@carlh.net>
+    Copyright (C) 2012-2019 Carl Hetherington <cth@carlh.net>
 
-    This program is free software; you can redistribute it and/or modify
+    This file is part of DCP-o-matic.
+
+    DCP-o-matic is free software; you can redistribute it and/or modify
     it under the terms of the GNU General Public License as published by
     the Free Software Foundation; either version 2 of the License, or
     (at your option) any later version.
 
-    This program is distributed in the hope that it will be useful,
+    DCP-o-matic is distributed in the hope that it will be useful,
     but WITHOUT ANY WARRANTY; without even the implied warranty of
     MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
     GNU General Public License for more details.
 
     You should have received a copy of the GNU General Public License
-    along with this program; if not, write to the Free Software
-    Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA.
+    along with DCP-o-matic.  If not, see <http://www.gnu.org/licenses/>.
 
 */
 
 #include "exceptions.h"
 #include "film.h"
 #include "log.h"
+#include "dcpomatic_log.h"
 #include "compose.hpp"
 #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 <iostream>
 
 #include "i18n.h"
 
@@ -40,14 +46,15 @@ using std::cout;
 using boost::shared_ptr;
 using boost::optional;
 using boost::function;
+using namespace dcpomatic;
 
-#define LOG_ERROR_NC(...) _film->log()->log (__VA_ARGS__, Log::TYPE_ERROR);
-
+/** @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)
        , _progress (0)
        , _ran_for (0)
 {
@@ -55,13 +62,27 @@ Job::Job (shared_ptr<const Film> film)
 }
 
 Job::~Job ()
+{
+       stop_thread ();
+}
+
+void
+Job::stop_thread ()
 {
        if (_thread) {
                _thread->interrupt ();
-               _thread->join ();
+               /* 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 */
+                       }
+               }
        }
 
        delete _thread;
+       _thread = 0;
 }
 
 /** Start the job in a separate thread, returning immediately */
@@ -70,7 +91,11 @@ Job::start ()
 {
        set_state (RUNNING);
        _start_time = time (0);
+       _sub_start_time = time (0);
        _thread = new 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 */
@@ -103,7 +128,11 @@ Job::run_wrapper ()
 
                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."), e.file().string())
+                       String::compose (
+                               _("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()
+                               )
                        );
 
                set_progress (1);
@@ -114,7 +143,11 @@ Job::run_wrapper ()
                if (e.code() == boost::system::errc::no_such_file_or_directory) {
                        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."), e.path1().string())
+                               String::compose (
+                                       _("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 {
                        set_error (
@@ -130,9 +163,38 @@ Job::run_wrapper ()
 
                set_state (FINISHED_CANCELLED);
 
+       } catch (sub::SubripError& e) {
+
+               string extra = "Error is near:\n";
+               BOOST_FOREACH (string i, e.context()) {
+                       extra += i + "\n";
+               }
+
+               set_error (e.what (), extra);
+               set_progress (1);
+               set_state (FINISHED_ERROR);
+
        } catch (std::bad_alloc& e) {
 
-               set_error (_("Out of memory"), _("There was not enough memory to do this."));
+               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."));
+               set_progress (1);
+               set_state (FINISHED_ERROR);
+
+       } catch (dcp::DCPReadError& 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);
 
@@ -206,10 +268,17 @@ Job::finished_cancelled () const
 }
 
 bool
-Job::paused () const
+Job::paused_by_user () const
+{
+       boost::mutex::scoped_lock lm (_state_mutex);
+       return _state == PAUSED_BY_USER;
+}
+
+bool
+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.
@@ -225,7 +294,7 @@ Job::set_state (State s)
                _state = s;
 
                if (_state == FINISHED_OK || _state == FINISHED_ERROR || _state == FINISHED_CANCELLED) {
-                       _ran_for = elapsed_time ();
+                       _ran_for = time(0) - _start_time;
                        finished = true;
                        _sub_name.clear ();
                }
@@ -233,29 +302,56 @@ 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_time () const
+Job::elapsed_sub_time () const
 {
-       if (_start_time == 0) {
+       if (_sub_start_time == 0) {
                return 0;
        }
 
-       return time (0) - _start_time;
+       return time (0) - _sub_start_time;
+}
+
+/** Check to see if this job has been interrupted or paused */
+void
+Job::check_for_interruption_or_pause ()
+{
+       boost::this_thread::interruption_point ();
+
+       boost::mutex::scoped_lock lm (_state_mutex);
+       while (_state == PAUSED_BY_USER || _state == PAUSED_BY_PRIORITY) {
+               emit (boost::bind (boost::ref (Progress)));
+               _pause_changed.wait (lm);
+       }
 }
 
 /** 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)
 {
-       if (!force && fabs (p - progress().get_value_or(0)) < 0.01) {
-               /* Calm excessive progress reporting */
-               return;
+       check_for_interruption_or_pause ();
+
+       if (!force) {
+               /* Check for excessively frequent progress reporting */
+               boost::mutex::scoped_lock lm (_progress_mutex);
+               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);
+                       if (elapsed < 0.5) {
+                               return;
+                       }
+               }
+               _last_progress_update = now;
        }
 
        set_progress_common (p);
@@ -264,18 +360,11 @@ Job::set_progress (float p, bool force)
 void
 Job::set_progress_common (optional<float> p)
 {
-       boost::mutex::scoped_lock lm (_progress_mutex);
-       _progress = p;
-       boost::this_thread::interruption_point ();
-
-       boost::mutex::scoped_lock lm2 (_state_mutex);
-       while (_state == PAUSED) {
-               _pause_changed.wait (lm2);
+       {
+               boost::mutex::scoped_lock lm (_progress_mutex);
+               _progress = p;
        }
 
-       lm.unlock ();
-       lm2.unlock ();
-
        emit (boost::bind (boost::ref (Progress)));
 }
 
@@ -292,10 +381,12 @@ Job::sub (string n)
 {
        {
                boost::mutex::scoped_lock lm (_progress_mutex);
+               LOG_GENERAL ("Sub-job %1 starting", n);
                _sub_name = n;
        }
 
        set_progress (0, true);
+       _sub_start_time = time (0);
 }
 
 string
@@ -314,15 +405,16 @@ Job::error_summary () const
 }
 
 /** 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)
 {
-       LOG_ERROR_NC (s);
-       LOG_ERROR_NC (d);
+       if (_film) {
+               _film->log()->log (String::compose ("Error in job: %1 (%2)", s, d), LogEntry::TYPE_ERROR);
+       }
 
-       _film->log()->log (String::compose ("Error in job: %1 (%2)", s, d), Log::TYPE_ERROR);
        boost::mutex::scoped_lock lm (_state_mutex);
        _error_summary = s;
        _error_details = d;
@@ -332,6 +424,7 @@ Job::set_error (string s, string d)
 void
 Job::set_progress_unknown ()
 {
+       check_for_interruption_or_pause ();
        set_progress_common (optional<float> ());
 }
 
@@ -340,10 +433,10 @@ string
 Job::status () const
 {
        optional<float> p = progress ();
-       int const t = elapsed_time ();
+       int const t = elapsed_sub_time ();
        int const r = remaining_time ();
 
-       SafeStringStream s;
+       string s;
        if (!finished () && p) {
                int pc = lrintf (p.get() * 100);
                if (pc == 100) {
@@ -351,22 +444,37 @@ Job::status () const
                        pc = 99;
                }
 
-               s << pc << N_("%");
+               char buffer[64];
+               snprintf (buffer, sizeof(buffer), "%d%%", pc);
+               s += buffer;
 
                if (t > 10 && r > 0) {
-                       /// TRANSLATORS: remaining here follows an amount of time that is remaining
-                       /// on an operation.
-                       s << "; " << seconds_to_approximate_hms (r) << " " << _("remaining");
+                       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[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"), 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.
+                       s += String::compose(
+                               _("; %1 remaining; finishing at %2%3"),
+                               seconds_to_approximate_hms(r), finish_string, day
+                               );
                }
        } else if (finished_ok ()) {
-               s << String::compose (_("OK (ran for %1)"), seconds_to_hms (_ran_for));
+               s = String::compose (_("OK (ran for %1)"), seconds_to_hms (_ran_for));
        } else if (finished_in_error ()) {
-               s << String::compose (_("Error: %1"), error_summary ());
+               s = String::compose (_("Error: %1"), error_summary ());
        } else if (finished_cancelled ()) {
-               s << _("Cancelled");
+               s = _("Cancelled");
        }
 
-       return s.str ();
+       return s;
 }
 
 string
@@ -379,7 +487,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");
@@ -397,10 +506,10 @@ int
 Job::remaining_time () const
 {
        if (progress().get_value_or(0) == 0) {
-               return elapsed_time ();
+               return elapsed_sub_time ();
        }
 
-       return elapsed_time() / progress().get() - elapsed_time();
+       return elapsed_sub_time() / progress().get() - elapsed_sub_time();
 }
 
 void
@@ -410,19 +519,45 @@ Job::cancel ()
                return;
        }
 
-       if (paused ()) {
+       if (paused_by_user() || paused_by_priority()) {
                resume ();
        }
 
        _thread->interrupt ();
+       DCPOMATIC_ASSERT (_thread->joinable ());
        _thread->join ();
+       delete _thread;
+       _thread = 0;
+}
+
+/** @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;
+               }
+       }
+
+       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 ();
        }
 }
@@ -430,7 +565,7 @@ Job::pause ()
 void
 Job::resume ()
 {
-       if (paused ()) {
+       if (paused_by_user() || paused_by_priority()) {
                set_state (RUNNING);
                _pause_changed.notify_all ();
        }
@@ -447,3 +582,16 @@ Job::when_finished (boost::signals2::connection& connection, function<void()> fi
        }
 }
 
+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;
+}