diff --git a/docs/source/nnls_solving.rst b/docs/source/nnls_solving.rst index 4dd17ecfd..d39ce953c 100644 --- a/docs/source/nnls_solving.rst +++ b/docs/source/nnls_solving.rst @@ -2041,6 +2041,12 @@ The three arrays will be: Time (in seconds) spent in the linear solver computing the trust region step. +.. member:: int Solver::Summary::num_linear_solves + + Number of times the Newton step was computed by solving a linear + system. This does not include linear solves used by inner + iterations. + .. member:: double Solver::Summary::residual_evaluation_time_in_seconds Time (in seconds) spent evaluating the residual vector. diff --git a/include/ceres/solver.h b/include/ceres/solver.h index 3a55a6581..2ed3fc125 100644 --- a/include/ceres/solver.h +++ b/include/ceres/solver.h @@ -841,6 +841,11 @@ class CERES_EXPORT Solver { // trust region step. double linear_solver_time_in_seconds; + // Number of times the Newton step was computed by solving a + // linear system. This does not include linear solves used by + // inner iterations. + int num_linear_solves; + // Time (in seconds) spent evaluating the residual vector. double residual_evaluation_time_in_seconds; diff --git a/internal/ceres/evaluator.h b/internal/ceres/evaluator.h index 68e8ca15e..2c79b5f28 100644 --- a/internal/ceres/evaluator.h +++ b/internal/ceres/evaluator.h @@ -164,12 +164,8 @@ class Evaluator { // that the base class implementation does not have to worry about // life time issues. Further, these calls are not expected to be // frequent or performance sensitive. - virtual std::map CallStatistics() const { - return std::map(); - } - - virtual std::map TimeStatistics() const { - return std::map(); + virtual std::map Statistics() const { + return std::map(); } }; diff --git a/internal/ceres/execution_summary.h b/internal/ceres/execution_summary.h index 80f1af88b..6713046dd 100644 --- a/internal/ceres/execution_summary.h +++ b/internal/ceres/execution_summary.h @@ -35,54 +35,45 @@ #include #include "ceres/internal/port.h" -#include "ceres/wall_time.h" #include "ceres/mutex.h" +#include "ceres/wall_time.h" namespace ceres { namespace internal { -// Struct used by various objects to report statistics and other -// information about their execution. e.g., ExecutionSummary::times -// can be used for reporting times associated with various activities. -// -// TODO(https://github.com/ceres-solver/ceres-solver/issues/340): -// Replace the two maps by one to save on a lookup, since the usage -// pattern is to keep track of the calls and the time increment at the -// same time. -// +struct CallStatistics { + CallStatistics() : time(0.), calls(0) {} + double time; + int calls; +}; + +// Struct used by various objects to report statistics about their +// execution. class ExecutionSummary { public: void IncrementTimeBy(const std::string& name, const double value) { - CeresMutexLock l(×_mutex_); - times_[name] += value; + CeresMutexLock l(&mutex_); + CallStatistics& call_stats = statistics_[name]; + call_stats.time += value; + ++call_stats.calls; } - void IncrementCall(const std::string& name) { - CeresMutexLock l(&calls_mutex_); - calls_[name] += 1; + const std::map& statistics() const { + return statistics_; } - const std::map& times() const { return times_; } - const std::map& calls() const { return calls_; } - private: - Mutex times_mutex_; - std::map times_; - - Mutex calls_mutex_; - std::map calls_; + Mutex mutex_; + std::map statistics_; }; class ScopedExecutionTimer { public: ScopedExecutionTimer(const std::string& name, ExecutionSummary* summary) - : start_time_(WallTimeInSeconds()), - name_(name), - summary_(summary) {} + : start_time_(WallTimeInSeconds()), name_(name), summary_(summary) {} ~ScopedExecutionTimer() { summary_->IncrementTimeBy(name_, WallTimeInSeconds() - start_time_); - summary_->IncrementCall(name_); } private: diff --git a/internal/ceres/gradient_problem_evaluator.h b/internal/ceres/gradient_problem_evaluator.h index 69e0e8a75..54586310a 100644 --- a/internal/ceres/gradient_problem_evaluator.h +++ b/internal/ceres/gradient_problem_evaluator.h @@ -86,12 +86,8 @@ class GradientProblemEvaluator : public Evaluator { virtual int NumResiduals() const { return 1; } - virtual std::map CallStatistics() const { - return execution_summary_.calls(); - } - - virtual std::map TimeStatistics() const { - return execution_summary_.times(); + virtual std::map Statistics() const { + return execution_summary_.statistics(); } private: diff --git a/internal/ceres/gradient_problem_solver.cc b/internal/ceres/gradient_problem_solver.cc index b22c5a1db..0d413752f 100644 --- a/internal/ceres/gradient_problem_solver.cc +++ b/internal/ceres/gradient_problem_solver.cc @@ -98,6 +98,7 @@ void GradientProblemSolver::Solve(const GradientProblemSolver::Options& options, const GradientProblem& problem, double* parameters_ptr, GradientProblemSolver::Summary* summary) { + using internal::CallStatistics; using internal::GradientProblemEvaluator; using internal::GradientProblemSolverStateUpdatingCallback; using internal::LoggingCallback; @@ -174,18 +175,22 @@ void GradientProblemSolver::Solve(const GradientProblemSolver::Options& options, SetSummaryFinalCost(summary); } - const std::map& evaluator_time_statistics = - minimizer_options.evaluator->TimeStatistics(); - summary->cost_evaluation_time_in_seconds = - FindWithDefault(evaluator_time_statistics, "Evaluator::Residual", 0.0); - summary->gradient_evaluation_time_in_seconds = - FindWithDefault(evaluator_time_statistics, "Evaluator::Jacobian", 0.0); - const std::map& evaluator_call_statistics = - minimizer_options.evaluator->CallStatistics(); - summary->num_cost_evaluations = - FindWithDefault(evaluator_call_statistics, "Evaluator::Residual", 0); - summary->num_gradient_evaluations = - FindWithDefault(evaluator_call_statistics, "Evaluator::Jacobian", 0); + const std::map& evaluator_statistics = + minimizer_options.evaluator->Statistics(); + { + const CallStatistics& call_stats = FindWithDefault( + evaluator_statistics, "Evaluator::Residual", CallStatistics()); + summary->cost_evaluation_time_in_seconds = call_stats.time; + summary->num_cost_evaluations = call_stats.calls; + } + + { + const CallStatistics& call_stats = FindWithDefault( + evaluator_statistics, "Evaluator::Jacobian", CallStatistics()); + summary->gradient_evaluation_time_in_seconds = call_stats.time; + summary->num_gradient_evaluations = call_stats.calls; + } + summary->total_time_in_seconds = WallTimeInSeconds() - start_time; } diff --git a/internal/ceres/line_search.cc b/internal/ceres/line_search.cc index bf7c3d434..1a88ebbca 100644 --- a/internal/ceres/line_search.cc +++ b/internal/ceres/line_search.cc @@ -150,21 +150,28 @@ double LineSearchFunction::DirectionInfinityNorm() const { } void LineSearchFunction::ResetTimeStatistics() { - const map evaluator_time_statistics = - evaluator_->TimeStatistics(); + const map evaluator_statistics = + evaluator_->Statistics(); + initial_evaluator_residual_time_in_seconds = - FindWithDefault(evaluator_time_statistics, "Evaluator::Residual", 0.0); + FindWithDefault( + evaluator_statistics, "Evaluator::Residual", CallStatistics()) + .time; initial_evaluator_jacobian_time_in_seconds = - FindWithDefault(evaluator_time_statistics, "Evaluator::Jacobian", 0.0); + FindWithDefault( + evaluator_statistics, "Evaluator::Jacobian", CallStatistics()) + .time; } void LineSearchFunction::TimeStatistics( double* cost_evaluation_time_in_seconds, double* gradient_evaluation_time_in_seconds) const { - const map evaluator_time_statistics = - evaluator_->TimeStatistics(); + const map evaluator_time_statistics = + evaluator_->Statistics(); *cost_evaluation_time_in_seconds = - FindWithDefault(evaluator_time_statistics, "Evaluator::Residual", 0.0) - + FindWithDefault( + evaluator_time_statistics, "Evaluator::Residual", CallStatistics()) + .time - initial_evaluator_residual_time_in_seconds; // Strictly speaking this will slightly underestimate the time spent // evaluating the gradient of the line search univariate cost function as it @@ -173,7 +180,9 @@ void LineSearchFunction::TimeStatistics( // allows direct subtraction of the timing information from the totals for // the evaluator returned in the solver summary. *gradient_evaluation_time_in_seconds = - FindWithDefault(evaluator_time_statistics, "Evaluator::Jacobian", 0.0) - + FindWithDefault( + evaluator_time_statistics, "Evaluator::Jacobian", CallStatistics()) + .time - initial_evaluator_jacobian_time_in_seconds; } diff --git a/internal/ceres/linear_solver.h b/internal/ceres/linear_solver.h index 5f996a140..65cb2424c 100644 --- a/internal/ceres/linear_solver.h +++ b/internal/ceres/linear_solver.h @@ -302,16 +302,12 @@ class LinearSolver { const PerSolveOptions& per_solve_options, double* x) = 0; - // The following two methods return copies instead of references so - // that the base class implementation does not have to worry about - // life time issues. Further, these calls are not expected to be - // frequent or performance sensitive. - virtual std::map CallStatistics() const { - return std::map(); - } - - virtual std::map TimeStatistics() const { - return std::map(); + // This method returns copies instead of references so that the base + // class implementation does not have to worry about life time + // issues. Further, this calls are not expected to be frequent or + // performance sensitive. + virtual std::map Statistics() const { + return std::map(); } // Factory @@ -341,12 +337,8 @@ class TypedLinearSolver : public LinearSolver { return SolveImpl(down_cast(A), b, per_solve_options, x); } - virtual std::map CallStatistics() const { - return execution_summary_.calls(); - } - - virtual std::map TimeStatistics() const { - return execution_summary_.times(); + virtual std::map Statistics() const { + return execution_summary_.statistics(); } private: diff --git a/internal/ceres/program_evaluator.h b/internal/ceres/program_evaluator.h index a625b2390..b4127479d 100644 --- a/internal/ceres/program_evaluator.h +++ b/internal/ceres/program_evaluator.h @@ -338,12 +338,8 @@ class ProgramEvaluator : public Evaluator { return program_->NumResiduals(); } - virtual std::map CallStatistics() const { - return execution_summary_.calls(); - } - - virtual std::map TimeStatistics() const { - return execution_summary_.times(); + virtual std::map Statistics() const { + return execution_summary_.statistics(); } private: diff --git a/internal/ceres/solver.cc b/internal/ceres/solver.cc index 4d1db506d..fcf817522 100644 --- a/internal/ceres/solver.cc +++ b/internal/ceres/solver.cc @@ -393,36 +393,41 @@ void PostSolveSummarize(const internal::PreprocessedProblem& pp, SummarizeReducedProgram(*pp.reduced_program, summary); } + using internal::CallStatistics; + // It is possible that no evaluator was created. This would be the // case if the preprocessor failed, or if the reduced problem did // not contain any parameter blocks. Thus, only extract the // evaluator statistics if one exists. if (pp.evaluator.get() != NULL) { - const map& evaluator_time_statistics = - pp.evaluator->TimeStatistics(); - summary->residual_evaluation_time_in_seconds = - FindWithDefault(evaluator_time_statistics, "Evaluator::Residual", 0.0); - summary->jacobian_evaluation_time_in_seconds = - FindWithDefault(evaluator_time_statistics, "Evaluator::Jacobian", 0.0); + const map& evaluator_statistics = + pp.evaluator->Statistics(); + { + const CallStatistics& call_stats = FindWithDefault( + evaluator_statistics, "Evaluator::Residual", CallStatistics()); - const map& evaluator_call_statistics = - pp.evaluator->CallStatistics(); - summary->num_residual_evaluations = - FindWithDefault(evaluator_call_statistics, "Evaluator::Residual", 0); - summary->num_jacobian_evaluations = - FindWithDefault(evaluator_call_statistics, "Evaluator::Jacobian", 0); + summary->residual_evaluation_time_in_seconds = call_stats.time; + summary->num_residual_evaluations = call_stats.calls; + } + { + const CallStatistics& call_stats = FindWithDefault( + evaluator_statistics, "Evaluator::Jacobian", CallStatistics()); + + summary->jacobian_evaluation_time_in_seconds = call_stats.time; + summary->num_jacobian_evaluations = call_stats.calls; + } } // Again, like the evaluator, there may or may not be a linear // solver from which we can extract run time statistics. In // particular the line search solver does not use a linear solver. if (pp.linear_solver.get() != NULL) { - const map& linear_solver_time_statistics = - pp.linear_solver->TimeStatistics(); - summary->linear_solver_time_in_seconds = - FindWithDefault(linear_solver_time_statistics, - "LinearSolver::Solve", - 0.0); + const map& linear_solver_statistics = + pp.linear_solver->Statistics(); + const CallStatistics& call_stats = FindWithDefault( + linear_solver_statistics, "LinearSolver::Solve", CallStatistics()); + summary->num_linear_solves = call_stats.calls; + summary->linear_solver_time_in_seconds = call_stats.time; } } @@ -633,6 +638,7 @@ Solver::Summary::Summary() postprocessor_time_in_seconds(-1.0), total_time_in_seconds(-1.0), linear_solver_time_in_seconds(-1.0), + num_linear_solves(-1), residual_evaluation_time_in_seconds(-1.0), num_residual_evaluations(-1), jacobian_evaluation_time_in_seconds(-1.0), @@ -889,8 +895,8 @@ string Solver::Summary::FullReport() const { } if (minimizer_type == TRUST_REGION) { - StringAppendF(&report, " Linear solver %23.6f\n", - linear_solver_time_in_seconds); + StringAppendF(&report, " Linear solver %23.6f (%d)\n", + linear_solver_time_in_seconds, num_linear_solves); } if (inner_iterations_used) {