| 662 | |
| 663 | #ifdef PPLNN_ENABLE_KERNEL_PROFILING |
| 664 | static void PrintProfilingStatistics(const ProfilingStatistics& stat, double run_dur, int32_t run_count) { |
| 665 | std::map<std::string, std::pair<double, double>> type_stat; |
| 666 | std::map<std::string, int> type_count; |
| 667 | char float_buf_0[128]; |
| 668 | char float_buf_1[128]; |
| 669 | LOG(INFO) << "----- OP statistics by Node -----"; |
| 670 | for (auto x = stat.prof_info.begin(); x != stat.prof_info.end(); ++x) { |
| 671 | auto ext_type = (x->domain == "" ? "" : x->domain + ".") + x->type; |
| 672 | double time = (double)x->exec_microseconds / 1000; |
| 673 | double avg_time = time / x->exec_count; |
| 674 | if (type_stat.find(ext_type) == type_stat.end()) { |
| 675 | type_stat[ext_type] = std::make_pair(avg_time, time); |
| 676 | type_count[ext_type] = 1; |
| 677 | } else { |
| 678 | std::pair<double, double>& time_pair = type_stat[ext_type]; |
| 679 | time_pair.first += avg_time; |
| 680 | time_pair.second += time; |
| 681 | type_count[ext_type]++; |
| 682 | } |
| 683 | sprintf(float_buf_0, "%8.4f", avg_time); |
| 684 | string temp = x->name; |
| 685 | temp.insert(temp.length(), temp.length() > 50 ? 0 : 50 - temp.length(), ' '); |
| 686 | LOG(INFO) << "NAME: [" << temp << "], " |
| 687 | << "AVG_TIME: [" << float_buf_0 << "], " |
| 688 | << "EXEC_COUNT: [" << x->exec_count << "]"; |
| 689 | } |
| 690 | LOG(INFO) << "----- OP statistics by OpType -----"; |
| 691 | double tot_kernel_time = 0; |
| 692 | for (auto it = type_stat.begin(); it != type_stat.end(); ++it) { |
| 693 | tot_kernel_time += it->second.second; |
| 694 | } |
| 695 | for (auto it = type_stat.begin(); it != type_stat.end(); ++it) { |
| 696 | sprintf(float_buf_0, "%8.4f", it->second.first); |
| 697 | sprintf(float_buf_1, "%8.4f", it->second.second / tot_kernel_time * 100); |
| 698 | string temp = it->first; |
| 699 | temp.insert(temp.length(), temp.length() > 20 ? 0 : 20 - temp.length(), ' '); |
| 700 | LOG(INFO) << "TYPE: [" << temp << "], AVG_TIME: [" << float_buf_0 << "], Percentage: [" << float_buf_1 |
| 701 | << "], excute times [" << type_count[it->first] << "]"; |
| 702 | } |
| 703 | |
| 704 | LOG(INFO) << "----- TOTAL statistics -----"; |
| 705 | sprintf(float_buf_0, "%8.4f", tot_kernel_time / run_count); |
| 706 | sprintf(float_buf_1, "%8.4f", run_dur / run_count); |
| 707 | LOG(INFO) << "RUN_COUNT: [" << run_count << "]"; |
| 708 | LOG(INFO) << "AVG_KERNEL_TIME: [" << float_buf_0 << "]"; |
| 709 | LOG(INFO) << "AVG_RUN_TIME: [" << float_buf_1 << "]"; |
| 710 | sprintf(float_buf_0, "%8.4f", tot_kernel_time); |
| 711 | sprintf(float_buf_1, "%8.4f", run_dur); |
| 712 | LOG(INFO) << "TOT_KERNEL_TIME: [" << float_buf_0 << "]"; |
| 713 | LOG(INFO) << "TOT_RUN_TIME: [" << float_buf_1 << "]"; |
| 714 | sprintf(float_buf_0, "%8.4f%%", (run_dur - tot_kernel_time) / run_dur * 100); |
| 715 | LOG(INFO) << "SCHED_LOST: [" << float_buf_0 << "]"; |
| 716 | } |
| 717 | #endif |
| 718 | |
| 719 | static bool SetInputs(const vector<string>& input_data, Runtime* runtime) { |