Skip to content

Commit d08ffce

Browse files
filikatfilikat
committed
Fix timers
1 parent f655c97 commit d08ffce

3 files changed

Lines changed: 47 additions & 26 deletions

File tree

‎highs/ipm/hipo/factorhighs/Analyse.cpp‎

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1408,7 +1408,7 @@ Int Analyse::run(Symbolic& S) {
14081408

14091409
HIPO_CLOCK_START(2);
14101410
if (getPermutation()) return kRetOrderingError;
1411-
HIPO_CLOCK_STOP(2, data_, kTimeAnalyseMetis);
1411+
HIPO_CLOCK_STOP(2, data_, kTimeAnalyseOrdering);
14121412

14131413
HIPO_CLOCK_START(2);
14141414
permute(iperm_);
@@ -1439,11 +1439,12 @@ Int Analyse::run(Symbolic& S) {
14391439
relativeIndClique();
14401440
HIPO_CLOCK_STOP(2, data_, kTimeAnalyseRelInd);
14411441

1442+
HIPO_CLOCK_START(2);
14421443
computeBlockStart();
14431444
computeCriticalPath();
14441445
computeStackSize();
1445-
14461446
findTreeSplitting();
1447+
HIPO_CLOCK_STOP(2, data_, kTimeAnalyseOther);
14471448

14481449
// move relevant stuff into S
14491450
S.n_ = n_;

‎highs/ipm/hipo/factorhighs/DataCollector.cpp‎

Lines changed: 42 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -105,19 +105,21 @@ void DataCollector::printTimes(const Log& log) const {
105105
#if HIPO_TIMING_LEVEL >= 2
106106

107107
log_stream << "\tOrdering: "
108-
<< fix(times[kTimeAnalyseOrdering], 8, 4) << " ("
109-
<< fix(times[kTimeAnalyseOrdering] / times[kTimeAnalyse] * 100, 4, 1)
108+
<< fix(times_[kTimeAnalyseOrdering], 8, 4) << " ("
109+
<< fix(times_[kTimeAnalyseOrdering] / times_[kTimeAnalyse] * 100,
110+
4, 1)
110111
<< "%)\n";
111112
log_stream << "\tTree: "
112113
<< fix(times_[kTimeAnalyseTree], 8, 4) << " ("
113114
<< fix(times_[kTimeAnalyseTree] / times_[kTimeAnalyse] * 100, 4, 1)
114115
<< "%)\n";
115116
log_stream << "\tCounts: "
116117
<< fix(times_[kTimeAnalyseCount], 8, 4) << " ("
117-
<< fix(times_[kTimeAnalyseCount] / times_[kTimeAnalyse] * 100, 4, 1)
118+
<< fix(times_[kTimeAnalyseCount] / times_[kTimeAnalyse] * 100, 4,
119+
1)
118120
<< "%)\n";
119-
log_stream << "\tSupernodes: " << fix(times_[kTimeAnalyseSn], 8, 4)
120-
<< " ("
121+
log_stream << "\tSupernodes: "
122+
<< fix(times_[kTimeAnalyseSn], 8, 4) << " ("
121123
<< fix(times_[kTimeAnalyseSn] / times_[kTimeAnalyse] * 100, 4, 1)
122124
<< "%)\n";
123125
log_stream << "\tReorder: "
@@ -132,18 +134,25 @@ void DataCollector::printTimes(const Log& log) const {
132134
<< "%)\n";
133135
log_stream << "\tRelative indices: "
134136
<< fix(times_[kTimeAnalyseRelInd], 8, 4) << " ("
135-
<< fix(times_[kTimeAnalyseRelInd] / times_[kTimeAnalyse] * 100, 4, 1)
137+
<< fix(times_[kTimeAnalyseRelInd] / times_[kTimeAnalyse] * 100, 4,
138+
1)
139+
<< "%)\n";
140+
log_stream << "\tOther: "
141+
<< fix(times_[kTimeAnalyseOther], 8, 4) << " ("
142+
<< fix(times_[kTimeAnalyseOther] / times_[kTimeAnalyse] * 100, 4,
143+
1)
136144
<< "%)\n";
137145
#endif
138146

139147
log_stream << "----------------------------------------------------\n";
140-
log_stream << "Factorise time \t" << fix(times_[kTimeFactorise], 8, 4)
141-
<< "\n";
148+
log_stream << "Factorise time \t"
149+
<< fix(times_[kTimeFactorise], 8, 4) << "\n";
142150

143151
#if HIPO_TIMING_LEVEL >= 2
144152
log_stream << "\tPrepare fact: "
145153
<< fix(times_[kTimeFactorisePrepare], 8, 4) << " ("
146-
<< fix(times_[kTimeFactorisePrepare] / times_[kTimeFactorise] * 100,
154+
<< fix(times_[kTimeFactorisePrepare] / times_[kTimeFactorise] *
155+
100,
147156
4, 1)
148157
<< "%)\n";
149158
log_stream << "\tAssemble original: "
@@ -180,8 +189,8 @@ void DataCollector::printTimes(const Log& log) const {
180189

181190
log_stream << "\t\tmain: " << fix(times_[kTimeDenseFact_main], 8, 4)
182191
<< "\n";
183-
log_stream << "\t\tSchur: " << fix(times_[kTimeDenseFact_schur], 8, 4)
184-
<< "\n";
192+
log_stream << "\t\tSchur: "
193+
<< fix(times_[kTimeDenseFact_schur], 8, 4) << "\n";
185194
log_stream << "\t\tkernel: "
186195
<< fix(times_[kTimeDenseFact_kernel], 8, 4) << "\n";
187196
log_stream << "\t\tconvert: "
@@ -207,8 +216,8 @@ void DataCollector::printTimes(const Log& log) const {
207216
<< fix(times_[kTimeSolveSolve_dense], 8, 4) << "\n";
208217
log_stream << "\t\tsparse: "
209218
<< fix(times_[kTimeSolveSolve_sparse], 8, 4) << "\n";
210-
log_stream << "\t\tswap: " << fix(times_[kTimeSolveSolve_swap], 8, 4)
211-
<< "\n";
219+
log_stream << "\t\tswap: "
220+
<< fix(times_[kTimeSolveSolve_swap], 8, 4) << "\n";
212221
#endif
213222
log_stream << "----------------------------------------------------\n";
214223

@@ -223,37 +232,44 @@ void DataCollector::printTimes(const Log& log) const {
223232
log_stream << "BLAS time \t" << fix(total_blas_time, 8, 4)
224233
<< '\n';
225234
log_stream << "\tcopy: \t" << fix(times_[kTimeBlas_copy], 8, 4)
226-
<< " (" << fix(times_[kTimeBlas_copy] / total_blas_time * 100, 4, 1)
235+
<< " ("
236+
<< fix(times_[kTimeBlas_copy] / total_blas_time * 100, 4, 1)
227237
<< "%) in "
228238
<< integer(blas_calls_[kTimeBlas_copy - kTimeBlasStart], 10)
229239
<< " calls\n";
230240
log_stream << "\taxpy: \t" << fix(times_[kTimeBlas_axpy], 8, 4)
231-
<< " (" << fix(times_[kTimeBlas_axpy] / total_blas_time * 100, 4, 1)
241+
<< " ("
242+
<< fix(times_[kTimeBlas_axpy] / total_blas_time * 100, 4, 1)
232243
<< "%) in "
233244
<< integer(blas_calls_[kTimeBlas_axpy - kTimeBlasStart], 10)
234245
<< " calls\n";
235246
log_stream << "\tscal: \t" << fix(times_[kTimeBlas_scal], 8, 4)
236-
<< " (" << fix(times_[kTimeBlas_scal] / total_blas_time * 100, 4, 1)
247+
<< " ("
248+
<< fix(times_[kTimeBlas_scal] / total_blas_time * 100, 4, 1)
237249
<< "%) in "
238250
<< integer(blas_calls_[kTimeBlas_scal - kTimeBlasStart], 10)
239251
<< " calls\n";
240252
log_stream << "\tswap: \t" << fix(times_[kTimeBlas_swap], 8, 4)
241-
<< " (" << fix(times_[kTimeBlas_swap] / total_blas_time * 100, 4, 1)
253+
<< " ("
254+
<< fix(times_[kTimeBlas_swap] / total_blas_time * 100, 4, 1)
242255
<< "%) in "
243256
<< integer(blas_calls_[kTimeBlas_swap - kTimeBlasStart], 10)
244257
<< " calls\n";
245258
log_stream << "\tgemv: \t" << fix(times_[kTimeBlas_gemv], 8, 4)
246-
<< " (" << fix(times_[kTimeBlas_gemv] / total_blas_time * 100, 4, 1)
259+
<< " ("
260+
<< fix(times_[kTimeBlas_gemv] / total_blas_time * 100, 4, 1)
247261
<< "%) in "
248262
<< integer(blas_calls_[kTimeBlas_gemv - kTimeBlasStart], 10)
249263
<< " calls\n";
250264
log_stream << "\ttrsv: \t" << fix(times_[kTimeBlas_trsv], 8, 4)
251-
<< " (" << fix(times_[kTimeBlas_trsv] / total_blas_time * 100, 4, 1)
265+
<< " ("
266+
<< fix(times_[kTimeBlas_trsv] / total_blas_time * 100, 4, 1)
252267
<< "%) in "
253268
<< integer(blas_calls_[kTimeBlas_trsv - kTimeBlasStart], 10)
254269
<< " calls\n";
255270
log_stream << "\ttpsv: \t" << fix(times_[kTimeBlas_tpsv], 8, 4)
256-
<< " (" << fix(times_[kTimeBlas_tpsv] / total_blas_time * 100, 4, 1)
271+
<< " ("
272+
<< fix(times_[kTimeBlas_tpsv] / total_blas_time * 100, 4, 1)
257273
<< "%) in "
258274
<< integer(blas_calls_[kTimeBlas_tpsv - kTimeBlasStart], 10)
259275
<< " calls\n";
@@ -263,17 +279,20 @@ void DataCollector::printTimes(const Log& log) const {
263279
<< integer(blas_calls_[kTimeBlas_ger - kTimeBlasStart], 10)
264280
<< " calls\n";
265281
log_stream << "\ttrsm: \t" << fix(times_[kTimeBlas_trsm], 8, 4)
266-
<< " (" << fix(times_[kTimeBlas_trsm] / total_blas_time * 100, 4, 1)
282+
<< " ("
283+
<< fix(times_[kTimeBlas_trsm] / total_blas_time * 100, 4, 1)
267284
<< "%) in "
268285
<< integer(blas_calls_[kTimeBlas_trsm - kTimeBlasStart], 10)
269286
<< " calls\n";
270287
log_stream << "\tsyrk: \t" << fix(times_[kTimeBlas_syrk], 8, 4)
271-
<< " (" << fix(times_[kTimeBlas_syrk] / total_blas_time * 100, 4, 1)
288+
<< " ("
289+
<< fix(times_[kTimeBlas_syrk] / total_blas_time * 100, 4, 1)
272290
<< "%) in "
273291
<< integer(blas_calls_[kTimeBlas_syrk - kTimeBlasStart], 10)
274292
<< " calls\n";
275293
log_stream << "\tgemm: \t" << fix(times_[kTimeBlas_gemm], 8, 4)
276-
<< " (" << fix(times_[kTimeBlas_gemm] / total_blas_time * 100, 4, 1)
294+
<< " ("
295+
<< fix(times_[kTimeBlas_gemm] / total_blas_time * 100, 4, 1)
277296
<< "%) in "
278297
<< integer(blas_calls_[kTimeBlas_gemm - kTimeBlasStart], 10)
279298
<< " calls\n";

‎highs/ipm/hipo/factorhighs/Timing.h‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -7,13 +7,14 @@ namespace hipo {
77

88
enum TimeItems {
99
kTimeAnalyse, // TIMING_LEVEL 1
10-
kTimeAnalyseOrdering, // TIMING_LEVEL 2
10+
kTimeAnalyseOrdering, // TIMING_LEVEL 2
1111
kTimeAnalyseTree, // TIMING_LEVEL 2
1212
kTimeAnalyseCount, // TIMING_LEVEL 2
1313
kTimeAnalysePattern, // TIMING_LEVEL 2
1414
kTimeAnalyseSn, // TIMING_LEVEL 2
1515
kTimeAnalyseReorder, // TIMING_LEVEL 2
1616
kTimeAnalyseRelInd, // TIMING_LEVEL 2
17+
kTimeAnalyseOther, // TIMING LEVEL 2
1718
kTimeFactorise, // TIMING_LEVEL 1
1819
kTimeFactorisePrepare, // TIMING_LEVEL 2
1920
kTimeFactoriseAssembleOriginal, // TIMING_LEVEL 2

0 commit comments

Comments
 (0)