Some improvements in progress reporting, especially for long jobs.

9 files changed, 46 insertions, 119 deletions

diff --git a/src/lib/encoder.cc b/src/lib/encoder.cc
index 35ebfb52e..924a91439 100644
--- a/src/lib/encoder.cc
+++ b/src/lib/encoder.cc
@@ -52,7 +52,6 @@ Encoder::Encoder (shared_ptr<const Film> f, shared_ptr<Job> j)
 	: _film (f)
 	, _job (j)
 	, _video_frames_out (0)
-	, _state (TRANSCODING)
 	, _terminate (false)
 {
 	_have_a_real_frame[EYES_BOTH] = false;
@@ -125,11 +124,6 @@ Encoder::process_end ()
 			_film->log()->log (String::compose (N_("Local encode failed (%1)"), e.what ()));
 		}
 	}
-
-	{
-		boost::mutex::scoped_lock lm (_state_mutex);
-		_state = HASHING;
-	}
 		
 	_writer->finish ();
 	_writer.reset ();
diff --git a/src/lib/encoder.h b/src/lib/encoder.h
index e9b30df9e..ab3f40762 100644
--- a/src/lib/encoder.h
+++ b/src/lib/encoder.h
@@ -77,16 +77,6 @@ public:
 	float current_encoding_rate () const;
 	int video_frames_out () const;
 
-	enum State {
-		TRANSCODING,
-		HASHING
-	};
-
-	State state () const {
-		boost::mutex::scoped_lock lm (_state_mutex);
-		return _state;
-	}
-
 private:
 	
 	void frame_done ();
@@ -98,7 +88,7 @@ private:
 	boost::shared_ptr<const Film> _film;
 	boost::shared_ptr<Job> _job;
 
-	/** Mutex for _time_history, _last_frame and _state */
+	/** Mutex for _time_history and _last_frame */
 	mutable boost::mutex _state_mutex;
 	/** List of the times of completion of the last _history_size frames;
 	    first is the most recently completed.
@@ -109,7 +99,6 @@ private:
 
 	/** Number of video frames written for the DCP so far */
 	int _video_frames_out;
-	State _state;
 
 	bool _have_a_real_frame[EYES_COUNT];
 	bool _terminate;
diff --git a/src/lib/job.cc b/src/lib/job.cc
index 8924fa09c..5fbd1a160 100644
--- a/src/lib/job.cc
+++ b/src/lib/job.cc
@@ -43,11 +43,10 @@ Job::Job (shared_ptr<const Film> f)
 	, _thread (0)
 	, _state (NEW)
 	, _start_time (0)
-	, _progress_unknown (false)
-	, _last_set (0)
+	, _progress (0)
 	, _ran_for (0)
 {
-	descend (1);
+
 }
 
 /** Start the job in a separate thread, returning immediately */
@@ -198,7 +197,7 @@ Job::set_state (State s)
 	}
 }
 
-/** @return Time (in seconds) that this job has been running */
+/** @return Time (in seconds) that this sub-job has been running */
 int
 Job::elapsed_time () const
 {
@@ -215,16 +214,13 @@ Job::elapsed_time () const
 void
 Job::set_progress (float p)
 {
-	if (fabs (p - _last_set) < 0.01) {
+	if (fabs (p - progress()) < 0.01) {
 		/* Calm excessive progress reporting */
 		return;
 	}
 
-	_last_set = p;
-
 	boost::mutex::scoped_lock lm (_progress_mutex);
-	_progress_unknown = false;
-	_stack.back().normalised = p;
+	_progress = p;
 	boost::this_thread::interruption_point ();
 
 	if (paused ()) {
@@ -236,54 +232,23 @@ Job::set_progress (float p)
 	}
 }
 
-/** @return fractional overall progress, or -1 if not known */
+/** @return fractional progress of this sub-job, or -1 if not known */
 float
-Job::overall_progress () const
+Job::progress () const
 {
 	boost::mutex::scoped_lock lm (_progress_mutex);
-	if (_progress_unknown) {
-		return -1;
-	}
-
-	float overall = 0;
-	float factor = 1;
-	for (list<Level>::const_iterator i = _stack.begin(); i != _stack.end(); ++i) {
-		factor *= i->allocation;
-		overall += i->normalised * factor;
-	}
-
-	if (overall > 1) {
-		overall = 1;
-	}
-	
-	return overall;
+	return _progress.get_value_or (-1);
 }
 
-/** Ascend up one level in terms of progress reporting; see descend() */
 void
-Job::ascend ()
+Job::sub (string n)
 {
-	boost::mutex::scoped_lock lm (_progress_mutex);
+	{
+		boost::mutex::scoped_lock lm (_progress_mutex);
+		_sub_name = n;
+	}
 	
-	assert (!_stack.empty ());
-	float const a = _stack.back().allocation;
-	_stack.pop_back ();
-	_stack.back().normalised += a;
-}
-
-/** Descend down one level in terms of progress reporting; e.g. if
- *  there is a task which is split up into N subtasks, each of which
- *  report their progress from 0 to 100%, call descend() before executing
- *  each subtask, and ascend() afterwards to ensure that overall progress
- *  is reported correctly.
- *
- *  @param a Fraction (from 0 to 1) of the current task to allocate to the subtask.
- */
-void
-Job::descend (float a)
-{
-	boost::mutex::scoped_lock lm (_progress_mutex);
-	_stack.push_back (Level (a));
+	set_progress (0);
 }
 
 string
@@ -317,14 +282,14 @@ void
 Job::set_progress_unknown ()
 {
 	boost::mutex::scoped_lock lm (_progress_mutex);
-	_progress_unknown = true;
+	_progress.reset ();
 }
 
 /** @return Human-readable status of this job */
 string
 Job::status () const
 {
-	float const p = overall_progress ();
+	float const p = progress ();
 	int const t = elapsed_time ();
 	int const r = remaining_time ();
 
@@ -353,11 +318,11 @@ Job::status () const
 	return s.str ();
 }
 
-/** @return An estimate of the remaining time for this job, in seconds */
+/** @return An estimate of the remaining time for this sub-job, in seconds */
 int
 Job::remaining_time () const
 {
-	return elapsed_time() / overall_progress() - elapsed_time();
+	return elapsed_time() / progress() - elapsed_time();
 }
 
 void
diff --git a/src/lib/job.h b/src/lib/job.h
index 9b8b14a93..62db0fc46 100644
--- a/src/lib/job.h
+++ b/src/lib/job.h
@@ -64,14 +64,16 @@ public:
 
 	int elapsed_time () const;
 	virtual std::string status () const;
+	std::string sub_name () const {
+		return _sub_name;
+	}
 
 	void set_progress_unknown ();
 	void set_progress (float);
-	void ascend ();
-	void descend (float);
-	float overall_progress () const;
+	void sub (std::string);
+	float progress () const;
 	bool progress_unknown () const {
-		return _progress_unknown;
+		return !_progress;
 	}
 
 	boost::signals2::signal<void()> Progress;
@@ -111,25 +113,13 @@ private:
 	std::string _error_summary;
 	std::string _error_details;
 
-	/** time that this job was started */
+	/** time that this sub-job was started */
 	time_t _start_time;
+	std::string _sub_name;
 
-	/** mutex for _stack and _progress_unknown */
+	/** mutex for _progress */
 	mutable boost::mutex _progress_mutex;
-
-	struct Level {
-		Level (float a) : allocation (a), normalised (0) {}
-
-		float allocation;
-		float normalised;
-	};
-
-	std::list<Level> _stack;
-
-	/** true if this job's progress will always be unknown */
-	bool _progress_unknown;
-
-	float _last_set;
+	boost::optional<float> _progress;
 
 	int _ran_for;
 };
diff --git a/src/lib/moving_image_content.cc b/src/lib/moving_image_content.cc
index a72ad6e8e..14ebfcf25 100644
--- a/src/lib/moving_image_content.cc
+++ b/src/lib/moving_image_content.cc
@@ -81,16 +81,14 @@ MovingImageContent::as_xml (xmlpp::Node* node) const
 void
 MovingImageContent::examine (shared_ptr<Job> job)
 {
-	job->descend (0.5);
+	job->sub (_("Computing digest"));
 	Content::examine (job);
-	job->ascend ();
 
 	shared_ptr<const Film> film = _film.lock ();
 	assert (film);
-	
-	job->descend (0.5);
+
+	job->sub (_("Examining content"));
 	shared_ptr<MovingImageExaminer> examiner (new MovingImageExaminer (film, shared_from_this(), job));
-	job->ascend ();
 
 	take_from_video_examiner (examiner);
 
diff --git a/src/lib/transcode_job.cc b/src/lib/transcode_job.cc
index c9ec2053d..74b425c1e 100644
--- a/src/lib/transcode_job.cc
+++ b/src/lib/transcode_job.cc
@@ -91,12 +91,7 @@ TranscodeJob::status () const
 	s << Job::status ();
 
 	if (!finished ()) {
-		if (_transcoder->state() == Encoder::TRANSCODING) {
-			s << "; " << fixed << setprecision (1) << fps << N_(" ") << _("frames per second");
-		} else {
-			/* TRANSLATORS: this means `computing a hash' as in a digest of a block of data */
-			s << "; " << _("hashing");
-		}
+		s << "; " << fixed << setprecision (1) << fps << N_(" ") << _("frames per second");
 	}
 	
 	return s.str ();
diff --git a/src/lib/transcoder.cc b/src/lib/transcoder.cc
index 63ba77939..717f28556 100644
--- a/src/lib/transcoder.cc
+++ b/src/lib/transcoder.cc
@@ -91,8 +91,3 @@ Transcoder::video_frames_out () const
 	return _encoder->video_frames_out ();
 }
 
-Encoder::State
-Transcoder::state () const
-{
-	return _encoder->state ();
-}
diff --git a/src/lib/transcoder.h b/src/lib/transcoder.h
index 7bf214a88..9c0de29bf 100644
--- a/src/lib/transcoder.h
+++ b/src/lib/transcoder.h
@@ -38,7 +38,6 @@ public:
 	void go ();
 
 	float current_encoding_rate () const;
-	Encoder::State state () const;
 	int video_frames_out () const;
 
 private:
diff --git a/src/lib/writer.cc b/src/lib/writer.cc
index 3c99830e5..a53563ae5 100644
--- a/src/lib/writer.cc
+++ b/src/lib/writer.cc
@@ -65,9 +65,10 @@ Writer::Writer (shared_ptr<const Film> f, shared_ptr<Job> j)
 {
 	/* Remove any old DCP */
 	boost::filesystem::remove_all (_film->dir (_film->dcp_name ()));
-	
+
+	_job->sub (_("Checking existing image data"));
 	check_existing_picture_mxf ();
-	
+
 	/* Create our picture asset in a subdirectory, named according to those
 	   film's parameters which affect the video output.  We will hard-link
 	   it into the DCP later.
@@ -101,7 +102,7 @@ Writer::Writer (shared_ptr<const Film> f, shared_ptr<Job> j)
 
 	_thread = new boost::thread (boost::bind (&Writer::thread, this));
 
-	_job->descend (0.9);
+	_job->sub (_("Encoding image data"));
 }
 
 void
@@ -381,17 +382,11 @@ Writer::finish ()
 							 )
 			       ));
 
-	/* Compute the digests for the assets now so that we can keep track of progress.
-	   We did _job->descend (0.9) in our constructor */
-	_job->ascend ();
-
-	_job->descend (0.1);
+	_job->sub (_("Computing image digest"));
 	_picture_asset->compute_digest (boost::bind (&Job::set_progress, _job.get(), _1));
-	_job->ascend ();
 
-	_job->descend (0.1);
+	_job->sub (_("Computing audio digest"));
 	_sound_asset->compute_digest (boost::bind (&Job::set_progress, _job.get(), _1));
-	_job->ascend ();
 
 	libdcp::XMLMetadata meta = Config::instance()->dcp_metadata ();
 	meta.set_issue_date_now ();
@@ -468,8 +463,15 @@ Writer::check_existing_picture_mxf ()
 		return;
 	}
 
+	int N = 0;
+	for (boost::filesystem::directory_iterator i (_film->info_dir ()); i != boost::filesystem::directory_iterator (); ++i) {
+		++N;
+	}
+
 	while (1) {
 
+		_job->set_progress (float (_first_nonexistant_frame) / N);
+
 		if (_film->three_d ()) {
 			if (!check_existing_picture_mxf_frame (mxf, _first_nonexistant_frame, EYES_LEFT)) {
 				break;