Skip to content

Commit 7d266d8

Browse files
jajhalljajhall
committed
Now silencing PDLP debug logging with PDLP_DEBUG_LOG
1 parent 034a87b commit 7d266d8

File tree

14 files changed

+364
-344
lines changed

14 files changed

+364
-344
lines changed

‎check/TestPdlp.cpp‎

Lines changed: 34 additions & 26 deletions
Original file line numberDiff line numberDiff line change
@@ -1,9 +1,10 @@
1+
#include <chrono>
2+
13
#include "HCheckConfig.h"
24
#include "HConfig.h"
35
#include "Highs.h"
46
#include "SpecialLps.h"
57
#include "catch.hpp"
6-
#include <chrono>
78

89
const bool dev_run = false;
910
const double double_equal_tolerance = 1e-3;
@@ -334,7 +335,8 @@ TEST_CASE("pdlp-restart-add-row", "[pdlp]") {
334335
}
335336

336337
TEST_CASE("hi-pdlp", "[pdlp]") {
337-
std::string model = "adlittle"; //"adlittle";//"afiro";// shell// stair //25fv47 //fit2p
338+
std::string model =
339+
"adlittle"; //"adlittle";//"afiro";// shell// stair //25fv47 //fit2p
338340
std::string model_file =
339341
std::string(HIGHS_DIR) + "/check/instances/" + model + ".mps";
340342
Highs h;
@@ -344,11 +346,10 @@ TEST_CASE("hi-pdlp", "[pdlp]") {
344346
h.setOptionValue("kkt_tolerance", kkt_tolerance);
345347
h.setOptionValue("presolve", "off");
346348

347-
HighsInt pdlp_features_off =
348-
//kPdlpScalingOff +
349-
//kPdlpRestartOff
350-
kPdlpAdaptiveStepSizeOff
351-
;
349+
HighsInt pdlp_features_off =
350+
// kPdlpScalingOff +
351+
// kPdlpRestartOff
352+
kPdlpAdaptiveStepSizeOff;
352353
h.setOptionValue("pdlp_features_off", pdlp_features_off);
353354

354355
HighsInt pdlp_scaling = // 0;
@@ -358,18 +359,22 @@ TEST_CASE("hi-pdlp", "[pdlp]") {
358359
h.setOptionValue("pdlp_scaling_mode", pdlp_scaling);
359360
h.setOptionValue("pdlp_step_size_strategy", 1);
360361
h.setOptionValue("pdlp_restart_strategy", 2);
361-
h.setOptionValue("pdlp_iteration_limit",3520);
362+
h.setOptionValue("pdlp_iteration_limit", 3520);
362363
// h.setOptionValue("log_dev_level", kHighsLogDevLevelVerbose);
363364
auto start_hipdlp = std::chrono::high_resolution_clock::now();
364365
HighsStatus run_status = h.run();
365366
auto end_hipdlp = std::chrono::high_resolution_clock::now();
366-
auto duration_hipdlp = std::chrono::duration_cast<std::chrono::milliseconds>(end_hipdlp - start_hipdlp);
367+
auto duration_hipdlp = std::chrono::duration_cast<std::chrono::milliseconds>(
368+
end_hipdlp - start_hipdlp);
367369
std::cout << "\n--- HiPDLP Results ---" << std::endl;
368-
std::cout << "Status: " << h.modelStatusToString(h.getModelStatus()) << std::endl;
370+
std::cout << "Status: " << h.modelStatusToString(h.getModelStatus())
371+
<< std::endl;
369372
std::cout << "Iterations: " << h.getInfo().pdlp_iteration_count << std::endl;
370-
std::cout << "Wall time: " << duration_hipdlp.count() / 1000.0 << " seconds" << std::endl;
371-
std::cout << "Objective: " << h.getInfo().objective_function_value << std::endl;
372-
373+
std::cout << "Wall time: " << duration_hipdlp.count() / 1000.0 << " seconds"
374+
<< std::endl;
375+
std::cout << "Objective: " << h.getInfo().objective_function_value
376+
<< std::endl;
377+
373378
// REQUIRE(run_status == HighsStatus::kOk);
374379
// REQUIRE(h.getModelStatus() == HighsModelStatus::kOptimal);
375380
// REQUIRE(h.getInfo().pdlp_iteration_count == 11880);
@@ -381,32 +386,35 @@ TEST_CASE("hi-pdlp", "[pdlp]") {
381386
auto start_cupdlp = std::chrono::high_resolution_clock::now();
382387
run_status = h.run();
383388
auto end_cupdlp = std::chrono::high_resolution_clock::now();
384-
auto duration_cupdlp = std::chrono::duration_cast<std::chrono::milliseconds>(end_cupdlp - start_cupdlp);
389+
auto duration_cupdlp =
390+
std::chrono::duration_cast<std::chrono::milliseconds>(end_cupdlp -
391+
start_cupdlp);
385392
std::cout << "\n--- cuPDLP Results ---" << std::endl;
386-
std::cout << "Status: " << h.modelStatusToString(h.getModelStatus()) << std::endl;
387-
std::cout << "Iterations: " << h.getInfo().pdlp_iteration_count << std::endl;
388-
std::cout << "Wall time: " << duration_cupdlp.count() / 1000.0 << " seconds" << std::endl;
389-
std::cout << "Objective: " << h.getInfo().objective_function_value << std::endl;
393+
std::cout << "Status: " << h.modelStatusToString(h.getModelStatus())
394+
<< std::endl;
395+
std::cout << "Iterations: " << h.getInfo().pdlp_iteration_count
396+
<< std::endl;
397+
std::cout << "Wall time: " << duration_cupdlp.count() / 1000.0 << " seconds"
398+
<< std::endl;
399+
std::cout << "Objective: " << h.getInfo().objective_function_value
400+
<< std::endl;
390401
}
391402
h.resetGlobalScheduler(true);
392403
}
393404

394405
TEST_CASE("hi-pdlp-timer", "[pdlp]") {
395-
std::string model = "shell";//"avgas";//
406+
std::string model = "shell"; //"avgas";//
396407
std::string model_file =
397408
std::string(HIGHS_DIR) + "/check/instances/" + model + ".mps";
398409
Highs h;
399410
// h.setOptionValue("output_flag", dev_run);
400411
REQUIRE(h.readModel(model_file) == HighsStatus::kOk);
401412
REQUIRE(h.setOptionValue("solver", kHiPdlpString) == HighsStatus::kOk);
402-
HighsInt pdlp_features_off =
403-
//kPdlpScalingOff +
404-
//kPdlpRestartOff
405-
kPdlpAdaptiveStepSizeOff
406-
;
413+
HighsInt pdlp_features_off =
414+
// kPdlpScalingOff +
415+
// kPdlpRestartOff
416+
kPdlpAdaptiveStepSizeOff;
407417
h.setOptionValue("pdlp_features_off", pdlp_features_off);
408418
HighsStatus run_status = h.run();
409419
h.resetGlobalScheduler(true);
410-
411420
}
412-

‎highs/pdlp/HiPdlpTimer.h‎

Lines changed: 53 additions & 61 deletions
Original file line numberDiff line numberDiff line change
@@ -50,48 +50,43 @@ class HipdlpTimer {
5050
clock.resize(kNumHipdlpClock);
5151
clock[kHipdlpClockTotal] = 0;
5252
clock[kHipdlpClockPreprocess] =
53-
timer_pointer->clock_def("HiPDLP preprocess");
54-
clock[kHipdlpClockSolve] =
55-
timer_pointer->clock_def("HiPDLP solve");
53+
timer_pointer->clock_def("HiPDLP preprocess");
54+
clock[kHipdlpClockSolve] = timer_pointer->clock_def("HiPDLP solve");
5655
clock[kHipdlpClockPostprocess] =
57-
timer_pointer->clock_def("HiPDLP postprocess");
56+
timer_pointer->clock_def("HiPDLP postprocess");
5857
clock[kHipdlpClockIterateUpdate] =
59-
timer_pointer->clock_def("Iterate update");
60-
clock[kHipdlpClockMatrixMultiply] =
61-
timer_pointer->clock_def("Ax");
58+
timer_pointer->clock_def("Iterate update");
59+
clock[kHipdlpClockMatrixMultiply] = timer_pointer->clock_def("Ax");
6260
clock[kHipdlpClockMatrixTransposeMultiply] =
63-
timer_pointer->clock_def("Aty");
64-
clock[kHipdlpClockProjectX] =
65-
timer_pointer->clock_def("Project X");
66-
clock[kHipdlpClockProjectY] =
67-
timer_pointer->clock_def("Project Y");
61+
timer_pointer->clock_def("Aty");
62+
clock[kHipdlpClockProjectX] = timer_pointer->clock_def("Project X");
63+
clock[kHipdlpClockProjectY] = timer_pointer->clock_def("Project Y");
6864
clock[kHipdlpClockStepSizeAdjustment] =
69-
timer_pointer->clock_def("Step size adjustment");
65+
timer_pointer->clock_def("Step size adjustment");
7066
clock[kHipdlpClockConvergenceCheck] =
71-
timer_pointer->clock_def("Convergence check");
72-
clock[kHipdlpClockRestartCheck] =
73-
timer_pointer->clock_def("Restart check");
67+
timer_pointer->clock_def("Convergence check");
68+
clock[kHipdlpClockRestartCheck] = timer_pointer->clock_def("Restart check");
7469
clock[kHipdlpClockAverageIterate] =
75-
timer_pointer->clock_def("Average iterate");
70+
timer_pointer->clock_def("Average iterate");
7671
clock[kHipdlpClockAverageIterateUpdateX] =
77-
timer_pointer->clock_def("Average iterate update X");
72+
timer_pointer->clock_def("Average iterate update X");
7873
clock[kHipdlpClockAverageIterateUpdateY] =
79-
timer_pointer->clock_def("Average iterate update Y");
74+
timer_pointer->clock_def("Average iterate update Y");
8075
clock[kHipdlpClockAverageIterateComputeX] =
81-
timer_pointer->clock_def("Average iterate compute X");
76+
timer_pointer->clock_def("Average iterate compute X");
8277
clock[kHipdlpClockAverageIterateComputeY] =
83-
timer_pointer->clock_def("Average iterate compute Y");
78+
timer_pointer->clock_def("Average iterate compute Y");
8479
clock[kHipdlpClockAverageIterateMatrixMultiply] =
85-
timer_pointer->clock_def("Average iterate Ax");
80+
timer_pointer->clock_def("Average iterate Ax");
8681
clock[kHipdlpClockAverageIterateMatrixTransposeMultiply] =
87-
timer_pointer->clock_def("Average iterate Aty");
82+
timer_pointer->clock_def("Average iterate Aty");
8883
};
8984

90-
bool reportHipdlpClockList(const char* grepStamp,
91-
const std::vector<HighsInt> hipdlp_clock_list,
92-
const HighsTimerClock& hipdlp_timer_clock,
93-
const HighsInt kHipdlpClockIdeal = kHipdlpClockTotal,
94-
const double tolerance_percent_report_ = -1) {
85+
bool reportHipdlpClockList(
86+
const char* grepStamp, const std::vector<HighsInt> hipdlp_clock_list,
87+
const HighsTimerClock& hipdlp_timer_clock,
88+
const HighsInt kHipdlpClockIdeal = kHipdlpClockTotal,
89+
const double tolerance_percent_report_ = -1) {
9590
HighsTimer* timer_pointer = hipdlp_timer_clock.timer_pointer_;
9691
if (!timer_pointer->printf_flag) return false;
9792
const std::vector<HighsInt>& clock = hipdlp_timer_clock.clock_;
@@ -112,53 +107,50 @@ class HipdlpTimer {
112107
void reportHipdlpCoreClock(const HighsTimerClock& hipdlp_timer_clock) {
113108
const std::vector<HighsInt> hipdlp_clock_list{
114109
kHipdlpClockPreprocess, kHipdlpClockSolve, kHipdlpClockPostprocess};
115-
reportHipdlpClockList("HipdlpCore___", hipdlp_clock_list, hipdlp_timer_clock,
116-
kHipdlpClockTotal);
110+
reportHipdlpClockList("HipdlpCore___", hipdlp_clock_list,
111+
hipdlp_timer_clock, kHipdlpClockTotal);
117112
};
118113

119114
void reportHipdlpSolveClock(const HighsTimerClock& hipdlp_timer_clock) {
120115
const std::vector<HighsInt> hipdlp_clock_list{
121-
kHipdlpClockIterateUpdate, kHipdlpClockConvergenceCheck,
122-
kHipdlpClockRestartCheck, kHipdlpClockAverageIterate
123-
};
124-
reportHipdlpClockList("HipdlpSolve__", hipdlp_clock_list, hipdlp_timer_clock,
125-
kHipdlpClockSolve);
116+
kHipdlpClockIterateUpdate, kHipdlpClockConvergenceCheck,
117+
kHipdlpClockRestartCheck, kHipdlpClockAverageIterate};
118+
reportHipdlpClockList("HipdlpSolve__", hipdlp_clock_list,
119+
hipdlp_timer_clock, kHipdlpClockSolve);
126120
};
127121

128-
void reportHipdlpIterateUpdateClock(const HighsTimerClock& hipdlp_timer_clock) {
122+
void reportHipdlpIterateUpdateClock(
123+
const HighsTimerClock& hipdlp_timer_clock) {
129124
const std::vector<HighsInt> hipdlp_clock_list{
130-
kHipdlpClockMatrixMultiply, kHipdlpClockMatrixTransposeMultiply,
131-
kHipdlpClockProjectX, kHipdlpClockProjectY, kHipdlpClockStepSizeAdjustment
132-
};
133-
reportHipdlpClockList("HipdlpIterUpd", hipdlp_clock_list, hipdlp_timer_clock,
134-
kHipdlpClockIterateUpdate);
125+
kHipdlpClockMatrixMultiply, kHipdlpClockMatrixTransposeMultiply,
126+
kHipdlpClockProjectX, kHipdlpClockProjectY,
127+
kHipdlpClockStepSizeAdjustment};
128+
reportHipdlpClockList("HipdlpIterUpd", hipdlp_clock_list,
129+
hipdlp_timer_clock, kHipdlpClockIterateUpdate);
135130
};
136131

137-
void reportHipdlpAverageIterateClock(const HighsTimerClock& hipdlp_timer_clock) {
132+
void reportHipdlpAverageIterateClock(
133+
const HighsTimerClock& hipdlp_timer_clock) {
138134
const std::vector<HighsInt> hipdlp_clock_list{
139-
kHipdlpClockAverageIterateUpdateX,
140-
kHipdlpClockAverageIterateUpdateY,
141-
kHipdlpClockAverageIterateComputeX,
142-
kHipdlpClockAverageIterateComputeY,
143-
kHipdlpClockAverageIterateMatrixMultiply,
144-
kHipdlpClockAverageIterateMatrixTransposeMultiply
145-
};
146-
reportHipdlpClockList("HipdlpAvgIter", hipdlp_clock_list, hipdlp_timer_clock,
147-
kHipdlpClockAverageIterate);
135+
kHipdlpClockAverageIterateUpdateX,
136+
kHipdlpClockAverageIterateUpdateY,
137+
kHipdlpClockAverageIterateComputeX,
138+
kHipdlpClockAverageIterateComputeY,
139+
kHipdlpClockAverageIterateMatrixMultiply,
140+
kHipdlpClockAverageIterateMatrixTransposeMultiply};
141+
reportHipdlpClockList("HipdlpAvgIter", hipdlp_clock_list,
142+
hipdlp_timer_clock, kHipdlpClockAverageIterate);
148143
};
149144

150-
void reportHipdlpMatrixMultiplyClock(const HighsTimerClock& hipdlp_timer_clock) {
145+
void reportHipdlpMatrixMultiplyClock(
146+
const HighsTimerClock& hipdlp_timer_clock) {
151147
const std::vector<HighsInt> hipdlp_clock_list{
152-
kHipdlpClockMatrixMultiply,
153-
kHipdlpClockMatrixTransposeMultiply,
154-
kHipdlpClockAverageIterateMatrixMultiply,
155-
kHipdlpClockAverageIterateMatrixTransposeMultiply
156-
};
157-
reportHipdlpClockList("HipdlpMtxMult", hipdlp_clock_list, hipdlp_timer_clock,
158-
kHipdlpClockSolve);
148+
kHipdlpClockMatrixMultiply, kHipdlpClockMatrixTransposeMultiply,
149+
kHipdlpClockAverageIterateMatrixMultiply,
150+
kHipdlpClockAverageIterateMatrixTransposeMultiply};
151+
reportHipdlpClockList("HipdlpMtxMult", hipdlp_clock_list,
152+
hipdlp_timer_clock, kHipdlpClockSolve);
159153
};
160-
161154
};
162155

163156
#endif /* PDLP_HIPDLPTIMER_H_ */
164-

‎highs/pdlp/HiPdlpWrapper.cpp‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -54,7 +54,7 @@ HighsStatus solveLpHiPdlp(const HighsOptions& options, HighsTimer& timer,
5454

5555
// 4. Solve with HiPdlp
5656
std::vector<double> x, y;
57-
x.resize(pdlp.getnCol(),0.0);
57+
x.resize(pdlp.getnCol(), 0.0);
5858
y.resize(pdlp.getnRow(), 0.0);
5959

6060
pdlp.solve(x, y);

‎highs/pdlp/cupdlp/cupdlp_defs.h‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -41,6 +41,8 @@ extern "C" {
4141
#define CUPDLP_DUMP_LINESEARCH_STATS (1)
4242
#define CUPDLP_INEXACT_EPS (1e-4)
4343

44+
#define PDLP_DEBUG_LOG (0)
45+
4446
typedef struct CUPDLP_CUDA_DENSE_VEC CUPDLPvec;
4547
typedef struct CUPDLP_DENSE_MATRIX CUPDLPdense;
4648
typedef struct CUPDLP_CSR_MATRIX CUPDLPcsr;

‎highs/pdlp/cupdlp/cupdlp_solver.c‎

Lines changed: 5 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -907,9 +907,11 @@ cupdlp_retcode PDHG_Solve(const cupdlp_int* has_variables, CUPDLPwork *pdhg) {
907907
timers->nIter = 0;
908908
timers->dSolvingBeg = getTimeStamp();
909909

910-
pdhg->debug_pdlp_log_file_ = fopen("cuPDLP.log", "w");
911-
assert(pdhg->debug_pdlp_log_file_);
912-
debugPdlpDataInitialise(&pdhg->debug_pdlp_data_);
910+
if (PDLP_DEBUG_LOG) {
911+
pdhg->debug_pdlp_log_file_ = fopen("cuPDLP.log", "w");
912+
assert(pdhg->debug_pdlp_log_file_);
913+
debugPdlpDataInitialise(&pdhg->debug_pdlp_data_);
914+
}
913915

914916
// PDHG_Init_Data does nothing!
915917
PDHG_Init_Data(pdhg);

‎highs/pdlp/hipdlp/defs.hpp‎

Lines changed: 23 additions & 30 deletions
Original file line numberDiff line numberDiff line change
@@ -38,7 +38,7 @@ struct StepSizeConfig {
3838
double dual_step;
3939
double beta;
4040
double power_method_lambda;
41-
int step_size_iter = 0; //nStepSizeIter
41+
int step_size_iter = 0; // nStepSizeIter
4242
};
4343

4444
struct MalitskyPockParams {
@@ -172,46 +172,39 @@ struct DetailedTimings {
172172
double projection_time = 0.0;
173173
double step_size_adjustment_time = 0.0;
174174
double other_time = 0.0;
175-
175+
176176
void print(const std::string& solver_name,
177-
const HighsLogOptions log_options) const {
177+
const HighsLogOptions log_options) const {
178178
highsLogUser(log_options, HighsLogType::kInfo,
179-
"\n=== %s Detailed Timings ===\n",
180-
solver_name.c_str());
179+
"\n=== %s Detailed Timings ===\n", solver_name.c_str());
181180
highsLogUser(log_options, HighsLogType::kInfo,
182-
"Total time: %6.2f s\n", total_time);
181+
"Total time: %6.2f s\n", total_time);
183182
highsLogUser(log_options, HighsLogType::kInfo,
184-
"Iterate update: %6.2f s (%3.0f \%)\n",
185-
iterate_update_time,
186-
iterate_update_time/total_time*100);
183+
"Iterate update: %6.2f s (%3.0f \%)\n",
184+
iterate_update_time, iterate_update_time / total_time * 100);
187185
highsLogUser(log_options, HighsLogType::kInfo,
188-
" - Matrix multiply: %6.2f s (%3.0f \%)\n",
189-
matrix_multiply_time,
190-
matrix_multiply_time/total_time*100);
186+
" - Matrix multiply: %6.2f s (%3.0f \%)\n",
187+
matrix_multiply_time, matrix_multiply_time / total_time * 100);
191188
highsLogUser(log_options, HighsLogType::kInfo,
192-
" - Projection: %6.2f s (%3.0f \%)\n",
193-
projection_time,
194-
projection_time/total_time*100);
189+
" - Projection: %6.2f s (%3.0f \%)\n",
190+
projection_time, projection_time / total_time * 100);
195191
highsLogUser(log_options, HighsLogType::kInfo,
196-
" - Step size adjust: %6.2f s (%3.0f \%)\n",
197-
step_size_adjustment_time,
198-
step_size_adjustment_time/total_time*100);
192+
" - Step size adjust: %6.2f s (%3.0f \%)\n",
193+
step_size_adjustment_time,
194+
step_size_adjustment_time / total_time * 100);
199195
highsLogUser(log_options, HighsLogType::kInfo,
200-
"Convergence check: %6.2f s (%3.0f \%)\n",
201-
convergence_check_time,
202-
convergence_check_time/total_time*100);
196+
"Convergence check: %6.2f s (%3.0f \%)\n",
197+
convergence_check_time,
198+
convergence_check_time / total_time * 100);
203199
highsLogUser(log_options, HighsLogType::kInfo,
204-
"Restart check: %6.2f s (%3.0f \%)\n",
205-
restart_check_time,
206-
restart_check_time/total_time*100);
200+
"Restart check: %6.2f s (%3.0f \%)\n",
201+
restart_check_time, restart_check_time / total_time * 100);
207202
highsLogUser(log_options, HighsLogType::kInfo,
208-
"Average iterate comp: %6.2f s (%3.0f \%)\n",
209-
average_iterate_time,
210-
average_iterate_time/total_time*100);
203+
"Average iterate comp: %6.2f s (%3.0f \%)\n",
204+
average_iterate_time, average_iterate_time / total_time * 100);
211205
highsLogUser(log_options, HighsLogType::kInfo,
212-
"Other: %6.2f s (%3.0f \%)\n",
213-
other_time,
214-
other_time/total_time*100);
206+
"Other: %6.2f s (%3.0f \%)\n", other_time,
207+
other_time / total_time * 100);
215208
}
216209
};
217210

0 commit comments

Comments
 (0)