Skip to content

Add logging and time budget for probing in presolve, and increase visibility of presolve rule switch-off #2865

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

Merged
jajhall merged 10 commits into from
Feb 24, 2026
Merged

Add logging and time budget for probing in presolve, and increase visibility of presolve rule switch-off #2865

Show file tree
Hide file tree
Changes from 8 commits
Commits
Show all changes
10 commits
Select commit Hold shift + click to select a range
9c097ca
Now using highsTimeSecondToString and highsTimeToString to standardis…
Feb 19, 2026
e8a4198
Merge branch 'latest' into fix-2860
Feb 19, 2026
350ce51
Improved probing time estimate and silenced logging in HPresolveAnaly…
Feb 19, 2026
3a92b40
Now reporting possible presolve_rule_off settings when options_->log_…
jajhall Feb 20, 2026
591fb8d
Merge branch 'latest' into fix-2860
Feb 21, 2026
f6de02b
Merge branch 'latest' into presolve-logging
jajhall Feb 21, 2026
849b1df
Merged presolve-logging into this branch and resolved minor conflict
Feb 21, 2026
9b202d2
Added unit test presolve-rule-off
Feb 21, 2026
1c2cb33
Replaced several silent = mipsolver && mipsolver->mipdata_->numRestar…
jajhall Feb 22, 2026
06309ae
Removed probing local time-out, cleaned up code following @fwesselm's…
jajhall Feb 22, 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
37 changes: 37 additions & 0 deletions check/TestPresolve.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -863,3 +863,40 @@ TEST_CASE("dual-bound-tightening", "[highs_test_presolve]") {
highs.passModel(lp);
REQUIRE(highs.presolve() == HighsStatus::kOk);
}

TEST_CASE("presolve-rule-off", "[highs_test_presolve]") {
std::string model = "afiro";
std::string model_file =
std::string(HIGHS_DIR) + "/check/instances/" + model + ".mps";
Highs h;
h.setOptionValue("output_flag", dev_run);
h.readModel(model_file);
h.setOptionValue("log_dev_level", 1);
h.setOptionValue("presolve_rule_logging", true);
HighsInt full_presolve_num_col, full_presolve_num_row;
// Run presolve with and without aggregator
for (HighsInt k = 0; k < 2; k++) {
h.presolve();
if (k == 0) {
full_presolve_num_col = h.getPresolvedLp().num_col_;
full_presolve_num_row = h.getPresolvedLp().num_row_;
if (dev_run)
printf("Presolved %s has num_col = %d; num_row = %d\n", model.c_str(),
int(full_presolve_num_col), int(full_presolve_num_row));
HighsPresolveLog presolve_log = h.getPresolveLog();
REQUIRE(presolve_log.rule[kPresolveRuleAggregator].col_removed > 0);
HighsInt presolve_rule_off =
std::pow(int(2), int(kPresolveRuleAggregator));
h.setOptionValue("presolve_rule_off", presolve_rule_off);
} else if (k > 0) {
HighsInt presolve_num_col = h.getPresolvedLp().num_col_;
HighsInt presolve_num_row = h.getPresolvedLp().num_row_;
REQUIRE(presolve_num_col > full_presolve_num_col);
REQUIRE(presolve_num_row > full_presolve_num_row);
if (dev_run)
printf("Presolved %s has num_col = %d; num_row = %d\n", model.c_str(),
int(presolve_num_col), int(presolve_num_row));
}
}
h.resetGlobalScheduler(true);
}
13 changes: 13 additions & 0 deletions highs/io/HighsIO.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -303,6 +303,19 @@ const std::string highsBoolToString(const bool b, const HighsInt field_width) {
return b ? " true" : "false";
}

const std::string highsTimeToString(const double time) {
return
#ifndef NDEBUG
std::to_string(time);
#else
std::to_string(static_cast<int>(time));
#endif
}

const std::string highsTimeSecondToString(const double time) {
return highsTimeToString(time) + "s";
}

const std::string highsInsertMdEscapes(const std::string& from_string) {
std::string to_string = "";
const char* underscore = "_";
Expand Down
3 changes: 2 additions & 1 deletion highs/io/HighsIO.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -108,5 +108,6 @@ const std::string highsBoolToString(const bool b,

const std::string highsInsertMdEscapes(const std::string& from_string);
const std::string highsInsertMdId(const std::string& from_string);

const std::string highsTimeToString(const double time);
const std::string highsTimeSecondToString(const double time);
#endif
115 changes: 86 additions & 29 deletions highs/presolve/HPresolve.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1683,12 +1683,70 @@ HPresolve::Result HPresolve::runProbing(HighsPostsolveStack& postsolve_stack) {
};
}

assert(mipsolver);
// Don't log probing for presolve before restart
const bool silent = mipsolver->mipdata_->numRestarts > 0;
HighsInt iBin = -1;
HighsInt iBin_probed = -1;
HighsInt num_binary = binaries.size();
double log_tt_interval = 5.0;
double tt0 = this->timer->read();
double log_tt = tt0;
HighsInt log_iBin_probed = iBin_probed;
double time_remaining = options->time_limit - tt0;
double probing_time_limit = 0.1 * time_remaining;
Copy link
Collaborator

@fwesselm fwesselm Feb 22, 2026

Choose a reason for hiding this comment

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

I understand that a time limit may be needed, but I also do not really like hard-coding things. However, having an option may also be too much.

Copy link
Member Author

@jajhall jajhall Feb 22, 2026

Choose a reason for hiding this comment

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

Agreed, but I felt that something was needed so that users for whom probing is very expensive could get some advantage from it.

Maybe it's better to let probing run to options->time_limit and print a message suggesting that probing in presolve is switched off.

bool logged_probing_time_limit = false;
for (const auto& binvar : binaries) {
iBin++;
HighsInt i = std::get<3>(binvar);

if (cliquetable.getSubstitution(i) != nullptr || !domain.isBinary(i))
continue;

iBin_probed++;
Copy link
Collaborator

@fwesselm fwesselm Feb 22, 2026

Choose a reason for hiding this comment

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

Would it be worth putting the new code that checks the time limit into a lambda? This could also be done later - it would make reading the probing code easier for me.

Copy link
Member Author

@jajhall jajhall Feb 22, 2026

Choose a reason for hiding this comment

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

Will do

double tt = this->timer->read();
if (tt > log_tt + log_tt_interval && iBin_probed > log_iBin_probed) {
Copy link
Collaborator

@fwesselm fwesselm Feb 22, 2026

Choose a reason for hiding this comment

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

It seems that nothing in this if block is done when silent = true, so maybe the outer if-check could look like this:

if (!silent && tt > log_tt + log_tt_interval && iBin_probed > log_iBin_probed)

and then the other checks for !silent could be removed.

Copy link
Member Author

@jajhall jajhall Feb 22, 2026

Choose a reason for hiding this comment

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

No, the block contains the return with Result::kStopped; if the probing time limit is reached. Since that is "lost" in what appears to be just logging tells me that I should refactor this section!

if (!silent && !logged_probing_time_limit &&
probing_time_limit < kHighsInf && !options->timeless_log) {
highsLogUser(options->log_options, HighsLogType::kInfo,
" Probing %d binaries with a time limit of %s\n",
int(num_binary),
highsTimeSecondToString(probing_time_limit).c_str());
logged_probing_time_limit = true;
}
if (tt > probing_time_limit) {
if (!silent)
highsLogUser(
options->log_options, HighsLogType::kWarning,
" Probing time limit reached: solver behaviour may be "
"non-deterministic\n");
return Result::kStopped;
}
if (!silent && !options->timeless_log) {
assert(iBin_probed > 0);
HighsInt dl_iBin_probed = iBin_probed - log_iBin_probed;
assert(dl_iBin_probed > 0);
double rate0 = (tt - tt0) / double(iBin_probed);
double rate1 = (tt - log_tt) / double(dl_iBin_probed);
double rate = std::max(rate0, rate1);
std::string rate_str =
" (rate " + highsTimeToString(1e3 * rate) + "/ms";
double expected_probing_finish_time =
tt + rate * (num_binary - iBin_probed);
std::string expected_probing_finish_time_str =
" => expected probing finish time " +
highsTimeSecondToString(expected_probing_finish_time) + ")";
std::string time_str = highsTimeSecondToString(tt);
highsLogUser(
options->log_options, HighsLogType::kInfo,
" Considered %d / %d binaries; %d probed %s%s %s\n", int(iBin),
int(num_binary), int(iBin_probed), rate_str.c_str(),
expected_probing_finish_time_str.c_str(), time_str.c_str());
log_tt = tt;
log_iBin_probed = iBin_probed;
}
}

bool tightenLimits = (numProbed - oldNumProbed) >= 2500;

// when a large percentage of columns have been deleted, stop this round
Expand Down Expand Up @@ -1761,9 +1819,6 @@ HPresolve::Result HPresolve::runProbing(HighsPostsolveStack& postsolve_stack) {
if (numLiftOpps >= maxNumLiftOpps)
implications.storeLiftingOpportunity = nullptr;

// printf("nprobed: %" HIGHSINT_FORMAT ", numCliques: %" HIGHSINT_FORMAT
// "\n", nprobed,
// cliquetable.numCliques());
if (domain.infeasible()) {
mipsolver->analysis_.mipTimerStop(kMipClockProbingPresolve);
return Result::kPrimalInfeasible;
Expand Down Expand Up @@ -5468,35 +5523,33 @@ HPresolve::Result HPresolve::presolve(HighsPostsolveStack& postsolve_stack) {
model->sense_ = ObjSense::kMinimize;
}

const bool silent = mipsolver && mipsolver->mipdata_->numRestarts > 0;
Copy link
Collaborator

@fwesselm fwesselm Feb 22, 2026

Choose a reason for hiding this comment

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

Would it be worth making this a method in HPresolve.h? Maybe not, but anyway:

bool isLogSilent() const {
  return mipsolver && mipsolver->mipdata_->numRestarts > 0;
}

Copy link
Member Author

@jajhall jajhall Feb 22, 2026

Choose a reason for hiding this comment

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

Would be more elegant

if (options->presolve != kHighsOffString) {
Copy link
Collaborator

@fwesselm fwesselm Feb 22, 2026

Choose a reason for hiding this comment

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

if (!silent && options->presolve != kHighsOffString) ?

if (!silent)
highsLogUser(options->log_options, HighsLogType::kInfo,
"Presolving model\n");
}
// Set up the logic to allow presolve rules, and logging for their
// effectiveness
analysis_.setup(this->model, this->options, this->numDeletedRows,
this->numDeletedCols);
this->numDeletedCols, silent);

if (options->presolve != kHighsOffString) {
if (mipsolver) mipsolver->mipdata_->cliquetable.setPresolveFlag(true);
if (!mipsolver || mipsolver->mipdata_->numRestarts == 0)
highsLogUser(options->log_options, HighsLogType::kInfo,
"Presolving model\n");

auto report = [&]() {
if (!mipsolver || mipsolver->mipdata_->numRestarts == 0) {
if (!silent) {
HighsInt numCol = model->num_col_ - numDeletedCols;
HighsInt numRow = model->num_row_ - numDeletedRows;
HighsInt numNonz =
static_cast<HighsInt>(Avalue.size() - freeslots.size());
// Only read the run time if it's to be printed
const double run_time = options->output_flag ? this->timer->read() : 0;
#ifndef NDEBUG
std::string time_str = " " + std::to_string(run_time) + "s";
#else
std::string time_str =
" " + std::to_string(static_cast<int>(run_time)) + "s";
#endif
std::string time_str = highsTimeSecondToString(run_time);
if (options->timeless_log) time_str = "";
highsLogUser(options->log_options, HighsLogType::kInfo,
"%" HIGHSINT_FORMAT " rows, %" HIGHSINT_FORMAT
" cols, %" HIGHSINT_FORMAT " nonzeros %s\n",
" cols, %" HIGHSINT_FORMAT " nonzeros %s\n",
Copy link
Collaborator

@fwesselm fwesselm Feb 22, 2026

Choose a reason for hiding this comment

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

Is the extra space needed?

Copy link
Member Author

@jajhall jajhall Feb 22, 2026

Choose a reason for hiding this comment

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

No, I don't know how that's crept in

numRow, numCol, numNonz, time_str.c_str());
}
};
Expand Down Expand Up @@ -6171,28 +6224,31 @@ HPresolve::Result HPresolve::removeDependentEquations(
const double time_limit =
std::max(1.0, std::min(0.01 * options->time_limit, 1000.0));
factor.setTimeLimit(time_limit);
const bool silent = mipsolver && mipsolver->mipdata_->numRestarts > 0;
// Determine rank deficiency of the equations
highsLogUser(options->log_options, HighsLogType::kInfo,
"Dependent equations search running on %d equations with time "
"limit of %.2fs\n",
static_cast<int>(matrix.num_col_), time_limit);
if (!silent)
highsLogUser(options->log_options, HighsLogType::kInfo,
"Dependent equations search running on %d equations with time "
"limit of %.2fs\n",
static_cast<int>(matrix.num_col_), time_limit);
double time_taken = -this->timer->read();
HighsInt build_return = factor.build();
time_taken += this->timer->read();
if (build_return == kBuildKernelReturnTimeout) {
// HFactor::build has timed out, so just return
highsLogUser(options->log_options, HighsLogType::kInfo,
"Dependent equations search terminated after %.3gs due to "
"expected time exceeding limit\n",
time_taken);
if (!silent)
highsLogUser(options->log_options, HighsLogType::kInfo,
"Dependent equations search terminated after %.3gs due to "
"expected time exceeding limit\n",
time_taken);
analysis_.logging_on_ = logging_on;
if (logging_on)
analysis_.stopPresolveRuleLog(kPresolveRuleDependentFreeCols);
return Result::kOk;
} else {
double pct_off_timeout =
1e2 * std::fabs(time_taken - time_limit) / time_limit;
if (pct_off_timeout < 1.0)
if (!silent && pct_off_timeout < 1.0)
highsLogUser(options->log_options, HighsLogType::kWarning,
"Dependent equations search finished within %.2f%% of limit "
"of %.2fs: "
Expand All @@ -6217,11 +6273,12 @@ HPresolve::Result HPresolve::removeDependentEquations(
num_fictitious_rows_skipped++;
}
}
highsLogUser(options->log_options, HighsLogType::kInfo,
"Dependent equations search removed %d rows and %d nonzeros "
"in %.2fs (limit = %.2fs)\n",
static_cast<int>(num_removed_row),
static_cast<int>(num_removed_nz), time_taken, time_limit);
if (!silent)
highsLogUser(options->log_options, HighsLogType::kInfo,
"Dependent equations search removed %d rows and %d nonzeros "
"in %.2fs (limit = %.2fs)\n",
static_cast<int>(num_removed_row),
static_cast<int>(num_removed_nz), time_taken, time_limit);
if (num_fictitious_rows_skipped)
highsLogDev(options->log_options, HighsLogType::kInfo,
", avoiding %d fictitious rows",
Expand Down
78 changes: 46 additions & 32 deletions highs/presolve/HPresolveAnalysis.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -11,21 +11,30 @@
void HPresolveAnalysis::setup(const HighsLp* model_,
const HighsOptions* options_,
const HighsInt& numDeletedRows_,
const HighsInt& numDeletedCols_) {
const HighsInt& numDeletedCols_,
const bool silent) {
model = model_;
options = options_;
numDeletedRows = &numDeletedRows_;
numDeletedCols = &numDeletedCols_;

this->allow_rule_.assign(kPresolveRuleCount, true);

if (options->presolve_rule_off) {
if (options->presolve_rule_off || options_->log_dev_level) {
// Some presolve rules are off
//
// Transform options->presolve_rule_off into logical settings in
// allow_rule_[*], commenting on the rules switched off
highsLogUser(options->log_options, HighsLogType::kInfo,
"Presolve rules not allowed:\n");
if (!silent) {
if (options->presolve_rule_off) {
highsLogUser(options->log_options, HighsLogType::kInfo,
"Presolve rules not allowed:\n");
} else {
highsLogUser(options->log_options, HighsLogType::kInfo,
"Permitted suppression of presolve rules via "
"presolve_rule_off option:\n");
}
}
HighsInt bit = 1;
for (HighsInt rule_type = kPresolveRuleMin; rule_type < kPresolveRuleCount;
rule_type++) {
Expand All @@ -35,17 +44,21 @@ void HPresolveAnalysis::setup(const HighsLp* model_,
// This is a rule that can be switched off, so comment
// positively if it is off
allow_rule_[rule_type] = allow;
if (!allow)
highsLogUser(options->log_options, HighsLogType::kInfo,
" Rule %2d (bit %4d): %s\n", (int)rule_type, (int)bit,
utilPresolveRuleTypeToString(rule_type).c_str());
} else if (!allow) {
if (!silent)
if (!allow ||
(!options->presolve_rule_off && options_->log_dev_level))
highsLogUser(options->log_options, HighsLogType::kInfo,
" Rule %2d (set bit %2d = %5d): %s\n",
int(rule_type), int(rule_type), int(bit),
utilPresolveRuleTypeToString(rule_type).c_str());
} else if (!allow && !silent) {
// This is a rule that cannot be switched off so, if an
// attempt is made, don't allow it to be off and comment
// negatively
highsLogUser(options->log_options, HighsLogType::kWarning,
"Cannot disallow rule %2d (bit %4d): %s\n", (int)rule_type,
(int)bit, utilPresolveRuleTypeToString(rule_type).c_str());
"Cannot disallow rule %2d (bit %2d = %5d): %s\n",
int(rule_type), int(rule_type), int(bit),
utilPresolveRuleTypeToString(rule_type).c_str());
}
bit *= 2;
}
Expand Down Expand Up @@ -175,32 +188,33 @@ bool HPresolveAnalysis::analysePresolveRuleLog(const bool report) {
if (report && sum_removed_row + sum_removed_col) {
const std::string rule =
"-------------------------------------------------------";
highsLogDev(log_options, HighsLogType::kInfo, "%s\n", rule.c_str());
highsLogDev(log_options, HighsLogType::kInfo,
"%-25s Rows Cols Calls\n",
"Presolve rule removed");
highsLogDev(log_options, HighsLogType::kInfo, "%s\n", rule.c_str());
highsLogUser(log_options, HighsLogType::kInfo, "%s\n", rule.c_str());
highsLogUser(log_options, HighsLogType::kInfo,
"%-25s Rows Cols Calls\n",
"Presolve rule removed");
highsLogUser(log_options, HighsLogType::kInfo, "%s\n", rule.c_str());
for (HighsInt rule_type = kPresolveRuleMin; rule_type < kPresolveRuleCount;
rule_type++)
if (presolve_log_.rule[rule_type].call ||
presolve_log_.rule[rule_type].row_removed ||
presolve_log_.rule[rule_type].col_removed)
highsLogDev(log_options, HighsLogType::kInfo, "%-25s %9d %9d %9d\n",
utilPresolveRuleTypeToString(rule_type).c_str(),
(int)presolve_log_.rule[rule_type].row_removed,
(int)presolve_log_.rule[rule_type].col_removed,
(int)presolve_log_.rule[rule_type].call);
highsLogDev(log_options, HighsLogType::kInfo, "%s\n", rule.c_str());
highsLogDev(log_options, HighsLogType::kInfo, "%-25s %9d %9d\n",
"Total reductions", (int)sum_removed_row, (int)sum_removed_col);
highsLogDev(log_options, HighsLogType::kInfo, "%s\n", rule.c_str());
highsLogDev(log_options, HighsLogType::kInfo, "%-25s %9d %9d\n",
"Original model", (int)original_num_row_,
(int)original_num_col_);
highsLogDev(log_options, HighsLogType::kInfo, "%-25s %9d %9d\n",
"Presolved model", (int)(original_num_row_ - sum_removed_row),
(int)(original_num_col_ - sum_removed_col));
highsLogDev(log_options, HighsLogType::kInfo, "%s\n", rule.c_str());
highsLogUser(log_options, HighsLogType::kInfo, "%-25s %9d %9d %9d\n",
utilPresolveRuleTypeToString(rule_type).c_str(),
(int)presolve_log_.rule[rule_type].row_removed,
(int)presolve_log_.rule[rule_type].col_removed,
(int)presolve_log_.rule[rule_type].call);
highsLogUser(log_options, HighsLogType::kInfo, "%s\n", rule.c_str());
highsLogUser(log_options, HighsLogType::kInfo, "%-25s %9d %9d\n",
"Total reductions", (int)sum_removed_row,
(int)sum_removed_col);
highsLogUser(log_options, HighsLogType::kInfo, "%s\n", rule.c_str());
highsLogUser(log_options, HighsLogType::kInfo, "%-25s %9d %9d\n",
"Original model", (int)original_num_row_,
(int)original_num_col_);
highsLogUser(log_options, HighsLogType::kInfo, "%-25s %9d %9d\n",
"Presolved model", (int)(original_num_row_ - sum_removed_row),
(int)(original_num_col_ - sum_removed_col));
highsLogUser(log_options, HighsLogType::kInfo, "%s\n", rule.c_str());
}
if (original_num_row_ == model->num_row_ &&
original_num_col_ == model->num_col_) {
Expand Down
3 changes: 2 additions & 1 deletion highs/presolve/HPresolveAnalysis.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -38,7 +38,8 @@ class HPresolveAnalysis {
// Transform options->presolve_rule_off into logical settings in
// allow_rule_[*], commenting on the rules switched off
void setup(const HighsLp* model_, const HighsOptions* options_,
const HighsInt& numDeletedRows_, const HighsInt& numDeletedCols_);
const HighsInt& numDeletedRows_, const HighsInt& numDeletedCols_,
const bool silent);
void resetNumDeleted();

std::string presolveReductionTypeToString(const HighsInt reduction_type);
Expand Down
Loading