From fe4a806a8685e8f6932465e10d09723f75bfb1cb Mon Sep 17 00:00:00 2001
From: Carl Hetherington <cth@carlh.net>
Date: Thu, 7 Jul 2016 15:29:03 +0100
Subject: [PATCH] Fix confusion about elapsed time of total job vs sub-job.

---
 ChangeLog      |  4 ++++
 src/lib/job.cc | 18 ++++++++++--------
 src/lib/job.h  |  6 ++++--
 3 files changed, 18 insertions(+), 10 deletions(-)

diff --git a/ChangeLog b/ChangeLog
index 6720af76d..78f863e71 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -1,3 +1,7 @@
+2016-07-07  c.hetherington  <cth@carlh.net>
+
+	* Fix incorrect job running time reports (#912).
+
 2016-07-06  Carl Hetherington  <cth@carlh.net>
 
 	* Version 2.8.19 released.
diff --git a/src/lib/job.cc b/src/lib/job.cc
index 9d1b25867..b316cddf7 100644
--- a/src/lib/job.cc
+++ b/src/lib/job.cc
@@ -52,6 +52,7 @@ Job::Job (shared_ptr<const Film> film)
 	, _thread (0)
 	, _state (NEW)
 	, _start_time (0)
+	, _sub_start_time (0)
 	, _progress (0)
 	, _ran_for (0)
 {
@@ -81,6 +82,7 @@ Job::start ()
 {
 	set_state (RUNNING);
 	_start_time = time (0);
+	_sub_start_time = time (0);
 	_thread = new boost::thread (boost::bind (&Job::run_wrapper, this));
 }
 
@@ -242,7 +244,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 ();
 		}
@@ -255,13 +257,13 @@ Job::set_state (State s)
 
 /** @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;
 }
 
 /** Set the progress of the current part of the job.
@@ -324,7 +326,7 @@ Job::sub (string n)
 	}
 
 	set_progress (0, true);
-	_start_time = time (0);
+	_sub_start_time = time (0);
 }
 
 string
@@ -371,7 +373,7 @@ 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;
@@ -428,10 +430,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
diff --git a/src/lib/job.h b/src/lib/job.h
index 7bc051142..804755ef8 100644
--- a/src/lib/job.h
+++ b/src/lib/job.h
@@ -65,7 +65,6 @@ public:
 	std::string error_summary () const;
 	std::string error_details () const;
 
-	int elapsed_time () const;
 	virtual std::string status () const;
 	std::string json_status () const;
 	std::string sub_name () const {
@@ -103,6 +102,7 @@ protected:
 
 	void set_state (State);
 	void set_error (std::string s, std::string d);
+	int elapsed_sub_time () const;
 
 	boost::shared_ptr<const Film> _film;
 
@@ -121,8 +121,10 @@ private:
 	std::string _error_summary;
 	std::string _error_details;
 
-	/** time that this sub-job was started */
+	/** time that this job was started */
 	time_t _start_time;
+	/** time that this sub-job was started */
+	time_t _sub_start_time;
 	std::string _sub_name;
 
 	/** mutex for _progress and _last_progress_update */
-- 
2.30.2