Skip to content

B&B logs deduplication #1352

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
nguidotti wants to merge 17 commits into from
Closed

B&B logs deduplication #1352

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
17 commits
Select commit Hold shift + click to select a range
a7f5121
logger_t now can support formatting strings based on `std::format`
nguidotti May 27, 2026
27f2973
moved search_tree object to a separated file. added a depth-first cle…
nguidotti May 27, 2026
501220b
track search progress using tree the weight metric. migrate the B&B l…
nguidotti May 27, 2026
9672194
simplified log lines construction in B&B
nguidotti May 29, 2026
8367299
switched to std::format for compile-time checks
nguidotti May 29, 2026
b865ae9
migrate node_id from int to uint64_t. bug fixes
nguidotti May 29, 2026
6d7f0f5
revert changes to node_id. added exception handling to the destructor.
nguidotti Jun 1, 2026
e5ea499
address coderabbit
nguidotti Jun 1, 2026
da1015f
revert log changes
nguidotti Jun 1, 2026
87cdf92
Merge branch 'main' into tree-progress
nguidotti Jun 2, 2026
6c04ed4
Merge branch 'main' into tree-progress
nguidotti Jun 3, 2026
f79029f
Merge remote-tracking branch 'origin/tree-progress' into tree-progress
nguidotti Jun 3, 2026
ffdc469
removed search progress from the logs. It is too inaccurate, especial…
nguidotti Jun 8, 2026
e47c61f
removed try-catch block in the destructor.
nguidotti Jun 8, 2026
5eb9730
removed changes to the search tree
nguidotti Jun 8, 2026
739aab2
fixed compilation
nguidotti Jun 8, 2026
3b9f99c
use constexpr constants to determine column width
nguidotti Jun 8, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
191 changes: 114 additions & 77 deletions cpp/src/branch_and_bound/branch_and_bound.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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 <typename f_t>
bool is_fractional(f_t x, variable_type_t var_type, f_t integer_tol)
{
Expand Down Expand Up @@ -195,22 +208,12 @@ f_t user_relative_gap(const lp_problem_t<i_t, f_t>& lp, f_t obj_value, f_t lower
return user_mip_gap;
}

template <typename i_t, typename f_t>
std::string user_mip_gap(const lp_problem_t<i_t, f_t>& lp, f_t obj_value, f_t lower_bound)
template <typename f_t>
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<f_t>::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<f_t>::infinity()) return "---";
if (value > 1e-3) { return std::format("{:5.1f}%", value * 100); }
return std::format("{:5.2f}%", value * 100);
}

#ifdef SHOW_DIVING_TYPE
Expand Down Expand Up @@ -326,29 +329,77 @@ void branch_and_bound_t<i_t, f_t>::set_initial_upper_bound(f_t bound)
upper_bound_ = bound;
}

template <typename i_t, typename f_t>
void branch_and_bound_t<i_t, f_t>::print_table_header()
{
std::string header =
std::format("{:^{}}|{:^{}}|{:^{}}|{:^{}}|{:^{}}|{:^{}}|{:^{}}|{:^{}}|{:^{}}|",

@chris-maes chris-maes Jun 8, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I find this significantly harder to read and understand than the printf format string. It's very easy to read a printf format string and understand the width and precision of each number printed out. I.e. %12.6e means to use a width of 12 with 6 digits of precision after the decimal. The following code is very difficult to read because I now must look up the width from the constants. Also it tells me nothing about the precision after the decimal point.

@nguidotti nguidotti Jun 8, 2026

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I can revert the changes with the constants, so it easier to read.

This specifically is just for the header of the table (so no precision). For the actual formatting for float, it is quite similar actually with the standard C formatting, e.g., {:>12.6f} is right-aligned, width 12 and precision 6. The main advantage here is to avoid manually setting the spacing for each log line and aligning to right/center/left. The syntax is the same that Python.

"",
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 <typename i_t, typename f_t>
void branch_and_bound_t<i_t, f_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<i_t, f_t>(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<i_t, f_t>(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",
Expand All @@ -369,34 +420,32 @@ void branch_and_bound_t<i_t, f_t>::report(
const f_t user_lower = compute_user_objective(original_lp_, lower_bound);
const f_t iters = static_cast<f_t>(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<i_t, f_t>(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 <typename i_t, typename f_t>
Expand Down Expand Up @@ -2597,11 +2646,7 @@ mip_status_t branch_and_bound_t<i_t, f_t>::solve(mip_solution_t<i_t, f_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<i_t, f_t> cut_pool(original_lp_.num_cols, settings_);
cut_generation_t<i_t, f_t> cut_generation(cut_pool,
Expand Down Expand Up @@ -2864,16 +2909,7 @@ mip_status_t branch_and_bound_t<i_t, f_t>::solve(mip_solution_t<i_t, f_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
{
Expand Down Expand Up @@ -3385,9 +3421,10 @@ void branch_and_bound_t<i_t, f_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<i_t, f_t>(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;
Expand All @@ -3403,7 +3440,7 @@ void branch_and_bound_t<i_t, f_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() ? "" : " ",
Expand Down
1 change: 1 addition & 0 deletions cpp/src/branch_and_bound/branch_and_bound.hpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -263,6 +263,7 @@ class branch_and_bound_t {
omp_atomic_t<f_t> lower_bound_numerical_;
std::function<void(f_t)> user_bound_callback_;

void print_table_header();
void report_heuristic(f_t obj);
void report(char symbol,
f_t obj,
Expand Down
44 changes: 44 additions & 0 deletions cpp/src/dual_simplex/logger.hpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,8 @@
#include <cstdarg>
#include <cstdio>
#include <cstring>
#include <format>

@aliceb-nv aliceb-nv Jun 3, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

is a very heavy heade in terms of compilation times in most c++ implementations. I'd be in favor of keeping it out of common headers and only use it in the TUs where it is required

@nguidotti nguidotti Jun 3, 2026 •
edited
Loading

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I did not notice a significant increase in compilation time by including or using the std::format. Maybe if it is used everywhere

@nguidotti nguidotti Jun 3, 2026

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

BTW, we can skip the compile-time checks of std::format with std::vformat. Although I would say the former is better.

#include <utility>

Comment thread
nguidotti marked this conversation as resolved.
namespace cuopt::linear_programming::dual_simplex {

Expand Down Expand Up @@ -84,6 +86,27 @@ class logger_t {
}
}

template <typename... Args>
void print_format(std::format_string<Args...> fmt, Args&&... args)
{
if (log) {
std::string msg = std::format(fmt, std::forward<Args&&>(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) {
Expand Down Expand Up @@ -118,6 +141,27 @@ class logger_t {
}
}

template <typename... Args>
void debug_format(std::format_string<Args...> fmt, Args&&... args)
{
if (log) {
std::string msg = std::format(fmt, std::forward<Args&&>(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;
Expand Down
Loading