Introduced timeless_log option so logging is deterministic

src/ipm/IpxWrapper.cpp

@@ -85,6 +85,7 @@ HighsStatus solveLpIpx(const HighsOptions& options, HighsTimer& timer,
     parameters.debug = 4;
   }
   parameters.highs_logging = true;
+  parameters.timeless_log = options.timeless_log;
   parameters.log_options = &options.log_options;
   // Just test feasibility and optimality tolerances for now
   // ToDo Set more parameters

src/ipm/ipx/control.h

@@ -91,6 +91,7 @@ class Control {
     double centringRatioReduction() const {return parameters_.centring_ratio_reduction; }
     double centringAlphaScaling() const{return parameters_.centring_alpha_scaling; }
     ipxint badProductsTolerance() const{return parameters_.bad_products_tolerance; }
+    bool timelessLog() const{return parameters_.timeless_log; }
 
     const Parameters& parameters() const;
     void parameters(const Parameters& new_parameters);

src/ipm/ipx/ipm.cc

@@ -825,8 +825,9 @@ void IPM::PrintHeader() {
     << " "  << Format("Iter", 4)
     << "  " << Format("P.res", 8) << " " << Format("D.res", 8)
     << "  " << Format("P.obj", 15) << " " << Format("D.obj", 15)
-    << "  " << Format("mu", 8)
-    << "  " << Format("Time", 7);
+    << "  " << Format("mu", 8);
+  if (!control_.timelessLog())
+    h_logging_stream << "  " << Format("Time", 7);
   control_.hLog(h_logging_stream);
   control_.Debug()
     << "  " << Format("stepsizes", 9)
@@ -850,8 +851,9 @@ void IPM::PrintOutput() {
       << " "  << Scientific(iterate_->dresidual(), 8, 2)
       << "  " << Scientific(iterate_->pobjective_after_postproc(), 15, 8)
       << " "  << Scientific(iterate_->dobjective_after_postproc(), 15, 8)
-      << "  " << Scientific(iterate_->mu(), 8, 2)
-      << "  " << Fixed(control_.Elapsed(), 6, 0) << "s";
+      << "  " << Scientific(iterate_->mu(), 8, 2);
+    if (!control_.timelessLog())
+      h_logging_stream << "  " << Fixed(control_.Elapsed(), 6, 0) << "s";
     control_.hLog(h_logging_stream);
     control_.Debug()
       << "  " << Fixed(step_primal_, 4, 2) << " " << Fixed(step_dual_, 4, 2)

src/ipm/ipx/ipx_parameters.h

@@ -64,6 +64,7 @@ struct ipx_parameters {
 
     /* HiGHS logging parameters */
     bool highs_logging;
+    bool timeless_log;
     const HighsLogOptions* log_options;
 
 };

src/ipm/ipx/lp_solver.cc

@@ -649,9 +649,10 @@ void LpSolver::RunCrossover() {
 void LpSolver::PrintSummary() {
   std::stringstream h_logging_stream;
   h_logging_stream.str(std::string());
-  h_logging_stream << "Summary\n"
-                   << Textline("Runtime:") << fix2(control_.Elapsed()) << "s\n"
-                   << Textline("Status interior point solve:")
+  h_logging_stream << "Summary\n";
+  if (!control_.timelessLog())
+    h_logging_stream << Textline("Runtime:") << fix2(control_.Elapsed()) << "s\n";
+  h_logging_stream << Textline("Status interior point solve:")
                    << StatusString(info_.status_ipm) << '\n'
                    << Textline("Status crossover:")
                    << StatusString(info_.status_crossover) << '\n';

src/lp_data/Highs.cpp

@@ -3874,10 +3874,13 @@ HighsStatus Highs::callSolveQp() {
   // Define the QP solver iteration logging function
   settings.iteration_log.subscribe([this](Statistics& stats) {
     int rep = stats.iteration.size() - 1;
+    std::string time_string =
+        options_.timeless_log ? ""
+                              : highsFormatToString(" %9.2fs", stats.time[rep]);
     highsLogUser(options_.log_options, HighsLogType::kInfo,
-                 "%11d  %15.8g           %6d %9.2fs\n",
-                 int(stats.iteration[rep]), stats.objval[rep],
-                 int(stats.nullspacedimension[rep]), stats.time[rep]);
+                 "%11d  %15.8g           %6d%s\n", int(stats.iteration[rep]),
+                 stats.objval[rep], int(stats.nullspacedimension[rep]),
+                 time_string.c_str());
   });
 
   // Define the QP nullspace limit logging function
@@ -4611,9 +4614,11 @@ void Highs::reportSolvedLpQpStats() {
     highsLogUser(log_options, HighsLogType::kInfo,
                  "Relative P-D gap    : %17.10e\n", relative_primal_dual_gap);
   }
-  double run_time = timer_.read();
-  highsLogUser(log_options, HighsLogType::kInfo,
-               "HiGHS run time      : %13.2f\n", run_time);
+  if (!options_.timeless_log) {
+    double run_time = timer_.read();
+    highsLogUser(log_options, HighsLogType::kInfo,
+                 "HiGHS run time      : %13.2f\n", run_time);
+  }
 }
 
 HighsStatus Highs::crossover(const HighsSolution& user_solution) {

src/lp_data/HighsOptions.h

@@ -335,6 +335,7 @@ struct HighsOptionsStruct {
   // Control of HiGHS log
   bool output_flag;
   bool log_to_console;
+  bool timeless_log;
 
   // Options for IPM solver
   HighsInt ipm_iteration_limit;
@@ -485,6 +486,7 @@ struct HighsOptionsStruct {
         write_presolved_model_file(""),
         output_flag(false),
         log_to_console(false),
+        timeless_log(false),
         ipm_iteration_limit(0),
         pdlp_native_termination(false),
         pdlp_scaling(false),
@@ -847,6 +849,11 @@ class HighsOptions : public HighsOptionsStruct {
                                        advanced, &log_to_console, true);
     records.push_back(record_bool);
 
+    record_bool = new OptionRecordBool(
+        "timeless_log", "Suppression of time-based data in logging", true,
+        &timeless_log, false);// true); //
+    records.push_back(record_bool);
+
     record_string =
         new OptionRecordString(kSolutionFileString, "Solution file", advanced,
                                &solution_file, kHighsFilenameDefault);

src/mip/HighsMipSolver.cpp

@@ -773,6 +773,7 @@ void HighsMipSolver::cleanupSolve() {
                     gapValString.data());
   }
 
+  bool timeless_log = options_mip_->timeless_log;
   highsLogUser(options_mip_->log_options, HighsLogType::kInfo,
                "\nSolving report\n");
   if (this->orig_model_->model_name_.length())
@@ -783,12 +784,15 @@ void HighsMipSolver::cleanupSolve() {
                "  Status            %s\n"
                "  Primal bound      %.12g\n"
                "  Dual bound        %.12g\n"
-               "  Gap               %s\n"
-               "  P-D integral      %.12g\n"
-               "  Solution status   %s\n",
+               "  Gap               %s\n",
                utilModelStatusToString(modelstatus_).c_str(), primal_bound_,
-               dual_bound_, gapString.data(),
-               mipdata_->primal_dual_integral.value, solutionstatus.c_str());
+               dual_bound_, gapString.data());
+  if (!timeless_log)
+    highsLogUser(options_mip_->log_options, HighsLogType::kInfo,
+                 "  P-D integral      %.12g\n",
+                 mipdata_->primal_dual_integral.value);
+  highsLogUser(options_mip_->log_options, HighsLogType::kInfo,
+               "  Solution status   %s\n", solutionstatus.c_str());
   if (solutionstatus != "-")
     highsLogUser(options_mip_->log_options, HighsLogType::kInfo,
                  "                    %.12g (objective)\n"
@@ -797,21 +801,23 @@ void HighsMipSolver::cleanupSolve() {
                  "                    %.12g (row viol.)\n",
                  solution_objective_, bound_violation_, integrality_violation_,
                  row_violation_);
+  if (!timeless_log)
+    highsLogUser(options_mip_->log_options, HighsLogType::kInfo,
+                 "  Timing            %.2f (total)\n"
+                 "                    %.2f (presolve)\n"
+                 "                    %.2f (solve)\n"
+                 "                    %.2f (postsolve)\n",
+                 timer_.read(), analysis_.mipTimerRead(kMipClockPresolve),
+                 analysis_.mipTimerRead(kMipClockSolve),
+                 analysis_.mipTimerRead(kMipClockPostsolve));
   highsLogUser(options_mip_->log_options, HighsLogType::kInfo,
-               "  Timing            %.2f (total)\n"
-               "                    %.2f (presolve)\n"
-               "                    %.2f (solve)\n"
-               "                    %.2f (postsolve)\n"
                "  Max sub-MIP depth %d\n"
                "  Nodes             %llu\n"
                "  Repair LPs        %llu (%llu feasible; %llu iterations)\n"
                "  LP iterations     %llu (total)\n"
                "                    %llu (strong br.)\n"
                "                    %llu (separation)\n"
                "                    %llu (heuristics)\n",
-               timer_.read(), analysis_.mipTimerRead(kMipClockPresolve),
-               analysis_.mipTimerRead(kMipClockSolve),
-               analysis_.mipTimerRead(kMipClockPostsolve),
                int(max_submip_level), (long long unsigned)mipdata_->num_nodes,
                (long long unsigned)mipdata_->total_repair_lp,
                (long long unsigned)mipdata_->total_repair_lp_feasible,
@@ -821,7 +827,7 @@ void HighsMipSolver::cleanupSolve() {
                (long long unsigned)mipdata_->sepa_lp_iterations,
                (long long unsigned)mipdata_->heuristic_lp_iterations);
 
-  analysis_.reportMipTimer();
+  if (!timeless_log) analysis_.reportMipTimer();
 
   assert(modelstatus_ != HighsModelStatus::kNotset);
 }

src/mip/HighsMipSolverData.cpp

@@ -678,6 +678,7 @@ void HighsMipSolverData::runSetup() {
   const HighsLp& model = *mipsolver.model_;
 
   last_disptime = -kHighsInf;
+  disptime = 0;
 
   // Transform the reference of the objective limit and lower/upper
   // bounds from the original model to the current model, undoing the
@@ -1598,21 +1599,26 @@ void HighsMipSolverData::printDisplayLine(const int solution_source) {
   bool output_flag = *mipsolver.options_mip_->log_options.output_flag;
   if (!output_flag) return;
 
-  double time = mipsolver.timer_.read();
+  bool timeless_log = mipsolver.options_mip_->timeless_log;
+  disptime = timeless_log ? disptime + 1 : mipsolver.timer_.read();
   if (solution_source == kSolutionSourceNone &&
-      time - last_disptime < mipsolver.options_mip_->mip_min_logging_interval)
+      disptime - last_disptime <
+          mipsolver.options_mip_->mip_min_logging_interval)
     return;
-  last_disptime = time;
+  last_disptime = disptime;
+  std::string time_string =
+      timeless_log ? "" : highsFormatToString(" %7.1fs", disptime);
 
   if (num_disp_lines % 20 == 0) {
     if (num_disp_lines == 0) printSolutionSourceKey();
-    highsLogUser(
-        mipsolver.options_mip_->log_options, HighsLogType::kInfo,
-        // clang-format off
-	"\n        Nodes      |    B&B Tree     |            Objective Bounds              |  Dynamic Constraints |       Work      \n"
-          "Src  Proc. InQueue |  Leaves   Expl. | BestBound       BestSol              Gap |   Cuts   InLp Confl. | LpIters     Time\n\n"
-        // clang-format on
-    );
+    std::string work_string0 = timeless_log ? "   Work" : "      Work      ";
+    std::string work_string1 = timeless_log ? "LpIters" : "LpIters     Time";
+    highsLogUser(mipsolver.options_mip_->log_options, HighsLogType::kInfo,
+                 // clang-format off
+	"\n        Nodes      |    B&B Tree     |            Objective Bounds              |  Dynamic Constraints | %s\n"
+	  "Src  Proc. InQueue |  Leaves   Expl. | BestBound       BestSol              Gap |   Cuts   InLp Confl. | %s\n\n",
+                 // clang-format on
+                 work_string0.c_str(), work_string1.c_str());
 
     //"   %7s | %10s | %10s | %10s | %10s | %-15s | %-15s | %7s | %7s "
     //"| %8s | %8s\n",
@@ -1656,13 +1662,13 @@ void HighsMipSolverData::printDisplayLine(const int solution_source) {
     highsLogUser(
         mipsolver.options_mip_->log_options, HighsLogType::kInfo,
         // clang-format off
-                 " %s %7s %7s   %7s %6.2f%%   %-15s %-15s %8s   %6" HIGHSINT_FORMAT " %6" HIGHSINT_FORMAT " %6" HIGHSINT_FORMAT "   %7s %7.1fs\n",
+                 " %s %7s %7s   %7s %6.2f%%   %-15s %-15s %8s   %6" HIGHSINT_FORMAT " %6" HIGHSINT_FORMAT " %6" HIGHSINT_FORMAT "   %7s%s\n",
         // clang-format on
         solutionSourceToString(solution_source).c_str(), print_nodes.data(),
         queue_nodes.data(), print_leaves.data(), explored, lb_string.data(),
         ub_string.data(), gap_string.data(), cutpool.getNumCuts(),
         lp.numRows() - lp.getNumModelRows(), conflictPool.getNumConflicts(),
-        print_lp_iters.data(), time);
+        print_lp_iters.data(), time_string.c_str());
   } else {
     std::array<char, 22> ub_string;
     if (mipsolver.options_mip_->objective_bound < ub) {
@@ -1677,13 +1683,13 @@ void HighsMipSolverData::printDisplayLine(const int solution_source) {
     highsLogUser(
         mipsolver.options_mip_->log_options, HighsLogType::kInfo,
         // clang-format off
-        " %s %7s %7s   %7s %6.2f%%   %-15s %-15s %8.2f   %6" HIGHSINT_FORMAT " %6" HIGHSINT_FORMAT " %6" HIGHSINT_FORMAT "   %7s %7.1fs\n",
+        " %s %7s %7s   %7s %6.2f%%   %-15s %-15s %8.2f   %6" HIGHSINT_FORMAT " %6" HIGHSINT_FORMAT " %6" HIGHSINT_FORMAT "   %7s%s\n",
         // clang-format on
         solutionSourceToString(solution_source).c_str(), print_nodes.data(),
         queue_nodes.data(), print_leaves.data(), explored, lb_string.data(),
         ub_string.data(), gap, cutpool.getNumCuts(),
         lp.numRows() - lp.getNumModelRows(), conflictPool.getNumConflicts(),
-        print_lp_iters.data(), time);
+        print_lp_iters.data(), time_string.c_str());
   }
   // Check that limitsToBounds yields the same values for the
   // dual_bound, primal_bound (modulo optimization sense) and
@@ -1960,6 +1966,7 @@ void HighsMipSolverData::evaluateRootNode() {
 
   // make sure first line after solving root LP is printed
   last_disptime = -kHighsInf;
+  disptime = 0;
 
   mipsolver.analysis_.mipTimerStart(kMipClockRandomizedRounding1);
   heuristics.randomizedRounding(firstlpsol);

src/mip/HighsMipSolverData.h

@@ -118,6 +118,7 @@ struct HighsMipSolverData {
 
   HighsCDouble pruned_treeweight;
   double avgrootlpiters;
+  double disptime;
   double last_disptime;
   int64_t firstrootlpiters;
   int64_t num_nodes;
@@ -183,6 +184,7 @@ struct HighsMipSolverData {
         maxTreeSizeLog2(0),
         pruned_treeweight(0),
         avgrootlpiters(0.0),
+        disptime(0.0),
         last_disptime(0.0),
         firstrootlpiters(0),
         num_nodes(0),

src/presolve/HPresolve.cpp

@@ -4098,6 +4098,7 @@ HPresolve::Result HPresolve::presolve(HighsPostsolveStack& postsolve_stack) {
 #else
         std::string time_str = " " + std::to_string(int(run_time)) + "s";
 #endif
+        if (options->timeless_log) time_str = "";
         highsLogUser(options->log_options, HighsLogType::kInfo,
                      "%" HIGHSINT_FORMAT " rows, %" HIGHSINT_FORMAT
                      " cols, %" HIGHSINT_FORMAT " nonzeros %s\n",

src/simplex/HighsSimplexAnalysis.cpp

@@ -36,6 +36,7 @@ void HighsSimplexAnalysis::setup(const std::string lp_name, const HighsLp& lp,
       kHighsAnalysisLevelNlaData & options.highs_analysis_level;
   analyse_simplex_data =
       analyse_simplex_summary_data || analyse_simplex_runtime_data;
+  highs_run_time = 0;
   last_user_log_time = -kHighsInf;
   delta_user_log_time = 5e0;
 
@@ -54,6 +55,7 @@ void HighsSimplexAnalysis::setup(const std::string lp_name, const HighsLp& lp,
   //  AnIterNumCostlyDseIt = 0;
   // Copy messaging parameter from options
   messaging(options.log_options);
+  timeless_log = options.timeless_log;
   // Initialise the densities
   col_aq_density = 0;
   row_ep_density = 0;
@@ -380,13 +382,13 @@ void HighsSimplexAnalysis::userInvertReport(const bool force) {
 
 void HighsSimplexAnalysis::userInvertReport(const bool header,
                                             const bool force) {
-  const double highs_run_time = timer_->read();
+  highs_run_time = timeless_log ? highs_run_time + 1 : timer_->read();
   if (!force && highs_run_time < last_user_log_time + delta_user_log_time)
     return;
   analysis_log = std::unique_ptr<std::stringstream>(new std::stringstream());
   reportIterationObjective(header);
   reportInfeasibility(header);
-  reportRunTime(header, highs_run_time);
+  if (!timeless_log) reportRunTime(header, highs_run_time);
   highsLogUser(log_options, HighsLogType::kInfo, "%s\n",
                analysis_log->str().c_str());
   if (!header) last_user_log_time = highs_run_time;

src/simplex/HighsSimplexAnalysis.h

@@ -152,8 +152,10 @@ class HighsSimplexAnalysis {
         max_sum_average_log_extreme_dual_steepest_edge_weight_error(0.0),
         num_invert_report_since_last_header(-1),
         num_iteration_report_since_last_header(-1),
+        highs_run_time(0.0),
         last_user_log_time(-kHighsInf),
         delta_user_log_time(1e0),
+        timeless_log(false),
         average_concurrency(0.0),
         average_fraction_of_possible_minor_iterations_performed(0.0),
         sum_multi_chosen(0),
@@ -428,8 +430,10 @@ class HighsSimplexAnalysis {
 
   HighsInt num_invert_report_since_last_header;
   HighsInt num_iteration_report_since_last_header;
+  double highs_run_time;
   double last_user_log_time;
   double delta_user_log_time;
+  bool timeless_log;
 
   double average_concurrency;
   double average_fraction_of_possible_minor_iterations_performed;