diff --git a/cpp/src/branch_and_bound/branch_and_bound.cpp b/cpp/src/branch_and_bound/branch_and_bound.cpp index 0222ad6fe..c76e30b64 100644 --- a/cpp/src/branch_and_bound/branch_and_bound.cpp +++ b/cpp/src/branch_and_bound/branch_and_bound.cpp @@ -45,6 +45,19 @@ namespace cuopt::linear_programming::dual_simplex { namespace { +// Column widths for the branch-and-bound progress table. +constexpr int SYMBOL_WIDTH = 1; +constexpr int EXPLORED_WIDTH = 12; +constexpr int UNEXPLORED_WIDTH = 12; +constexpr int OBJECTIVE_WIDTH = 19; +constexpr int BOUND_WIDTH = 15; +constexpr int INTEGER_INFEASIBLE_WIDTH = 8; +constexpr int DEPTH_WIDTH = 7; +constexpr int ITER_NODE_WIDTH = 11; +constexpr int GAP_WIDTH = 11; +constexpr int WORK_WIDTH = 8; +constexpr int TIME_WIDTH = 8; + template bool is_fractional(f_t x, variable_type_t var_type, f_t integer_tol) { @@ -195,22 +208,12 @@ f_t user_relative_gap(const lp_problem_t& lp, f_t obj_value, f_t lower return user_mip_gap; } -template -std::string user_mip_gap(const lp_problem_t& lp, f_t obj_value, f_t lower_bound) +template +std::string to_percentage(f_t value) { - const f_t user_mip_gap = user_relative_gap(lp, obj_value, lower_bound); - if (user_mip_gap == std::numeric_limits::infinity()) { - return " - "; - } else { - constexpr int BUFFER_LEN = 32; - char buffer[BUFFER_LEN]; - if (user_mip_gap > 1e-3) { - snprintf(buffer, BUFFER_LEN - 1, "%5.1f%%", user_mip_gap * 100); - } else { - snprintf(buffer, BUFFER_LEN - 1, "%5.2f%%", user_mip_gap * 100); - } - return std::string(buffer); - } + if (value == std::numeric_limits::infinity()) return "---"; + if (value > 1e-3) { return std::format("{:5.1f}%", value * 100); } + return std::format("{:5.2f}%", value * 100); } #ifdef SHOW_DIVING_TYPE @@ -326,29 +329,77 @@ void branch_and_bound_t::set_initial_upper_bound(f_t bound) upper_bound_ = bound; } +template +void branch_and_bound_t::print_table_header() +{ + std::string header = + std::format("{:^{}}|{:^{}}|{:^{}}|{:^{}}|{:^{}}|{:^{}}|{:^{}}|{:^{}}|{:^{}}|", + "", + SYMBOL_WIDTH, + "Explored", + EXPLORED_WIDTH, + "Unexplored", + UNEXPLORED_WIDTH, + "Objective", + OBJECTIVE_WIDTH, + "Bound", + BOUND_WIDTH, + "IntInf", + INTEGER_INFEASIBLE_WIDTH, + "Depth", + DEPTH_WIDTH, + "Iter/Node", + ITER_NODE_WIDTH, + "Gap", + GAP_WIDTH); + if (settings_.deterministic) { header += std::format("{:^{}}|", "Work", WORK_WIDTH); } + header += std::format("{:^{}}|", "Time", TIME_WIDTH); + settings_.log.printf("%s\n", header.c_str()); +} + template void branch_and_bound_t::report_heuristic(f_t obj) { if (is_running_) { - f_t user_obj = compute_user_objective(original_lp_, obj); - f_t user_lower = compute_user_objective(original_lp_, get_lower_bound()); - std::string user_gap = user_mip_gap(original_lp_, obj, get_lower_bound()); - - settings_.log.printf( - "H %+13.6e %+10.6e %s %9.2f\n", - user_obj, - user_lower, - user_gap.c_str(), - toc(exploration_stats_.start_time)); + f_t lower_bound = get_lower_bound(); + f_t user_obj = compute_user_objective(original_lp_, obj); + f_t user_lower = compute_user_objective(original_lp_, lower_bound); + f_t user_gap = user_relative_gap(original_lp_, obj, lower_bound); + std::string user_gap_text = to_percentage(user_gap); + + std::string log_line = + std::format("{:^{}} {:>{}} {:>{}} {:^+{}.6e} {:^+{}.6e} {:>{}} {:>{}} {:^{}} {:^{}}", + "H", + SYMBOL_WIDTH, + "", // nodes explored + EXPLORED_WIDTH, + "", // nodes unexplored + UNEXPLORED_WIDTH, + user_obj, + OBJECTIVE_WIDTH, + user_lower, + BOUND_WIDTH, + "", // integer infeasible + INTEGER_INFEASIBLE_WIDTH, + "", // depth + DEPTH_WIDTH, + "", // iter/node + ITER_NODE_WIDTH, + user_gap_text, + GAP_WIDTH); + + if (settings_.deterministic) { log_line += std::format("{:^{}}", "", WORK_WIDTH); } + log_line += std::format(" {:>{}.2f}", toc(exploration_stats_.start_time), TIME_WIDTH); + settings_.log.printf("%s\n", log_line.c_str()); } else { if (solving_root_relaxation_.load()) { f_t user_obj = compute_user_objective(original_lp_, obj); - std::string user_gap = - user_mip_gap(original_lp_, obj, root_lp_current_lower_bound_.load()); - settings_.log.printf( - "New solution from primal heuristics. Objective %+.6e. Gap %s. Time %.2f\n", + f_t user_gap = user_relative_gap(original_lp_, obj, root_lp_current_lower_bound_.load()); + std::string user_gap_text = to_percentage(user_gap); + settings_.log.print_format( + "New solution from primal heuristics. Objective {:+.6e}. Gap {}. Time {:.2f}\n", user_obj, - user_gap.c_str(), + user_gap_text, toc(exploration_stats_.start_time)); } else { settings_.log.printf("New solution from primal heuristics. Objective %+.6e. Time %.2f\n", @@ -369,34 +420,32 @@ void branch_and_bound_t::report( const f_t user_lower = compute_user_objective(original_lp_, lower_bound); const f_t iters = static_cast(exploration_stats_.total_lp_iters); const f_t iter_node = nodes_explored > 0 ? iters / nodes_explored : iters; - const std::string user_gap = user_mip_gap(original_lp_, obj, lower_bound); - if (work_time >= 0) { - settings_.log.printf( - "%c %10d %10lu %+13.6e %+10.6e %6d %6d %7.1e %s %9.2f %9.2f\n", - symbol, - nodes_explored, - nodes_unexplored, - user_obj, - user_lower, - node_int_infeas, - node_depth, - iter_node, - user_gap.c_str(), - work_time, - toc(exploration_stats_.start_time)); - } else { - settings_.log.printf("%c %10d %10lu %+13.6e %+10.6e %6d %6d %7.1e %s %9.2f\n", - symbol, - nodes_explored, - nodes_unexplored, - user_obj, - user_lower, - node_int_infeas, - node_depth, - iter_node, - user_gap.c_str(), - toc(exploration_stats_.start_time)); - } + f_t user_gap = user_relative_gap(original_lp_, obj, lower_bound); + std::string user_gap_text = to_percentage(user_gap); + + std::string log_line = + std::format("{:^{}} {:>{}} {:>{}} {:^+{}.6e} {:^+{}.6e} {:>{}} {:>{}} {:^{}.1e} {:^{}}", + symbol, + SYMBOL_WIDTH, + nodes_explored, + EXPLORED_WIDTH, + nodes_unexplored, + UNEXPLORED_WIDTH, + user_obj, + OBJECTIVE_WIDTH, + user_lower, + BOUND_WIDTH, + node_int_infeas, + INTEGER_INFEASIBLE_WIDTH, + node_depth, + DEPTH_WIDTH, + iter_node, + ITER_NODE_WIDTH, + user_gap_text, + GAP_WIDTH); + if (work_time >= 0) { log_line += std::format(" {:>{}.2f}", work_time, WORK_WIDTH); } + log_line += std::format(" {:>{}.2f}", toc(exploration_stats_.start_time), TIME_WIDTH); + settings_.log.printf("%s\n", log_line.c_str()); } template @@ -2597,11 +2646,7 @@ mip_status_t branch_and_bound_t::solve(mip_solution_t& solut is_running_ = true; lower_bound_numerical_ = inf; - if (num_fractional != 0 && settings_.max_cut_passes > 0) { - settings_.log.printf( - " | Explored | Unexplored | Objective | Bound | IntInf | Depth | Iter/Node | " - "Gap | Time |\n"); - } + if (num_fractional != 0 && settings_.max_cut_passes > 0) { print_table_header(); } cut_pool_t cut_pool(original_lp_.num_cols, settings_); cut_generation_t cut_generation(cut_pool, @@ -2864,16 +2909,7 @@ mip_status_t branch_and_bound_t::solve(mip_solution_t& solut if (settings_.diving_settings.coefficient_diving != 0) { calculate_variable_locks(original_lp_, var_up_locks_, var_down_locks_); } - - if (settings_.deterministic) { - settings_.log.printf( - " | Explored | Unexplored | Objective | Bound | IntInf | Depth | Iter/Node " - "| Gap | Work | Time |\n"); - } else { - settings_.log.printf( - " | Explored | Unexplored | Objective | Bound | IntInf | Depth | Iter/Node " - "| Gap | Time |\n"); - } + print_table_header(); #pragma omp taskgroup { @@ -3385,9 +3421,10 @@ void branch_and_bound_t::deterministic_sync_callback() exploration_stats_.last_log = tic(); } - f_t obj = compute_user_objective(original_lp_, upper_bound); - f_t user_lower = compute_user_objective(original_lp_, lower_bound); - std::string gap_user = user_mip_gap(original_lp_, upper_bound, lower_bound); + f_t obj = compute_user_objective(original_lp_, upper_bound); + f_t user_lower = compute_user_objective(original_lp_, lower_bound); + f_t user_gap = user_relative_gap(original_lp_, upper_bound, lower_bound); + std::string user_gap_text = to_percentage(user_gap); std::string idle_workers; i_t idle_count = 0; @@ -3403,7 +3440,7 @@ void branch_and_bound_t::deterministic_sync_callback() exploration_stats_.nodes_unexplored, obj, user_lower, - gap_user.c_str(), + user_gap_text.c_str(), toc(exploration_stats_.start_time), state_hash, idle_workers.empty() ? "" : " ", diff --git a/cpp/src/branch_and_bound/branch_and_bound.hpp b/cpp/src/branch_and_bound/branch_and_bound.hpp index 0b32b2ece..15a6030db 100644 --- a/cpp/src/branch_and_bound/branch_and_bound.hpp +++ b/cpp/src/branch_and_bound/branch_and_bound.hpp @@ -263,6 +263,7 @@ class branch_and_bound_t { omp_atomic_t lower_bound_numerical_; std::function user_bound_callback_; + void print_table_header(); void report_heuristic(f_t obj); void report(char symbol, f_t obj, diff --git a/cpp/src/dual_simplex/logger.hpp b/cpp/src/dual_simplex/logger.hpp index f81308670..3f384e195 100644 --- a/cpp/src/dual_simplex/logger.hpp +++ b/cpp/src/dual_simplex/logger.hpp @@ -16,6 +16,8 @@ #include #include #include +#include +#include namespace cuopt::linear_programming::dual_simplex { @@ -84,6 +86,27 @@ class logger_t { } } + template + void print_format(std::format_string fmt, Args&&... args) + { + if (log) { + std::string msg = std::format(fmt, std::forward(args)...); + if (log_to_console) { +#ifdef CUOPT_LOG_ACTIVE_LEVEL + std::string_view msg_view = msg.ends_with("\n") ? msg.substr(0, msg.size() - 1) : msg; + CUOPT_LOG_INFO("%s%s", log_prefix.c_str(), msg.c_str()); +#else + std::printf("%s", msg.c_str()); + fflush(stdout); +#endif + } + if (log_to_file && log_file != nullptr) { + std::fprintf(log_file, "%s", msg.c_str()); + fflush(log_file); + } + } + } + void debug([[maybe_unused]] const char* fmt, ...) { if (log) { @@ -118,6 +141,27 @@ class logger_t { } } + template + void debug_format(std::format_string fmt, Args&&... args) + { + if (log) { + std::string msg = std::format(fmt, std::forward(args)...); + if (log_to_console) { +#ifdef CUOPT_LOG_ACTIVE_LEVEL + std::string_view msg_view = msg.ends_with("\n") ? msg.substr(0, msg.size() - 1) : msg; + CUOPT_LOG_TRACE("%s%s", log_prefix.c_str(), msg_view.c_str()); +#else + std::printf("%s", msg.c_str()); + fflush(stdout); +#endif + } + if (log_to_file && log_file != nullptr) { + std::fprintf(log_file, "%s", msg.c_str()); + fflush(log_file); + } + } + } + bool log; bool log_to_console; std::string log_prefix;