Add iteration and time reporting for inner iterations.
Also
1. Remove an inadvertent LOG(INFO) from trust_region_minimizer.cc
2. Refactor some of the code in FullReport to reduce duplication
across line search and trust region minimizers.
3. Consistent capitalization.
Change-Id: I9078b1704efab23d2858530636f524e60c7d9016
diff --git a/include/ceres/solver.h b/include/ceres/solver.h
index 8f394ea..d339bcc 100644
--- a/include/ceres/solver.h
+++ b/include/ceres/solver.h
@@ -599,6 +599,7 @@
int num_successful_steps;
int num_unsuccessful_steps;
+ int num_inner_iteration_steps;
// When the user calls Solve, before the actual optimization
// occurs, Ceres performs a number of preprocessing steps. These
@@ -620,6 +621,7 @@
double linear_solver_time_in_seconds;
double residual_evaluation_time_in_seconds;
double jacobian_evaluation_time_in_seconds;
+ double inner_iteration_time_in_seconds;
// Preprocessor summary.
int num_parameter_blocks;
@@ -649,20 +651,22 @@
vector<int> linear_solver_ordering_given;
vector<int> linear_solver_ordering_used;
+ bool inner_iterations_given;
+ bool inner_iterations_used;
+
+ vector<int> inner_iteration_ordering_given;
+ vector<int> inner_iteration_ordering_used;
+
PreconditionerType preconditioner_type;
TrustRegionStrategyType trust_region_strategy_type;
DoglegType dogleg_type;
- bool inner_iterations;
SparseLinearAlgebraLibraryType sparse_linear_algebra_library;
LineSearchDirectionType line_search_direction_type;
LineSearchType line_search_type;
int max_lbfgs_rank;
-
- vector<int> inner_iteration_ordering_given;
- vector<int> inner_iteration_ordering_used;
};
// Once a least squares problem has been built, this function takes
diff --git a/internal/ceres/solver.cc b/internal/ceres/solver.cc
index ea9ff1f..5acbbfd 100644
--- a/internal/ceres/solver.cc
+++ b/internal/ceres/solver.cc
@@ -91,6 +91,7 @@
fixed_cost(-1.0),
num_successful_steps(-1),
num_unsuccessful_steps(-1),
+ num_inner_iteration_steps(-1),
preprocessor_time_in_seconds(-1.0),
minimizer_time_in_seconds(-1.0),
postprocessor_time_in_seconds(-1.0),
@@ -98,6 +99,7 @@
linear_solver_time_in_seconds(-1.0),
residual_evaluation_time_in_seconds(-1.0),
jacobian_evaluation_time_in_seconds(-1.0),
+ inner_iteration_time_in_seconds(-1.0),
num_parameter_blocks(-1),
num_parameters(-1),
num_effective_parameters(-1),
@@ -114,9 +116,10 @@
num_linear_solver_threads_used(-1),
linear_solver_type_given(SPARSE_NORMAL_CHOLESKY),
linear_solver_type_used(SPARSE_NORMAL_CHOLESKY),
+ inner_iterations_given(false),
+ inner_iterations_used(false),
preconditioner_type(IDENTITY),
trust_region_strategy_type(LEVENBERG_MARQUARDT),
- inner_iterations(false),
sparse_linear_algebra_library(SUITE_SPARSE),
line_search_direction_type(LBFGS),
line_search_type(ARMIJO) {
@@ -184,9 +187,8 @@
num_residuals, num_residuals_reduced);
}
- // TODO(sameeragarwal): Refactor this into separate functions.
-
if (minimizer_type == TRUST_REGION) {
+ // TRUST_SEARCH HEADER
StringAppendF(&report, "\nMinimizer %19s\n",
"TRUST_REGION");
if (linear_solver_type_used == SPARSE_NORMAL_CHOLESKY ||
@@ -194,12 +196,12 @@
(linear_solver_type_used == ITERATIVE_SCHUR &&
(preconditioner_type == CLUSTER_JACOBI ||
preconditioner_type == CLUSTER_TRIDIAGONAL))) {
- StringAppendF(&report, "\nSparse Linear Algebra Library %15s\n",
+ StringAppendF(&report, "\nSparse linear algebra library %15s\n",
SparseLinearAlgebraLibraryTypeToString(
sparse_linear_algebra_library));
}
- StringAppendF(&report, "Trust Region Strategy %19s",
+ StringAppendF(&report, "Trust region strategy %19s",
TrustRegionStrategyTypeToString(
trust_region_strategy_type));
if (trust_region_strategy_type == DOGLEG) {
@@ -227,7 +229,7 @@
"N/A", "N/A");
}
- StringAppendF(&report, "Threads: % 25d% 25d\n",
+ StringAppendF(&report, "Threads % 25d% 25d\n",
num_threads_given, num_threads_used);
StringAppendF(&report, "Linear solver threads % 23d% 25d\n",
num_linear_solver_threads_given,
@@ -244,7 +246,14 @@
used.c_str());
}
- if (inner_iterations) {
+ if (inner_iterations_given) {
+ StringAppendF(&report,
+ "Use inner iterations %20s %20s\n",
+ inner_iterations_given ? "True" : "False",
+ inner_iterations_used ? "True" : "False");
+ }
+
+ if (inner_iterations_used) {
string given;
StringifyOrdering(inner_iteration_ordering_given, &given);
string used;
@@ -254,57 +263,8 @@
given.c_str(),
used.c_str());
}
-
- if (termination_type == DID_NOT_RUN) {
- CHECK(!error.empty())
- << "Solver terminated with DID_NOT_RUN but the solver did not "
- << "return a reason. This is a Ceres error. Please report this "
- << "to the Ceres team";
- StringAppendF(&report, "Termination: %20s\n",
- "DID_NOT_RUN");
- StringAppendF(&report, "Reason: %s\n", error.c_str());
- return report;
- }
-
- StringAppendF(&report, "\nCost:\n");
- StringAppendF(&report, "Initial % 30e\n", initial_cost);
- if (termination_type != NUMERICAL_FAILURE &&
- termination_type != USER_ABORT) {
- StringAppendF(&report, "Final % 30e\n", final_cost);
- StringAppendF(&report, "Change % 30e\n",
- initial_cost - final_cost);
- }
-
- StringAppendF(&report, "\nNumber of iterations:\n");
- StringAppendF(&report, "Successful % 20d\n",
- num_successful_steps);
- StringAppendF(&report, "Unsuccessful % 20d\n",
- num_unsuccessful_steps);
- StringAppendF(&report, "Total % 20d\n",
- num_successful_steps + num_unsuccessful_steps);
-
- StringAppendF(&report, "\nTime (in seconds):\n");
- StringAppendF(&report, "Preprocessor %25.3f\n",
- preprocessor_time_in_seconds);
- StringAppendF(&report, "\n Residual Evaluations %22.3f\n",
- residual_evaluation_time_in_seconds);
- StringAppendF(&report, " Jacobian Evaluations %22.3f\n",
- jacobian_evaluation_time_in_seconds);
- StringAppendF(&report, " Linear Solver %23.3f\n",
- linear_solver_time_in_seconds);
- StringAppendF(&report, "Minimizer %25.3f\n\n",
- minimizer_time_in_seconds);
-
- StringAppendF(&report, "Postprocessor %24.3f\n",
- postprocessor_time_in_seconds);
-
- StringAppendF(&report, "Total %25.3f\n\n",
- total_time_in_seconds);
-
- StringAppendF(&report, "Termination: %25s\n",
- SolverTerminationTypeToString(termination_type));
} else {
- // LINE_SEARCH
+ // LINE_SEARCH HEADER
StringAppendF(&report, "\nMinimizer %19s\n", "LINE_SEARCH");
if (line_search_direction_type == LBFGS) {
StringAppendF(&report, "Line search direction %19s(%d)\n",
@@ -321,52 +281,72 @@
StringAppendF(&report, "\n");
StringAppendF(&report, "%45s %21s\n", "Given", "Used");
- StringAppendF(&report, "Threads: % 25d% 25d\n",
+ StringAppendF(&report, "Threads % 25d% 25d\n",
num_threads_given, num_threads_used);
- if (termination_type == DID_NOT_RUN) {
- CHECK(!error.empty())
- << "Solver terminated with DID_NOT_RUN but the solver did not "
- << "return a reason. This is a Ceres error. Please report this "
- << "to the Ceres team";
- StringAppendF(&report, "Termination: %20s\n",
- "DID_NOT_RUN");
- StringAppendF(&report, "Reason: %s\n", error.c_str());
- return report;
- }
-
- StringAppendF(&report, "\nCost:\n");
- StringAppendF(&report, "Initial % 30e\n", initial_cost);
- if (termination_type != NUMERICAL_FAILURE &&
- termination_type != USER_ABORT) {
- StringAppendF(&report, "Final % 30e\n", final_cost);
- StringAppendF(&report, "Change % 30e\n",
- initial_cost - final_cost);
- }
-
- StringAppendF(&report, "\nNumber of iterations: % 20d\n",
- static_cast<int>(iterations.size() - 1));
-
- StringAppendF(&report, "\nTime (in seconds):\n");
- StringAppendF(&report, "Preprocessor %25.3f\n",
- preprocessor_time_in_seconds);
- StringAppendF(&report, "\n Residual Evaluations %22.3f\n",
- residual_evaluation_time_in_seconds);
- StringAppendF(&report, " Jacobian Evaluations %22.3f\n",
- jacobian_evaluation_time_in_seconds);
- StringAppendF(&report, "Minimizer %25.3f\n\n",
- minimizer_time_in_seconds);
-
- StringAppendF(&report, "Postprocessor %24.3f\n",
- postprocessor_time_in_seconds);
-
- StringAppendF(&report, "Total %25.3f\n\n",
- total_time_in_seconds);
-
- StringAppendF(&report, "Termination: %25s\n",
- SolverTerminationTypeToString(termination_type));
}
+ if (termination_type == DID_NOT_RUN) {
+ CHECK(!error.empty())
+ << "Solver terminated with DID_NOT_RUN but the solver did not "
+ << "return a reason. This is a Ceres error. Please report this "
+ << "to the Ceres team";
+ StringAppendF(&report, "Termination: %20s\n",
+ "DID_NOT_RUN");
+ StringAppendF(&report, "Reason: %s\n", error.c_str());
+ return report;
+ }
+
+ StringAppendF(&report, "\nCost:\n");
+ StringAppendF(&report, "Initial % 30e\n", initial_cost);
+ if (termination_type != NUMERICAL_FAILURE &&
+ termination_type != USER_ABORT) {
+ StringAppendF(&report, "Final % 30e\n", final_cost);
+ StringAppendF(&report, "Change % 30e\n",
+ initial_cost - final_cost);
+ }
+
+ StringAppendF(&report, "\nMinimizer iterations % 16d\n",
+ num_successful_steps + num_unsuccessful_steps);
+ StringAppendF(&report, "Successful steps % 14d\n",
+ num_successful_steps);
+ StringAppendF(&report, "Unsuccessful steps % 14d\n",
+ num_unsuccessful_steps);
+ if (inner_iterations_used) {
+ StringAppendF(&report, "Steps with inner iterations % 14d\n",
+ num_inner_iteration_steps);
+ }
+
+ StringAppendF(&report, "\nTime (in seconds):\n");
+ StringAppendF(&report, "Preprocessor %25.3f\n",
+ preprocessor_time_in_seconds);
+
+ StringAppendF(&report, "\n Residual evaluation %23.3f\n",
+ residual_evaluation_time_in_seconds);
+ StringAppendF(&report, " Jacobian evaluation %23.3f\n",
+ jacobian_evaluation_time_in_seconds);
+
+ if (minimizer_type == TRUST_REGION) {
+ StringAppendF(&report, " Linear solver %23.3f\n",
+ linear_solver_time_in_seconds);
+ }
+
+ if (inner_iterations_used) {
+ StringAppendF(&report, " Inner iterations %23.3f\n",
+ inner_iteration_time_in_seconds);
+ }
+
+ StringAppendF(&report, "Minimizer %25.3f\n\n",
+ minimizer_time_in_seconds);
+
+ StringAppendF(&report, "Postprocessor %24.3f\n",
+ postprocessor_time_in_seconds);
+
+ StringAppendF(&report, "Total %25.3f\n\n",
+ total_time_in_seconds);
+
+ StringAppendF(&report, "Termination: %25s\n",
+ SolverTerminationTypeToString(termination_type));
return report;
};
diff --git a/internal/ceres/solver_impl.cc b/internal/ceres/solver_impl.cc
index 56993c8..76e9c92 100644
--- a/internal/ceres/solver_impl.cc
+++ b/internal/ceres/solver_impl.cc
@@ -536,8 +536,7 @@
}
}
}
-
- event_logger.AddEvent("CreateIIM");
+ event_logger.AddEvent("CreateInnerIterationMinimizer");
// The optimizer works on contiguous parameter vectors; allocate some.
Vector parameters(reduced_program->NumParameters());
@@ -1264,6 +1263,8 @@
const Program& program,
const ProblemImpl::ParameterMap& parameter_map,
Solver::Summary* summary) {
+ summary->inner_iterations_given = true;
+
scoped_ptr<CoordinateDescentMinimizer> inner_iteration_minimizer(
new CoordinateDescentMinimizer);
scoped_ptr<ParameterBlockOrdering> inner_iteration_ordering;
@@ -1306,9 +1307,9 @@
return NULL;
}
- summary->inner_iterations = true;
+ summary->inner_iterations_used = true;
+ summary->inner_iteration_time_in_seconds = 0.0;
SummarizeOrdering(ordering_ptr, &(summary->inner_iteration_ordering_used));
-
return inner_iteration_minimizer.release();
}
diff --git a/internal/ceres/trust_region_minimizer.cc b/internal/ceres/trust_region_minimizer.cc
index ab0f44b..3206dec 100644
--- a/internal/ceres/trust_region_minimizer.cc
+++ b/internal/ceres/trust_region_minimizer.cc
@@ -319,6 +319,8 @@
} else {
// Check if performing an inner iteration will make it better.
if (inner_iterations_are_enabled) {
+ ++summary->num_inner_iteration_steps;
+ double inner_iteration_start_time = WallTimeInSeconds();
const double x_plus_delta_cost = new_cost;
Vector inner_iteration_x = x_plus_delta;
Solver::Summary inner_iteration_summary;
@@ -347,10 +349,12 @@
// Disable inner iterations once the relative improvement
// drops below tolerance.
if (!inner_iterations_are_enabled) {
- LOG(INFO) << "Disabling inner iterations. Progress : "
- << inner_iteration_relative_progress;
+ VLOG(2) << "Disabling inner iterations. Progress : "
+ << inner_iteration_relative_progress;
}
}
+ summary->inner_iteration_time_in_seconds +=
+ WallTimeInSeconds() - inner_iteration_start_time;
}
}
diff --git a/internal/ceres/wall_time.cc b/internal/ceres/wall_time.cc
index e63d20c..85c4417 100644
--- a/internal/ceres/wall_time.cc
+++ b/internal/ceres/wall_time.cc
@@ -86,7 +86,7 @@
last_event_time_ = current_time;
StringAppendF(&events_,
- " %25s : %10.5f %10.5f\n",
+ " %30s : %10.5f %10.5f\n",
event_name.c_str(),
relative_time_delta,
absolute_time_delta);
