X-Git-Url: https://main.carlh.net/gitweb/?p=dcpomatic.git;a=blobdiff_plain;f=src%2Flib%2Fjob.cc;h=8966a65e700eb84b8f3945eb7d81987d8c88f7b5;hp=8c46b49621c4a86a8c637d114d29dacce0976c00;hb=386e25f3b9d3fa59cbdeed458d9b3e0d21e338b8;hpb=b00389305af83dfd1e3b41ab3b108cb591f18c5d diff --git a/src/lib/job.cc b/src/lib/job.cc index 8c46b4962..8966a65e7 100644 --- a/src/lib/job.cc +++ b/src/lib/job.cc @@ -1,35 +1,42 @@ /* - Copyright (C) 2012-2015 Carl Hetherington + Copyright (C) 2012-2019 Carl Hetherington - 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 . */ -/** @file src/job.cc +/** @file src/job.cc * @brief A parent class to represent long-running tasks which are run in their own thread. */ -#include -#include -#include #include "job.h" #include "util.h" #include "cross.h" #include "exceptions.h" #include "film.h" #include "log.h" +#include "dcpomatic_log.h" +#include "compose.hpp" +#include +#include +#include +#include +#include +#include +#include #include "i18n.h" @@ -38,27 +45,57 @@ using std::list; 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 film) : _film (film) , _thread (0) , _state (NEW) , _start_time (0) + , _sub_start_time (0) , _progress (0) , _ran_for (0) { } +Job::~Job () +{ + stop_thread (); +} + +void +Job::stop_thread () +{ + 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 */ + } + } + } + + delete _thread; + _thread = 0; +} + /** Start the job in a separate thread, returning immediately */ void 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 */ @@ -91,19 +128,73 @@ 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); set_state (FINISHED_ERROR); + } catch (boost::filesystem::filesystem_error& e) { + + 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 (%2). Perhaps it does not exist or is in an unexpected format."), + boost::filesystem::absolute (e.path1()).string(), + e.what() + ) + ); + } else { + set_error ( + e.what (), + string (_("It is not known what caused this error.")) + " " + REPORT_PROBLEM + ); + } + + set_progress (1); + set_state (FINISHED_ERROR); + } catch (boost::thread_interrupted &) { 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); @@ -177,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. @@ -196,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 (); } @@ -204,43 +302,69 @@ 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; } - boost::mutex::scoped_lock lm (_progress_mutex); - _progress = p; - boost::this_thread::interruption_point (); + set_progress_common (p); +} - boost::mutex::scoped_lock lm2 (_state_mutex); - while (_state == PAUSED) { - _pause_changed.wait (lm2); +void +Job::set_progress_common (optional p) +{ + { + boost::mutex::scoped_lock lm (_progress_mutex); + _progress = p; } - lm.unlock (); - lm2.unlock (); - emit (boost::bind (boost::ref (Progress))); } @@ -257,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 @@ -279,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; @@ -297,11 +424,8 @@ Job::set_error (string s, string d) void Job::set_progress_unknown () { - boost::mutex::scoped_lock lm (_progress_mutex); - _progress.reset (); - lm.unlock (); - - emit (boost::bind (boost::ref (Progress))); + check_for_interruption_or_pause (); + set_progress_common (optional ()); } /** @return Human-readable status of this job */ @@ -309,33 +433,48 @@ string Job::status () const { optional 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 = rint (p.get() * 100); + int pc = lrintf (p.get() * 100); if (pc == 100) { /* 100% makes it sound like we've finished when we haven't */ 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 @@ -348,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"); @@ -366,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 @@ -379,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 (); } } @@ -399,8 +565,33 @@ Job::pause () 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 finished) +{ + boost::mutex::scoped_lock lm (_state_mutex); + if (_state == FINISHED_OK || _state == FINISHED_ERROR || _state == FINISHED_CANCELLED) { + finished (); + } else { + connection = Finished.connect (finished); + } +} + +optional +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; +}