Skip to content

Commit

Permalink
[BENCHMARK_APP/C++] Align performance counters and report output (ope…
Browse files Browse the repository at this point in the history 
…nvinotoolkit#14140)

* [BENCHMARK_APP/C++] Align performance counters output, set all output time values to milliseconds

* [C++] Style fixes
  • Loading branch information
@PiotrKrzem
PiotrKrzem authored Nov 30, 2022
1 parent 5f06431 commit 5708285
Show file tree
Hide file tree
Showing 2 changed files with 55 additions and 39 deletions.
2 changes: 1 addition & 1 deletion samples/cpp/benchmark_app/main.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1240,7 +1240,7 @@ int main(int argc, char* argv[]) {
if (!FLAGS_exec_graph_path.empty()) {
try {
ov::serialize(compiledModel.get_runtime_model(), FLAGS_exec_graph_path);
slog::info << "executable graph is stored to " << FLAGS_exec_graph_path << slog::endl;
slog::info << "Executable graph is stored to " << FLAGS_exec_graph_path << slog::endl;
} catch (const std::exception& ex) {
slog::err << "Can't get executable graph: " << ex.what() << slog::endl;
}
Expand Down
92 changes: 54 additions & 38 deletions samples/cpp/common/utils/include/samples/common.hpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1013,32 +1013,33 @@ static UNUSED void printPerformanceCounts(std::vector<ov::ProfilingInfo> perform
const int maxLayerName = 30;

if (it.node_name.length() >= maxLayerName) {
toPrint = it.node_name.substr(0, maxLayerName - 4);
toPrint = it.node_name.substr(0, maxLayerName - 5);
toPrint += "...";
}

stream << std::setw(maxLayerName) << std::left << toPrint;
stream << std::setw(maxLayerName) << std::left << toPrint << " ";
switch (it.status) {
case ov::ProfilingInfo::Status::EXECUTED:
stream << std::setw(15) << std::left << "EXECUTED";
stream << std::setw(15) << std::left << "EXECUTED ";
break;
case ov::ProfilingInfo::Status::NOT_RUN:
stream << std::setw(15) << std::left << "NOT_RUN";
stream << std::setw(15) << std::left << "NOT_RUN ";
break;
case ov::ProfilingInfo::Status::OPTIMIZED_OUT:
stream << std::setw(15) << std::left << "OPTIMIZED_OUT";
stream << std::setw(15) << std::left << "OPTIMIZED_OUT ";
break;
}
stream << std::setw(30) << std::left << "layerType: " + std::string(it.node_type) + " ";
stream << std::setw(20) << std::left << "realTime: " + std::to_string(it.real_time.count());
stream << std::setw(20) << std::left << "cpu: " + std::to_string(it.cpu_time.count());
stream << " execType: " << it.exec_type << std::endl;
stream << std::setw(30) << std::left << "execType: " + std::string(it.exec_type) + " ";
stream << std::setw(25) << std::left << "realTime (ms): " + std::to_string(it.real_time.count() / 1000.0) + " ";
stream << std::setw(25) << std::left << "cpuTime (ms): " + std::to_string(it.cpu_time.count() / 1000.0) + " ";
stream << std::endl;
if (it.real_time.count() > 0) {
totalTime += it.real_time;
}
}
stream << std::setw(20) << std::left << "Total time: " + std::to_string(totalTime.count()) << " microseconds"
<< std::endl;
stream << std::setw(25) << std::left << "Total time: " + std::to_string(totalTime.count() / 1000.0)
<< " milliseconds" << std::endl;
std::cout << std::endl;
std::cout << "Full device name: " << deviceName << std::endl;
std::cout << std::endl;
Expand Down Expand Up @@ -1075,25 +1076,29 @@ static UNUSED void printPerformanceCountsNoSort(std::vector<ov::ProfilingInfo> p
const int maxLayerName = 30;

if (it.node_name.length() >= maxLayerName) {
toPrint = it.node_name.substr(0, maxLayerName - 4);
toPrint = it.node_name.substr(0, maxLayerName - 5);
toPrint += "...";
}

stream << std::setw(maxLayerName) << std::left << toPrint;
stream << std::setw(maxLayerName) << std::left << toPrint << " ";
switch (it.status) {
case ov::ProfilingInfo::Status::EXECUTED:
stream << std::setw(15) << std::left << "EXECUTED";
stream << std::setw(15) << std::left << "EXECUTED ";
break;
case ov::ProfilingInfo::Status::NOT_RUN:
stream << std::setw(15) << std::left << "NOT_RUN";
stream << std::setw(15) << std::left << "NOT_RUN ";
break;
case ov::ProfilingInfo::Status::OPTIMIZED_OUT:
stream << std::setw(15) << std::left << "OPTIMIZED_OUT";
stream << std::setw(15) << std::left << "OPTIMIZED_OUT ";
break;
}
stream << std::setw(30) << std::left << "layerType: " + std::string(it.node_type) + " ";
stream << std::setw(20) << std::left << "realTime: " + std::to_string(it.real_time.count());
stream << std::setw(15) << std::left << "cpu: " + std::to_string(it.cpu_time.count());
stream << std::setw(30) << std::left << "execType: " + std::string(it.exec_type) + " ";
stream << std::setw(25) << std::left
<< "realTime (ms): " + std::to_string(it.real_time.count() / 1000.0) + " ";
stream << std::setw(25) << std::left
<< "cpuTime (ms): " + std::to_string(it.cpu_time.count() / 1000.0) + " ";

double opt_proportion = it.real_time.count() * 100.0 / totalTime.count();
std::stringstream opt_proportion_ss;
opt_proportion_ss << std::fixed << std::setprecision(2) << opt_proportion;
Expand All @@ -1102,11 +1107,12 @@ static UNUSED void printPerformanceCountsNoSort(std::vector<ov::ProfilingInfo> p
opt_proportion_str = "N/A";
}
stream << std::setw(20) << std::left << "proportion: " + opt_proportion_str + "%";
stream << " execType: " << it.exec_type << std::endl;

stream << std::endl;
}
}
stream << std::setw(20) << std::left << "Total time: " + std::to_string(totalTime.count() / 1000.0)
<< " microseconds" << std::endl;
stream << std::setw(25) << std::left << "Total time: " + std::to_string(totalTime.count() / 1000.0)
<< " milliseconds" << std::endl;
std::cout << std::endl;
std::cout << "Full device name: " << deviceName << std::endl;
std::cout << std::endl;
Expand Down Expand Up @@ -1143,25 +1149,29 @@ static UNUSED void printPerformanceCountsDescendSort(std::vector<ov::ProfilingIn
const int maxLayerName = 30;

if (it.node_name.length() >= maxLayerName) {
toPrint = it.node_name.substr(0, maxLayerName - 4);
toPrint = it.node_name.substr(0, maxLayerName - 5);
toPrint += "...";
}

stream << std::setw(maxLayerName) << std::left << toPrint;
stream << std::setw(maxLayerName) << std::left << toPrint << " ";
switch (it.status) {
case ov::ProfilingInfo::Status::EXECUTED:
stream << std::setw(15) << std::left << "EXECUTED";
stream << std::setw(15) << std::left << "EXECUTED ";
break;
case ov::ProfilingInfo::Status::NOT_RUN:
stream << std::setw(15) << std::left << "NOT_RUN";
stream << std::setw(15) << std::left << "NOT_RUN ";
break;
case ov::ProfilingInfo::Status::OPTIMIZED_OUT:
stream << std::setw(15) << std::left << "OPTIMIZED_OUT";
stream << std::setw(15) << std::left << "OPTIMIZED_OUT ";
break;
}
stream << std::setw(30) << std::left << "layerType: " + std::string(it.node_type) + " ";
stream << std::setw(20) << std::left << "realTime: " + std::to_string(it.real_time.count());
stream << std::setw(15) << std::left << "cpu: " + std::to_string(it.cpu_time.count());
stream << std::setw(30) << std::left << "execType: " + std::string(it.exec_type) + " ";
stream << std::setw(25) << std::left
<< "realTime (ms): " + std::to_string(it.real_time.count() / 1000.0) + " ";
stream << std::setw(25) << std::left
<< "cpuTime (ms): " + std::to_string(it.cpu_time.count() / 1000.0) + " ";

double opt_proportion = it.real_time.count() * 100.0 / totalTime.count();
std::stringstream opt_proportion_ss;
opt_proportion_ss << std::fixed << std::setprecision(2) << opt_proportion;
Expand All @@ -1170,11 +1180,12 @@ static UNUSED void printPerformanceCountsDescendSort(std::vector<ov::ProfilingIn
opt_proportion_str = "N/A";
}
stream << std::setw(20) << std::left << "proportion: " + opt_proportion_str + "%";
stream << " execType: " << it.exec_type << std::endl;

stream << std::endl;
}
}
stream << std::setw(20) << std::left << "Total time: " + std::to_string(totalTime.count() / 1000.0)
<< " microseconds" << std::endl;
stream << std::setw(25) << std::left << "Total time: " + std::to_string(totalTime.count() / 1000.0)
<< " milliseconds" << std::endl;
std::cout << std::endl;
std::cout << "Full device name: " << deviceName << std::endl;
std::cout << std::endl;
Expand Down Expand Up @@ -1208,15 +1219,19 @@ static UNUSED void printPerformanceCountsSimpleSort(std::vector<ov::ProfilingInf
const int maxLayerName = 30;

if (it.node_name.length() >= maxLayerName) {
toPrint = it.node_name.substr(0, maxLayerName - 4);
toPrint = it.node_name.substr(0, maxLayerName - 5);
toPrint += "...";
}

stream << std::setw(maxLayerName) << std::left << toPrint;
stream << std::setw(15) << std::left << "EXECUTED";
stream << std::setw(maxLayerName) << std::left << toPrint << " ";
stream << std::setw(15) << std::left << "EXECUTED ";
stream << std::setw(30) << std::left << "layerType: " + std::string(it.node_type) + " ";
stream << std::setw(20) << std::left << "realTime: " + std::to_string(it.real_time.count());
stream << std::setw(15) << std::left << "cpu: " + std::to_string(it.cpu_time.count());
stream << std::setw(30) << std::left << "execType: " + std::string(it.exec_type) + " ";
stream << std::setw(25) << std::left
<< "realTime (ms): " + std::to_string(it.real_time.count() / 1000.0) + " ";
stream << std::setw(25) << std::left
<< "cpuTime (ms): " + std::to_string(it.cpu_time.count() / 1000.0) + " ";

double opt_proportion = it.real_time.count() * 100.0 / totalTime.count();
std::stringstream opt_proportion_ss;
opt_proportion_ss << std::fixed << std::setprecision(2) << opt_proportion;
Expand All @@ -1225,12 +1240,13 @@ static UNUSED void printPerformanceCountsSimpleSort(std::vector<ov::ProfilingInf
opt_proportion_str = "N/A";
}
stream << std::setw(20) << std::left << "proportion: " + opt_proportion_str + "%";
stream << " execType: " << it.exec_type << std::endl;

stream << std::endl;
}
}
}
stream << std::setw(20) << std::left << "Total time: " + std::to_string(totalTime.count() / 1000.0)
<< " microseconds" << std::endl;
stream << std::setw(25) << std::left << "Total time: " + std::to_string(totalTime.count() / 1000.0)
<< " milliseconds" << std::endl;
std::cout << std::endl;
std::cout << "Full device name: " << deviceName << std::endl;
std::cout << std::endl;
Expand Down

0 comments on commit 5708285

Please sign in to comment.