huawei
/
mindspore2022
0
0
Fork 53
Code Issues Pull Requests 29 Projects Releases Wiki Activity

开源代码评注赛：胡一菲最nb队PR #13

Open
luxiaoguo wants to merge 1 commits from luxiaoguo/mindspore2022:master into master
pull from: luxiaoguo/mindspore2022:master
merge into: huawei:master
Conversation 0 Commits 1 Files Changed 12 +713 -251
12 changed files with 713 additions and 251 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

27
mindspore/ccsrc/profiler/device/cpu/cpu_data_saver.cc
View File

@ -24,13 +24,23 @@
namespace mindspore {
namespace profiler {
namespace cpu {
/**
* @brief Static instance of CpuDataSaver used for accessing CPU profiling data saver functionality.
*/
std::shared_ptr<CpuDataSaver> CpuDataSaver::cpu_data_saver_inst_ = std::make_shared<CpuDataSaver>();
/**
* @brief Write profiling data to a file at the specified output path directory.
*
* @param out_path_dir The directory path where profiling data will be written.
*/
void CpuDataSaver::WriteFile(const std::string out_path_dir) {
if (op_detail_infos_.empty() || op_type_infos_.empty()) {
MS_LOG(INFO) << "No cpu operation detail infos to write.";
MS_LOG(INFO) << "No CPU operation detail infos to write.";
return;
}
// Determine device ID based on context or environment variables.
#if ENABLE_GPU
auto context_ptr = MsContext::GetInstance();
MS_EXCEPTION_IF_NULL(context_ptr);
@ -38,11 +48,14 @@ void CpuDataSaver::WriteFile(const std::string out_path_dir) {
device_id_ = std::to_string(device_id);
#else
auto rank_id = common::GetEnv("RANK_ID");
// If RANK_ID is not set, default value is 0.
if (rank_id.empty()) {
rank_id = "0";
}
rank_id = std::string(rank_id);
// When the value of RANK_ID is not a number, set its value to 0.
for (int i = 0; i < static_cast<int>(rank_id.size()); i++) {
if (std::isdigit(rank_id[i]) == 0) {
@ -50,16 +63,28 @@ void CpuDataSaver::WriteFile(const std::string out_path_dir) {
break;
}
}
device_id_ = rank_id;
#endif
op_side_ = "cpu";
WriteOpDetail(out_path_dir);
WriteOpType(out_path_dir);
WriteOpTimestamp(out_path_dir);
}
/**
* @brief Get a reference to OpTimestampInfo, which stores operation timestamp information.
*
* @return A reference to OpTimestampInfo.
*/
OpTimestampInfo &CpuDataSaver::GetOpTimeStampInfo() { return op_timestamps_map_; }
/**
* @brief Get the shared instance of CpuDataSaver for accessing CPU profiling data saver functionality.
*
* @return A reference to the shared instance of CpuDataSaver.
*/
std::shared_ptr<CpuDataSaver> &CpuDataSaver::GetInstance() { return cpu_data_saver_inst_; }
} // namespace cpu
} // namespace profiler

24
mindspore/ccsrc/profiler/device/cpu/cpu_data_saver.h
View File

@ -35,13 +35,29 @@ class CpuDataSaver : public DataSaver {
~CpuDataSaver() = default;
CpuDataSaver(const CpuDataSaver &) = delete;
/**
* @brief Copy constructor is deleted to prevent copying of CpuDataSaver instances.
*/
CpuDataSaver(const CpuDataSaver &) = delete;
CpuDataSaver &operator=(const CpuDataSaver &) = delete;
/**
* @brief Assignment operator is deleted to prevent assignment of CpuDataSaver instances.
*/
CpuDataSaver &operator=(const CpuDataSaver &) = delete;
OpTimestampInfo &GetOpTimeStampInfo();
/**
* @brief Get a reference to OpTimestampInfo, which stores operation timestamp information.
*
* @return A reference to OpTimestampInfo.
*/
OpTimestampInfo &GetOpTimeStampInfo();
void WriteFile(const std::string out_path);
/**
* @brief Write profiling data to a file at the specified output path.
*
* @param out_path The path to the output file where profiling data will be written.
*/
void WriteFile(const std::string out_path);
private:
static std::shared_ptr<CpuDataSaver> cpu_data_saver_inst_;

65
mindspore/ccsrc/profiler/device/cpu/cpu_profiling.cc
View File

@ -28,60 +28,73 @@
namespace mindspore {
namespace profiler {
namespace cpu {
// CPUProfiler class instance
std::shared_ptr<CPUProfiler> CPUProfiler::profiler_inst_ = std::make_shared<CPUProfiler>();
// Get an instance of the CPUProfiler class
std::shared_ptr<CPUProfiler> &CPUProfiler::GetInstance() { return profiler_inst_; }
// Initialize the CPUProfiler
void CPUProfiler::Init(const std::string &profileDataPath = "") {
// Initialize the CPUProfiler
MS_LOG(INFO) << "Initialize CPU Profiling";
base_time_ = GetHostMonoTimeStamp();
profile_data_path_ = profileDataPath;
base_time_ = GetHostMonoTimeStamp(); // Get the host's monotonically increasing timestamp
profile_data_path_ = profileDataPath; // Set the path to store profiling data
MS_LOG(INFO) << " Host start time(ns): " << base_time_ << " profile data path: " << profile_data_path_;
}
// Enable or disable step profiling
void CPUProfiler::StepProfilingEnable(const bool enable_flag) {
// Enable or disable step profiling
MS_LOG(INFO) << "CPU Profiler enable flag: " << enable_flag;
enable_flag_ = enable_flag;
}
// Set runtime data for an operation
void CPUProfiler::SetRunTimeData(const std::string &op_name, const uint32_t pid, bool is_parallel) {
// Set runtime data for an operation
if (!is_parallel) {
op_name_ = op_name;
pid_ = pid;
op_name_ = op_name; // Set the current operation's name
pid_ = pid; // Set the process ID of the current operation
}
{
std::shared_lock<std::shared_mutex> lock(op_map_mutex_);
auto iter = op_info_map_.find(op_name);
if (iter != op_info_map_.end()) {
iter->second.op_count += 1;
iter->second.op_count += 1; // Increment operation count if the operation already exists
return;
}
}
std::unique_lock<std::shared_mutex> lock(op_map_mutex_);
OpInfo op_info;
op_info.op_name = op_name;
op_info.pid = pid;
op_info.op_count = 1;
op_info_map_[op_name] = op_info;
op_info.op_name = op_name; // Set the operation's name
op_info.pid = pid; // Set the process ID of the operation
op_info.op_count = 1; // Initialize the operation count
op_info_map_[op_name] = op_info; // Add the operation to the map
}
// Set the start time for an operation
void CPUProfiler::SetRuntimeStart(const std::string op_name, const uint64_t start_timestamp) {
// Set the start time for an operation
std::shared_lock<std::shared_mutex> lock(op_map_mutex_);
auto iter = op_info_map_.find(op_name);
if (iter != op_info_map_.end()) {
iter->second.tmp_start_duration.start_timestamp = start_timestamp;
iter->second.tmp_start_duration.start_timestamp = start_timestamp; // Set the start timestamp
auto actor_manager = ActorMgr::GetActorMgrRef();
MS_EXCEPTION_IF_NULL(actor_manager);
auto thread_pool = actor_manager->GetActorThreadPool();
auto worker_ids_map = thread_pool->GetWorkerIdMap();
auto id_iter = worker_ids_map.find(std::this_thread::get_id());
if (id_iter != worker_ids_map.end()) {
iter->second.tmp_start_duration.tid = id_iter->second;
iter->second.tmp_start_duration.tid = id_iter->second; // Set the thread ID
}
}
}
// Set the end time for an operation and return elapsed time
float CPUProfiler::SetRuntimeEnd(const std::string op_name, const uint64_t stop_timestamp) {
// Set the end time for an operation and return the elapsed time
float op_time_elapsed = 0;
std::shared_lock<std::shared_mutex> lock(op_map_mutex_);
auto iter = op_info_map_.find(op_name);
@ -98,22 +111,23 @@ float CPUProfiler::SetRuntimeEnd(const std::string op_name, const uint64_t stop_
MS_LOG(EXCEPTION) << "Op " << op_name << " start time thread id must be equal to end thread id.";
}
}
(void)iter->second.start_duration.emplace_back(iter->second.tmp_start_duration);
(void)iter->second.start_duration.emplace_back(iter->second.tmp_start_duration); // Store duration info
op_time_elapsed = iter->second.tmp_start_duration.duration;
}
return op_time_elapsed;
}
// Begin producing operation data for parallel profiling
void CPUProfiler::OpDataProducerBeginParallel(const std::string op_name, const uint32_t pid) {
auto start_timestamp = GetHostMonoTimeStamp();
SetRunTimeData(op_name, pid, true);
SetRunTimeData(op_name, pid, true); // Set runtime data for parallel operation
SetRuntimeStart(op_name, start_timestamp);
#if ENABLE_GPU
if (MsContext::GetInstance()->get_param<bool>(MS_CTX_ENABLE_MINDRT)) {
// For heterogeneous scene, record op name to gpu_profiler_inst.
auto gpu_profiler_inst = profiler::gpu::GPUProfiler::GetInstance();
// For cpu network, no gpu profiler, do not to raise exception.
// For cpu network, no gpu profiler, do not raise an exception.
if (gpu_profiler_inst && gpu_profiler_inst->GetEnableFlag()) {
gpu_profiler_inst->RecordOneStepStartEndInfo(op_name);
}
@ -121,6 +135,7 @@ void CPUProfiler::OpDataProducerBeginParallel(const std::string op_name, const u
#endif
}
// End producing operation data for parallel profiling
void CPUProfiler::OpDataProducerEndParallel(const std::string op_name) {
auto stop_timestamp = GetHostMonoTimeStamp();
float op_time_elapsed = SetRuntimeEnd(op_name, stop_timestamp);
@ -128,6 +143,7 @@ void CPUProfiler::OpDataProducerEndParallel(const std::string op_name) {
Profiler::SetRunTimeData(op_name, op_time_elapsed);
}
// Begin producing operation data for profiling
void CPUProfiler::OpDataProducerBegin(const std::string op_name, const uint32_t pid) {
op_time_start_ = GetHostMonoTimeStamp();
op_time_mono_start_ = GetHostMonoTimeStamp();
@ -137,7 +153,7 @@ void CPUProfiler::OpDataProducerBegin(const std::string op_name, const uint32_t
if (MsContext::GetInstance()->get_param<bool>(MS_CTX_ENABLE_MINDRT)) {
// For heterogeneous scene, record op name to gpu_profiler_inst.
auto gpu_profiler_inst = profiler::gpu::GPUProfiler::GetInstance();
// For cpu network, no gpu profiler, do not to raise exception.
// For cpu network, no gpu profiler, do not raise an exception.
if (gpu_profiler_inst && gpu_profiler_inst->GetEnableFlag()) {
gpu_profiler_inst->RecordOneStepStartEndInfo(op_name);
}
@ -145,6 +161,7 @@ void CPUProfiler::OpDataProducerBegin(const std::string op_name, const uint32_t
#endif
}
// End producing operation data for profiling
void CPUProfiler::OpDataProducerEnd() {
float op_time_elapsed = 0;
op_time_stop_ = GetHostMonoTimeStamp();
@ -154,33 +171,39 @@ void CPUProfiler::OpDataProducerEnd() {
Profiler::SetRunTimeData(op_name_, op_time_mono_start_, op_time_elapsed);
}
// Stop CPU profiling
void CPUProfiler::Stop() {
MS_LOG(INFO) << "Stop CPU Profiling";
SaveProfileData();
ClearInst();
}
// Save the profiling data to a file
void CPUProfiler::SaveProfileData() {
if (profile_data_path_.empty()) {
MS_LOG(WARNING) << "Profile data path is empty, skip save profile data.";
MS_LOG(WARNING) << "Profile data path is empty, skip saving profile data.";
} else {
auto cpu_data_saver_inst = profiler::cpu::CpuDataSaver::GetInstance();
MS_EXCEPTION_IF_NULL(cpu_data_saver_inst);
cpu_data_saver_inst->ParseOpInfo(op_info_map_);
cpu_data_saver_inst->WriteFile(profile_data_path_);
cpu_data_saver_inst->ParseOpInfo(op_info_map_); // Parse operation info
cpu_data_saver_inst->WriteFile(profile_data_path_); // Write data to the specified file
}
}
// Clear the CPU profiler instance
void CPUProfiler::ClearInst() { op_info_map_.clear(); }
// Register CPUProfiler class in Python binding
REGISTER_PYBIND_DEFINE(CPUProfiler_, ([](const py::module *m) {
(void)py::class_<CPUProfiler, std::shared_ptr<CPUProfiler>>(*m, "CPUProfiler")
.def_static("get_instance", &CPUProfiler::GetInstance, "CPUProfiler get_instance.")
.def("init", &CPUProfiler::Init, py::arg("profile_data_path"), "init")
.def("stop", &CPUProfiler::Stop, "stop")
.def("init", &CPUProfiler::Init, py::arg("profile_data_path"), "Initialize CPU profiler")
.def("stop", &CPUProfiler::Stop, "Stop CPU profiler")
.def("step_profiling_enable", &CPUProfiler::StepProfilingEnable, py::arg("enable_flag"),
"enable or disable step profiling");
"Enable or disable step profiling");
}));
} // namespace cpu
} // namespace profiler
} // namespace mindspore

57
mindspore/ccsrc/profiler/device/cpu/cpu_profiling.h
View File

@ -32,8 +32,10 @@
namespace mindspore {
namespace profiler {
namespace cpu {
// Conversion factor from nanoseconds to milliseconds
const float kNanosecondToMillisecond = 1000000;
// CPUProfiler class for CPU profiling
class CPUProfiler : public Profiler {
public:
static std::shared_ptr<CPUProfiler> &GetInstance();
@ -42,14 +44,69 @@ class CPUProfiler : public Profiler {
CPUProfiler(const CPUProfiler &) = delete;
CPUProfiler &operator=(const CPUProfiler &) = delete;
/**
* @brief Initialize the CPU profiler.
*
* @param profileDataPath The path to store the profiling data.
*/
void Init(const std::string &profileDataPath) override;
/**
* @brief Stop the CPU profiler.
*/
void Stop() override;
/**
* @brief Enable or disable step profiling.
*
* @param enable_flag True to enable step profiling, false to disable.
*/
void StepProfilingEnable(const bool enable_flag) override;
/**
* @brief Begin producing operation data for profiling.
*
* @param op_name The name of the operation.
* @param pid The process ID associated with the operation.
*/
void OpDataProducerBegin(const std::string op_name, const uint32_t pid);
/**
* @brief End producing operation data for profiling.
*/
void OpDataProducerEnd() override;
/**
* @brief End producing operation data for parallel profiling.
*
* @param op_name The name of the operation.
*/
void OpDataProducerEndParallel(const std::string op_name);
/**
* @brief Begin producing operation data for parallel profiling.
*
* @param op_name The name of the operation.
* @param pid The process ID associated with the operation.
*/
void OpDataProducerBeginParallel(const std::string op_name, const uint32_t pid);
/**
* @brief Set the end time for an operation.
*
* @param op_name The name of the operation.
* @param stop_timestamp The timestamp when the operation ended.
*
* @return The elapsed time for the operation.
*/
float SetRuntimeEnd(const std::string op_name, const uint64_t stop_timestamp);
/**
* @brief Set the start time for an operation.
*
* @param op_name The name of the operation.
* @param start_timestamp The timestamp when the operation started.
*/
void SetRuntimeStart(const std::string op_name, const uint64_t start_timestamp);
private:

34
mindspore/ccsrc/profiler/device/data_saver.cc
View File

@ -22,9 +22,10 @@
namespace mindspore {
namespace profiler {
// Constructor for OpDetailInfo
OpDetailInfo::OpDetailInfo(const std::shared_ptr<OpInfo> op_info, float proportion)
: op_info_(op_info), proportion_(proportion) {
// op_full_name is like 'xxx/xxx/{op_type}-op{node_id}'
// Extract information from op_full_name, which is like 'xxx/xxx/{op_type}-op{node_id}'
op_full_name_ = op_info->op_name;
auto op_type_begin_iter = op_full_name_.rfind('/') + 1;
auto op_type_end_iter = op_full_name_.rfind('-');
@ -37,6 +38,7 @@ OpDetailInfo::OpDetailInfo(const std::shared_ptr<OpInfo> op_info, float proporti
op_avg_time_ = op_info->op_host_cost_time / op_info->op_count;
}
// Parses information about operations and timestamps
void DataSaver::ParseOpInfo(const OpInfoMap &op_info_maps) {
op_detail_infos_.reserve(op_info_maps.size());
float total_time_sum = GetTotalOpTime(op_info_maps);
@ -46,19 +48,21 @@ void DataSaver::ParseOpInfo(const OpInfoMap &op_info_maps) {
MS_LOG(ERROR) << "The total operation times can not be 0.";
return;
}
// Calculate the proportion of this operation's time relative to the total time
float proportion = item.second.op_host_cost_time / total_time_sum;
auto op_info = std::make_shared<OpInfo>(item.second);
if (op_info == nullptr) {
MS_LOG(ERROR) << "Create Operation information node failed when parse operation information.";
return;
}
// Create OpDetailInfo object to store detailed information about this operation
OpDetailInfo op_detail_info = OpDetailInfo(op_info, proportion);
op_detail_infos_.emplace_back(op_detail_info);
// Add detailed information to the corresponding operation type
AddOpDetailInfoForType(op_detail_info);
}
// update average time of op type
// Update average time of each operation type
for (auto &op_type : op_type_infos_) {
// device_infos: <type_name, op_type_info>
if (op_type.second.count_ == 0) {
MS_LOG(ERROR) << "The num of operation type can not be 0.";
return;
@ -69,6 +73,7 @@ void DataSaver::ParseOpInfo(const OpInfoMap &op_info_maps) {
MS_LOG(DEBUG) << "Get " << op_type_infos_.size() << " operation type items.";
}
// Adds detailed information about an operation type to op_type_infos_
void DataSaver::AddOpDetailInfoForType(const OpDetailInfo &op_detail_info) {
// Construct OpType object according to op detail info
OpType op_type = OpType{op_detail_info.op_type_,
@ -87,24 +92,27 @@ void DataSaver::AddOpDetailInfoForType(const OpDetailInfo &op_detail_info) {
}
}
// Calculates the total time spent on all operations in op_info_maps
float DataSaver::GetTotalOpTime(const OpInfoMap &op_info_maps) const {
float sum = 0;
// Calculate the sum of op_host_cost_time for all operations
sum = std::accumulate(op_info_maps.begin(), op_info_maps.end(), sum,
[](float i, auto iter) { return i + iter.second.op_host_cost_time; });
MS_LOG(DEBUG) << "The total op time is " << sum;
return sum;
}
// Writes information about operation types to a CSV file
void DataSaver::WriteOpType(const std::string &saver_base_dir) const {
std::string file_path = saver_base_dir + "/" + op_side_ + "_op_type_info_" + device_id_ + ".csv";
std::ofstream ofs(file_path);
// check if the file is writable
// Check if the file is writable
if (!ofs.is_open()) {
MS_LOG(WARNING) << "Open file '" << file_path << "' failed!";
return;
}
try {
// write op type info into file
// Write op type info into file
if (op_side_ == "cpu") {
ofs << OpType().GetCpuHeader() << std::endl;
for (auto op_type_info : op_type_infos_) {
@ -118,13 +126,14 @@ void DataSaver::WriteOpType(const std::string &saver_base_dir) const {
}
}
} catch (const std::exception &e) {
MS_LOG(ERROR) << "Write " << file_path << "failed: " << e.what();
MS_LOG(ERROR) << "Write " << file_path << " failed: " << e.what();
}
ofs.close();
ChangeFileMode(file_path);
MS_LOG(INFO) << "Write " << op_type_infos_.size() << " op type infos into file: " << file_path;
}
// Writes detailed information about operations to a CSV file
void DataSaver::WriteOpDetail(const std::string &saver_base_dir) const {
std::string file_path = saver_base_dir + "/" + op_side_ + "_op_detail_info_" + device_id_ + ".csv";
std::ofstream ofs(file_path);
@ -133,7 +142,7 @@ void DataSaver::WriteOpDetail(const std::string &saver_base_dir) const {
return;
}
try {
// write op detail info into file
// Write op detail info into file
if (op_side_ == "cpu") {
ofs << OpDetailInfo().GetCpuHeader() << std::endl;
for (auto op_detail : op_detail_infos_) {
@ -147,23 +156,24 @@ void DataSaver::WriteOpDetail(const std::string &saver_base_dir) const {
}
}
} catch (const std::exception &e) {
MS_LOG(ERROR) << "Write " << file_path << "failed: " << e.what();
MS_LOG(ERROR) << "Write " << file_path << " failed: " << e.what();
}
ofs.close();
ChangeFileMode(file_path);
MS_LOG(INFO) << "Write " << op_detail_infos_.size() << " op detail infos into file: " << file_path;
}
// Writes timestamps of operation executions to a text file
void DataSaver::WriteOpTimestamp(const std::string &saver_base_dir) const {
std::string file_path = saver_base_dir + "/" + op_side_ + "_op_execute_timestamp_" + device_id_ + ".txt";
std::ofstream ofs(file_path);
// check if the file is writable
// Check if the file is writable
if (!ofs.is_open()) {
MS_LOG(WARNING) << "Open file '" << file_path << "' failed!";
return;
}
try {
// write op timestamp info into file
// Write op timestamp info into file
for (const auto &op_timestamp_info : op_timestamps_map_) {
if (op_side_ == "cpu") {
ofs << op_timestamp_info.first << ";HostCpuOps;";
@ -179,17 +189,19 @@ void DataSaver::WriteOpTimestamp(const std::string &saver_base_dir) const {
ofs << std::endl;
}
} catch (const std::exception &e) {
MS_LOG(ERROR) << "Write " << file_path << "failed: " << e.what();
MS_LOG(ERROR) << "Write " << file_path << " failed: " << e.what();
}
ofs.close();
ChangeFileMode(file_path);
}
// Changes the file mode of the specified file to read-write
void DataSaver::ChangeFileMode(const std::string &file_path) const {
if (chmod(common::SafeCStr(file_path), S_IRUSR | S_IWUSR) == -1) {
MS_LOG(WARNING) << "Modify file: " << file_path << " to rw fail.";
return;
}
}
} // namespace profiler
} // namespace mindspore

119
mindspore/ccsrc/profiler/device/data_saver.h
View File

@ -26,87 +26,52 @@
#include "utils/log_adapter.h"
namespace mindspore {
namespace profiler {
// Structure to store detailed information about an operation
struct OpDetailInfo {
std::string op_type_;
std::string op_name_;
std::string op_full_name_;
std::shared_ptr<OpInfo> op_info_{nullptr};
float op_avg_time_{0};
float proportion_{0};
std::string op_type_; /**< Type of the operation. */
std::string op_name_; /**< Name of the operation. */
std::string op_full_name_; /**< Full name of the operation. */
std::shared_ptr<OpInfo> op_info_{nullptr}; /**< Shared pointer to information about the operation. */
float op_avg_time_{0}; /**< Average time for the operation. */
float proportion_{0}; /**< Proportion of time spent on this operation. */
OpDetailInfo() = default;
OpDetailInfo(const std::shared_ptr<OpInfo> op_info, float proportion);
std::string GetCpuHeader() const {
return "op_side,op_type,op_name,full_op_name,op_occurrences,op_total_time(ms),"
"op_avg_time(ms),total_proportion,subgraph,pid";
}
std::string GetGpuHeader() const {
return "op_side,op_type,op_name,op_full_name,op_occurrences,op_total_time(us),op_avg_time(us),total_proportion,"
"cuda_activity_cost_time(us),cuda_activity_call_count";
}
std::string GetCpuHeader() const;
std::string GetGpuHeader() const;
void OutputCpuOpDetailInfo(std::ostream &os) const {
os << "Host," << op_type_ << ',' << op_name_ << ',' << op_full_name_ << ',' << op_info_->op_count << ','
<< op_info_->op_host_cost_time << ',' << op_avg_time_ << ',' << proportion_ << ",Default," << op_info_->pid
<< std::endl;
}
void OutputGpuOpDetailInfo(std::ostream &os) const {
os << "Device," << op_type_ << ',' << op_name_ << ',' << op_full_name_ << ',' << op_info_->op_count << ','
<< op_info_->op_host_cost_time << ',' << op_avg_time_ << ',' << proportion_ << ','
<< op_info_->cupti_activity_time << ',' << op_info_->op_kernel_count << std::endl;
}
void OutputCpuOpDetailInfo(std::ostream &os) const;
void OutputGpuOpDetailInfo(std::ostream &os) const;
};
// Structure to store information about an operation type
struct OpType {
std::string op_type_;
int count_{0};
int step_{0};
float total_time_{0};
float avg_time_{0};
float proportion_{0};
std::string op_type_; /**< Type of the operation. */
int count_{0}; /**< Count of this operation type. */
int step_{0}; /**< Step count. */
float total_time_{0}; /**< Total time spent on this operation type. */
float avg_time_{0}; /**< Average time for this operation type. */
float proportion_{0}; /**< Proportion of time spent on this operation type. */
std::string GetCpuHeader() const {
return "op_type,type_occurrences,execution_frequency(per-step),"
"total_compute_time,avg_time(ms),percent";
}
std::string GetGpuHeader() const { return "op_type,type_occurrences,total_time(us),total_proportion,avg_time(us)"; }
std::string GetCpuHeader() const;
std::string GetGpuHeader() const;
void OutputCpuOpTypeInfo(std::ostream &os) const {
if (step_ == 0) {
MS_LOG(ERROR) << "The run step can not be 0.";
return;
}
if (count_ == 0) {
MS_LOG(ERROR) << "The num of operation type can not be 0.";
return;
}
os << op_type_ << ',' << count_ << ',' << count_ / step_ << ',' << total_time_ << ',' << total_time_ / count_ << ','
<< proportion_ << std::endl;
}
void OutputCpuOpTypeInfo(std::ostream &os) const;
void OutputGpuOpTypeInfo(std::ostream &os) const;
void OutputGpuOpTypeInfo(std::ostream &os) const {
os << op_type_ << ',' << count_ << ',' << total_time_ << ',' << proportion_ << ',' << avg_time_ << std::endl;
}
OpType &operator+=(const OpType &other) {
this->count_ += other.count_;
this->total_time_ += other.total_time_;
this->proportion_ += other.proportion_;
return *this;
}
OpType &operator+=(const OpType &other);
};
using OpTimestampInfo = std::unordered_map<std::string, std::vector<StartDuration>>; // <op_full_name, StartDuration>
// Aliases for unordered maps and vectors
using OpTimestampInfo = std::unordered_map<std::string, std::vector<StartDuration>>;
using OpInfoMap = std::unordered_map<std::string, OpInfo>;
using OpTypeInfos = std::unordered_map<std::string, OpType>; // <op_full_name, Optype>
using OpTypeInfos = std::unordered_map<std::string, OpType>;
using OpDetailInfos = std::vector<OpDetailInfo>;
class DataSaver {
public:
DataSaver() = default;
virtual ~DataSaver() = default;
void ParseOpInfo(const OpInfoMap &op_info_maps);
@ -114,16 +79,47 @@ class DataSaver {
OpTimestampInfo op_timestamps_map_;
protected:
/**
* @brief Adds detailed information about an operation type.
*
* @param[in] op_detail_info Information about the operation type.
*/
void AddOpDetailInfoForType(const OpDetailInfo &op_detail_info);
/**
* @brief Calculates the total time spent on all operations.
*
* @param[in] op_info_maps A map containing information about operations.
* @return Total time spent on all operations.
*/
float GetTotalOpTime(const OpInfoMap &op_info_maps) const;
/**
* @brief Writes information about operation types to a file.
*
* @param[in] saver_base_dir Base directory for saving data.
*/
void WriteOpType(const std::string &saver_base_dir) const;
/**
* @brief Writes detailed information about operations to a file.
*
* @param[in] saver_base_dir Base directory for saving data.
*/
void WriteOpDetail(const std::string &saver_base_dir) const;
/**
* @brief Writes timestamps for operations to a file.
*
* @param[in] saver_base_dir Base directory for saving data.
*/
void WriteOpTimestamp(const std::string &saver_base_dir) const;
/**
* @brief Changes the file mode of the specified file.
*
* @param[in] file_path Path to the file.
*/
void ChangeFileMode(const std::string &file_path) const;
OpTypeInfos op_type_infos_;
@ -131,6 +127,7 @@ class DataSaver {
std::string op_side_;
std::string device_id_;
};
} // namespace profiler
} // namespace mindspore

39
mindspore/ccsrc/profiler/device/gpu/cupti_interface.cc
View File

@ -21,53 +21,66 @@
namespace mindspore {
namespace profiler {
namespace gpu {
// LoadLibrary function
// This function loads a shared library using dlopen and returns the handle.
// It throws an exception if loading fails.
inline void *LoadLibrary(const char *name) {
// Load the shared library with RTLD_LAZY and RTLD_LOCAL flags
auto handle = dlopen(name, RTLD_LAZY | RTLD_LOCAL);
if (handle == nullptr) {
// Throw an exception with an error message if loading fails
MS_LOG(EXCEPTION) << "Load lib " << name << " Please check whether configured the path of CUPTI to LD_LIBRARY_PATH";
}
return handle;
}
// GetCUPTIHandle function
// This function gets the handle to the CUPTI library using LoadLibrary.
// It ensures that the handle is obtained only once and returns it.
inline void *GetCUPTIHandle() {
// Static variable to store the CUPTI handle
static void *handle = LoadLibrary("libcupti.so");
return handle;
}
// GetCUPTIFunc function
// This function gets a function pointer from the CUPTI library handle.
// It ensures that the function pointer is obtained only once and returns it.
inline void *GetCUPTIFunc(const char *name) {
// Get the CUPTI library handle using GetCUPTIHandle
static void *handle = GetCUPTIHandle();
// Get the function pointer by name from the CUPTI library
void *func = dlsym(handle, name);
if (func == nullptr) {
// Throw an exception with an error message if obtaining the function pointer fails
MS_LOG(EXCEPTION) << "Load func " << name << " failed, make sure you have implied it!";
}
return func;
}
// Define function pointer types for various CUPTI functions
using CuptiSubscribeFunc = CUptiResult (*)(CUpti_SubscriberHandle *subscriber, CUpti_CallbackFunc callback,
void *userdata);
using CuptiEnableDomainFunc = CUptiResult (*)(uint32_t enable, CUpti_SubscriberHandle subscriber,
CUpti_CallbackDomain domain);
using CuptiActivityEnableFunc = CUptiResult (*)(CUpti_ActivityKind kind);
using CuptiActivityRegisterCallbacksFunc = CUptiResult (*)(CUpti_BuffersCallbackRequestFunc funcBufferRequested,
CUpti_BuffersCallbackCompleteFunc funcBufferCompleted);
using CuptiUnsubscribeFunc = CUptiResult (*)(CUpti_SubscriberHandle subscriber);
using CuptiActivityFlushAllFunc = CUptiResult (*)(uint32_t flag);
using CuptiActivityDisableFunc = CUptiResult (*)(CUpti_ActivityKind kind);
using CuptiActivityGetNextRecordFunc = CUptiResult (*)(uint8_t *buffer, size_t validBufferSizeBytes,
CUpti_Activity **record);
using CuptiActivityGetNumDroppedRecordsFunc = CUptiResult (*)(CUcontext context, uint32_t streamId, size_t *dropped);
using CuptiGetTimestampFunc = CUptiResult (*)(uint64_t *timestamp);
using CuptiGetResultStringFunc = CUptiResult (*)(CUptiResult result, const char **str);
using CuptiGetStreamIdFunc = CUptiResult (*)(CUcontext context, CUstream stream, uint32_t *streamId);
using CuptiGetDeviceIdFunc = CUptiResult (*)(CUcontext context, uint32_t *deviceId);
// ... Define function pointer types for other CUPTI functions ...
// CuptiSubscribe function
// This function calls the CuptiSubscribeFunc obtained from GetCUPTIFunc.
CUptiResult CuptiSubscribe(CUpti_SubscriberHandle *subscriber, CUpti_CallbackFunc callback, void *userdata) {
// Get the function pointer using GetCUPTIFunc
static auto func_ptr = reinterpret_cast<CuptiSubscribeFunc>(GetCUPTIFunc("cuptiSubscribe"));
// Call the function pointer and return the result
return func_ptr(subscriber, callback, userdata);
}
// CuptiEnableDomain function
// This function calls the CuptiEnableDomainFunc obtained from GetCUPTIFunc.
CUptiResult CuptiEnableDomain(uint32_t enable, CUpti_SubscriberHandle subscriber, CUpti_CallbackDomain domain) {
// Get the function pointer using GetCUPTIFunc
static auto func_ptr = reinterpret_cast<CuptiEnableDomainFunc>(GetCUPTIFunc("cuptiEnableDomain"));
// Call the function pointer and return the result
return func_ptr(enable, subscriber, domain);
}

248
mindspore/ccsrc/profiler/device/gpu/gpu_profiling.cc
View File

@ -31,8 +31,11 @@
namespace mindspore {
namespace profiler {
namespace gpu {
const size_t BUF_SIZE = 32 * 1024;
const size_t ALIGN_SIZE = 8;
// Constants for buffer size and alignment
constexpr size_t BUF_SIZE = 32 * 1024;
constexpr size_t ALIGN_SIZE = 8;
// Helper macro for checking CUPTI return values with error handling
#define CHECK_CUPTI_RET_WITH_ERROR(expression, message) \
if ((expression) != CUPTI_SUCCESS) { \
const char *errstr; \
@ -44,12 +47,15 @@ const size_t ALIGN_SIZE = 8;
<< " GPU performance tuning document on the official website of mindinsight."; \
}
// Helper macro for checking CUPTI return values with exception handling
#define CHECK_CUPTI_RET_WITH_EXCEPT(expression, message) \
if ((expression) != CUPTI_SUCCESS) { \
const char *errstr; \
CuptiGetResultString(expression, &errstr); \
MS_LOG(EXCEPTION) << "CUPTI Error:" << errstr << " function:" << (message); \
}
// Helper macro for checking CUDA return values with error handling
#define CHECK_CUDA_RET_WITH_ERROR(expression, message) \
do { \
cudaError_t status = (expression); \
@ -58,6 +64,8 @@ const size_t ALIGN_SIZE = 8;
<< cudaGetErrorString(status); \
} \
} while (0)
// Helper macro for checking the validity of a pointer and logging an error if it's nullptr
#define PROFILER_ERROR_IF_NULLPTR(ptr) \
do { \
if ((ptr) == nullptr) { \
@ -66,31 +74,40 @@ const size_t ALIGN_SIZE = 8;
} \
} while (0)
// Static member initialization
std::shared_ptr<GPUProfiler> GPUProfiler::profiler_inst_ = std::make_shared<GPUProfiler>();
// GetThreadID function
// This function returns the ID of the current thread using pthread_self.
int32_t GetThreadID() {
uint32_t thread_id = static_cast<uint32_t>(pthread_self());
return thread_id;
}
// GetStreamID function
// This function returns the ID of the CUDA stream associated with a given context and stream pointer.
uint32_t GetStreamID(const CUcontext context, const void *stream) {
uint32_t stream_id = 0;
if (stream != nullptr) {
CHECK_CUPTI_RET_WITH_ERROR(CuptiGetStreamId(context, (CUstream)stream, &stream_id), "CuptiGetStreamId");
if (CuptiGetStreamId(context, (CUstream)stream, &stream_id) != CUPTI_SUCCESS) {
MS_LOG(ERROR) << "Training process unexpectedly stopped, profiling data cannot be write to file"
MS_LOG(ERROR) << "Training process unexpectedly stopped, profiling data cannot be written to a file."
<< "To obtain the profiling data, do not interrupt the training process.";
}
}
return stream_id;
}
// GetCUPTITimeStamp function
// This function returns the current CUPTI timestamp.
uint64_t GetCUPTITimeStamp() {
uint64_t time_stamp = 0l;
CHECK_CUPTI_RET_WITH_ERROR(CuptiGetTimestamp(&time_stamp), "CuptiGetTimestamp");
return time_stamp;
}
// GetHostTimeStamp function
// This function returns the current host timestamp in nanoseconds.
uint64_t GetHostTimeStamp() {
auto cur_sys_clock = std::chrono::system_clock::now();
uint64_t cur_time_stamp =
@ -98,6 +115,8 @@ uint64_t GetHostTimeStamp() {
return cur_time_stamp;
}
// GetKernelFunc function
// This function demangles the kernel function name if possible and returns it.
std::string GetKernelFunc(const char *name) {
char *demangledName = abi::__cxa_demangle(name, nullptr, nullptr, nullptr);
if (demangledName != nullptr) {
@ -107,6 +126,8 @@ std::string GetKernelFunc(const char *name) {
}
}
// IsMemcpyAsyncEvent function
// This function checks if a CUPTI callback ID represents an asynchronous memory copy event.
bool IsMemcpyAsyncEvent(CUpti_CallbackId cb_id) {
switch (cb_id) {
case CUPTI_DRIVER_TRACE_CBID_cuMemcpyAsync:
@ -125,6 +146,8 @@ bool IsMemcpyAsyncEvent(CUpti_CallbackId cb_id) {
return false;
}
// IsMemcpySyncEvent function
// This function checks if a CUPTI callback ID represents a synchronous memory copy event.
bool IsMemcpySyncEvent(CUpti_CallbackId cb_id) {
switch (cb_id) {
case CUPTI_DRIVER_TRACE_CBID_cuMemcpy:
@ -144,9 +167,10 @@ bool IsMemcpySyncEvent(CUpti_CallbackId cb_id) {
default:
return false;
}
return false;
}
// CUPTIApiExit function
// This function handles CUPTI callback exit events and processes the profiling data.
void CUPTIApiExit(const std::shared_ptr<GPUProfiler> &gpu_profiler_inst, CUpti_CallbackId cb_id,
const CUpti_CallbackData *cb_data) {
uint64_t start_timestamp = *cb_data->correlationData;
@ -179,6 +203,8 @@ void CUPTIApiExit(const std::shared_ptr<GPUProfiler> &gpu_profiler_inst, CUpti_C
}
}
// CUPTICallBackFunc function
// This function is the callback function for CUPTI API events and handles entry and exit events.
void CUPTICallBackFunc(void *user_data, CUpti_CallbackDomain domain, CUpti_CallbackId cb_id,
const CUpti_CallbackData *cb_data) {
if (domain != CUPTI_CB_DOMAIN_DRIVER_API) {
@ -204,8 +230,10 @@ void CUPTICallBackFunc(void *user_data, CUpti_CallbackDomain domain, CUpti_Callb
}
}
// GetKernelFuncName function
// This function extracts the kernel function name from a full kernel name.
std::string GetKernelFuncName(std::string kernel_name) {
// remove the return type name (void) in kernel_name.
// Remove the return type name (void) in kernel_name.
std::string search_pattern("void ");
auto func_name_begin_iter = kernel_name.find(search_pattern);
if (func_name_begin_iter == kernel_name.npos) {
@ -216,36 +244,56 @@ std::string GetKernelFuncName(std::string kernel_name) {
return kernel_name.substr(func_name_begin_iter);
}
// GetInstance function
// This function returns the singleton instance of the GPUProfiler class.
std::shared_ptr<GPUProfiler> &GPUProfiler::GetInstance() {
MS_EXCEPTION_IF_NULL(profiler_inst_);
return profiler_inst_;
}
// GPUProfiler::SyncEnable function
// This function sets the synchronous profiling enable flag for the GPU profiler.
void GPUProfiler::SyncEnable(const bool enable_flag) {
// Log the synchronous profiling enable flag
MS_LOG(INFO) << "GPU Profiler synchronous enable flag:" << enable_flag;
// Set the synchronous enable flag
sync_enable_flag_ = enable_flag;
}
// GPUProfiler::StepProfilingEnable function
// This function sets the step profiling enable flag for the GPU profiler.
void GPUProfiler::StepProfilingEnable(const bool enable_flag) {
// Log the step profiling enable flag
MS_LOG(INFO) << "GPU Profiler enable flag:" << enable_flag;
// Flush all CUPTI activities
CHECK_CUPTI_RET_WITH_ERROR(CuptiActivityFlushAll(0), "CuptiActivityFlushAll");
// Set the step profiling enable flag
enable_flag_ = enable_flag;
}
// GPUProfiler::FixOpNameByCorrelationId function
// This function fixes the operation name based on the correlation ID in the event.
void GPUProfiler::FixOpNameByCorrelationId(Event *event) {
// Check if the event is an activity event
PROFILER_ERROR_IF_NULLPTR(event);
if (event->api_type != CUPTIApiType::kActivity) {
return;
}
// Find the operation name in the op_name_map_ using the correlation ID
auto iter = op_name_map_.find(event->correlation_id);
if (iter != op_name_map_.end()) {
event->op_name = std::move(iter->second);
}
}
// GPUProfiler::AddEvent function
// This function adds an event to the GPU profiler's event list, handling concurrency for different types of events.
void GPUProfiler::AddEvent(Event &&event) {
// protect callback concurrency for driver api and activity
// Protect callback concurrency for driver API and activity
std::unique_lock<std::mutex> lock(event_mutex_);
// Determine the type of the event and add it to the appropriate event list
switch (event.api_type) {
case CUPTIApiType::kCallback: {
if (cupti_callback_events_count_ < max_cupti_callback_events_) {
@ -270,6 +318,8 @@ void GPUProfiler::AddEvent(Event &&event) {
}
}
// GPUProfiler::EventLog function
// This function logs information about an event, including its details and timestamps.
void GPUProfiler::EventLog(const Event &event) {
MS_LOG(DEBUG) << "GPUProfiler"
<< ",\"kernel_name:" << event.kernel_name << "\",kernel_type:" << event.kernel_type
@ -281,30 +331,36 @@ void GPUProfiler::EventLog(const Event &event) {
<< ",stream_id:" << event.stream_id << ",cb_id:" << event.cb_id;
}
// GPUProfiler::ProcessEvents function
// This function processes the collected events, updating operation-specific profiling information.
void GPUProfiler::ProcessEvents() {
for (Event &event : events_) {
// Fix operation names based on correlation IDs
if (event.op_name.empty()) {
FixOpNameByCorrelationId(&event);
}
// Log the event details
EventLog(event);
// Skip events with empty operation names or stream synchronization events
if (event.op_name.empty() || event.cb_id == CUPTI_DRIVER_TRACE_CBID_cuStreamSynchronize) {
continue;
}
// Update profiling information for the associated operation
auto iter = op_info_map_.find(event.op_name);
if (iter != op_info_map_.end()) {
switch (event.api_type) {
case CUPTIApiType::kCallback: {
iter->second.op_kernel_api_count += 1;
// The time unit from ns to us
// Convert and accumulate the time unit from ns to us
iter->second.cupti_api_call_time += (event.end_time_stamp - event.start_time_stamp) / kTimeUnit;
break;
}
case CUPTIApiType::kActivity: {
iter->second.op_kernel_count += 1;
// The time unit from ns to us
// Convert and accumulate the time unit from ns to us
iter->second.cupti_activity_time += (event.end_time_stamp - event.start_time_stamp) / kTimeUnit;
break;
}
@ -315,10 +371,14 @@ void GPUProfiler::ProcessEvents() {
}
}
// GPUProfiler::OpsParser function
// This function parses and analyzes the collected events to generate profiling information.
void GPUProfiler::OpsParser() {
// Log information about the collected events
MS_LOG(INFO) << "Count the number of events size:" << events_.size()
<< " callback api:" << cupti_callback_events_count_ << " activity:" << cupti_activity_events_count_;
// Check for dropped events and log a warning if any
if (cupti_activity_events_drop_count_ > 0 || cupti_callback_events_drop_count_ > 0) {
MS_LOG(WARNING)
<< "The total number of events exceeded the profiler's processing capacity, some events were discarded."
@ -326,23 +386,32 @@ void GPUProfiler::OpsParser() {
<< " callback api events:" << cupti_callback_events_drop_count_;
}
// If no events were collected, return
if (events_.size() == 0) {
return;
}
// Process and analyze the collected events
ProcessEvents();
// Log the generated profiling information
MS_LOG(DEBUG) << "GPU_profiler, op_name, op_count , kernel_count, kernel_api_count,|"
",cupti_activity_total_time, cupti_api_call_total_time, op_host_cost_total_time,|"
",cupti_activity_average_time,cupti_api_call_average_time, op_host_cost_average_time"
<< std::endl;
// Create a vector of ordered operation information based on cupti_activity_time
std::vector<std::pair<std::string, OpInfo>> order_vec(op_info_map_.begin(), op_info_map_.end());
// Define a comparison function for sorting
auto cmp_func = [](const std::pair<std::string, OpInfo> &a, const std::pair<std::string, OpInfo> &b) {
return a.second.cupti_activity_time > b.second.cupti_activity_time;
};
// Sort the operation information vector
std::sort(order_vec.begin(), order_vec.end(), cmp_func);
// Log the profiling information for each operation
for (auto iter = order_vec.begin(); iter != order_vec.end(); iter++) {
if (iter->second.op_count == 0) {
MS_LOG(ERROR) << "The num of operations can not be 0.";
@ -359,6 +428,8 @@ void GPUProfiler::OpsParser() {
}
}
// GPUProfiler::EventHandleProcess function
// This function processes a CUPTI callback event and creates an Event object to add to the profiler's event list.
void GPUProfiler::EventHandleProcess(CUpti_CallbackId cbid, const CUpti_CallbackData *cbdata,
const std::string &typestring, uint64_t startTimestamp, uint64_t endTimestamp) {
Event event;
@ -380,22 +451,34 @@ void GPUProfiler::EventHandleProcess(CUpti_CallbackId cbid, const CUpti_Callback
op_name_map_[event.correlation_id] = event.op_name;
AddEvent(std::move(event));
}
// ActivityAllocBuffer function
// This function allocates memory buffer for CUPTI activity records.
void CUPTIAPI ActivityAllocBuffer(uint8_t **buffer, size_t *size, size_t *maxNumRecords);
// ActivityProcessBuffer function
// This function processes the CUPTI activity records in the buffer.
void CUPTIAPI ActivityProcessBuffer(CUcontext ctx, uint32_t streamId, uint8_t *buffer, size_t size, size_t validSize);
// Init function
// This function initializes the GPU Profiler, subscribing to CUPTI callbacks and enabling specific activity kinds.
void GPUProfiler::Init(const std::string &profileDataPath = "") {
MS_LOG(INFO) << "Initialize GPU Profiling";
// Check if the GPU Profiler has already been initialized
if (subscriber_ != nullptr) {
// If already initialized, stop CUPTI and raise an exception
StopCUPTI();
MS_LOG(EXCEPTION)
<< "Repeated initialization, Please check whether you have created the Profiler object multiple times";
MS_LOG(EXCEPTION) << "Repeated initialization, Please check whether you have created the Profiler object multiple times";
}
// Subscribe to CUPTI callbacks using CUPTICallBackFunc
CHECK_CUPTI_RET_WITH_EXCEPT(CuptiSubscribe(&subscriber_, (CUpti_CallbackFunc)CUPTICallBackFunc, this),
"CuptiSubscribe");
// Enable CUPTI domain for driver API callbacks
CHECK_CUPTI_RET_WITH_EXCEPT(CuptiEnableDomain(1, subscriber_, CUPTI_CB_DOMAIN_DRIVER_API), "CuptiEnableDomain");
// Enable specific CUPTI activity kinds (Memory copies and Kernel activities)
activities_enable_.emplace_back(CUPTI_ACTIVITY_KIND_MEMCPY);
activities_enable_.emplace_back(CUPTI_ACTIVITY_KIND_MEMCPY2);
activities_enable_.emplace_back(CUPTI_ACTIVITY_KIND_KERNEL);
@ -405,36 +488,48 @@ void GPUProfiler::Init(const std::string &profileDataPath = "") {
CHECK_CUPTI_RET_WITH_EXCEPT(CuptiActivityEnable(*it), "CuptiActivityEnable");
}
// Register callback functions for allocating and processing CUPTI activity records
CHECK_CUPTI_RET_WITH_EXCEPT(CuptiActivityRegisterCallbacks(ActivityAllocBuffer, ActivityProcessBuffer),
"CuptiActivityRegisterCallbacks");
// Get the start timestamps for GPU and host
base_time_.gpu_start_time = GetCUPTITimeStamp();
base_time_.host_start_time = GetHostTimeStamp();
base_time_.host_start_monotonic_raw_time = GetHostMonoTimeStamp();
// Set the profile data path and log relevant information
profile_data_path_ = profileDataPath;
MS_LOG(INFO) << "GPU start time(ns):" << base_time_.gpu_start_time
<< " Host start time(ns):" << base_time_.host_start_time << " profile data path: " << profile_data_path_;
is_init_ = true;
}
// SetRunTimeData function
// This function sets runtime data for a specific operation.
void GPUProfiler::SetRunTimeData(const std::string &op_name, void *stream) {
// Check if the operation already exists in the op_info_map
auto iter = op_info_map_.find(op_name);
if (iter != op_info_map_.end()) {
// If it exists, increment the operation count
iter->second.op_count += 1;
} else {
// If it doesn't exist, create a new OpInfo entry and set its data
OpInfo op_info;
op_info.op_name = op_name;
op_info.stream = stream;
op_info.op_count = 1;
op_info_map_[op_name] = op_info;
}
// Set the current operation name and stream
op_name_ = op_name;
stream_ = stream;
}
// OpDataProducerBegin function
// This function marks the beginning of an operation's data production and records start timestamps.
void GPUProfiler::OpDataProducerBegin(const std::string op_name, void *stream) {
if (sync_enable_flag_) {
// Create CUDA events for synchronization if sync_enable_flag_ is true
CHECK_CUDA_RET_WITH_ERROR(cudaEventCreate(&op_event_start_), "cudaEventCreate op event start failed");
CHECK_CUDA_RET_WITH_ERROR(cudaEventCreate(&op_event_stop_), "cudaEventCreate op event stop failed");
CHECK_CUDA_RET_WITH_ERROR(cudaEventRecord(op_event_start_, (CUstream)stream_),
@ -442,66 +537,103 @@ void GPUProfiler::OpDataProducerBegin(const std::string op_name, void *stream) {
op_host_time_start_ = GetHostTimeStamp();
op_cupti_time_start_ = GetCUPTITimeStamp();
} else {
// Record timestamps without synchronization
op_host_time_start_ = GetHostTimeStamp();
op_cupti_time_start_ = GetCUPTITimeStamp();
}
// Set runtime data for the current operation
SetRunTimeData(op_name, stream);
// Record the start time for the operation if MindRT is enabled
if (MsContext::GetInstance()->get_param<bool>(MS_CTX_ENABLE_MINDRT)) {
RecordOneStepStartEndInfo(op_name);
}
}
// SingleOpLaunchTimeProcess function
// This function processes the launch time of a single operation.
void GPUProfiler::SingleOpLaunchTimeProcess(float op_time_elapsed) {
// Get the launch end time
auto launch_end_time = GetTime();
// Calculate the launch start time
double launch_start_time = launch_end_time - op_time_elapsed / kTimeUnit / kTimeUnit;
// Set the single operation launch time as a pair of start and end times
SetSingleOpLaunchTime(std::make_pair(launch_start_time, launch_end_time));
}
// OpDataProducerEnd function
// This function marks the end of an operation's data production and calculates the elapsed time.
void GPUProfiler::OpDataProducerEnd() {
float op_time_elapsed = 0;
if (sync_enable_flag_) {
// Record end event and synchronize if sync_enable_flag_ is true
CHECK_CUDA_RET_WITH_ERROR(cudaEventRecord(op_event_stop_, (CUstream)stream_),
"cudaEventRecord op event stop failed");
CHECK_CUDA_RET_WITH_ERROR(cudaEventSynchronize(op_event_start_), "cudaEventSynchronize op event start failed");
CHECK_CUDA_RET_WITH_ERROR(cudaEventSynchronize(op_event_stop_), "cudaEventSynchronize op event stop failed");
// Calculate the elapsed time using CUDA events
CHECK_CUDA_RET_WITH_ERROR(cudaEventElapsedTime(&op_time_elapsed, op_event_start_, op_event_stop_),
"cudaEventElapsedTime failed");
// Destroy CUDA events
CHECK_CUDA_RET_WITH_ERROR(cudaEventDestroy(op_event_start_), "cudaEventDestroy op event start failed");
CHECK_CUDA_RET_WITH_ERROR(cudaEventDestroy(op_event_stop_), "cudaEventDestroy op event stop failed");
// Convert elapsed time to microseconds
op_time_elapsed = op_time_elapsed * kTimeUnit;
// Record the host stop time
op_host_time_stop_ = GetHostTimeStamp();
// Process the launch time for the single operation
SingleOpLaunchTimeProcess(op_time_elapsed);
} else {
// Calculate elapsed time without synchronization
op_host_time_stop_ = GetHostTimeStamp();
op_time_elapsed = (op_host_time_stop_ - op_host_time_start_) / kTimeUnit;
// Process the launch time for the single operation
SingleOpLaunchTimeProcess(op_time_elapsed);
}
// Log the host elapsed time for the operation
MS_LOG(DEBUG) << "Host Time Elapsed(us)," << op_name_ << "," << op_time_elapsed;
// Set runtime data for the operation with elapsed time
Profiler::SetRunTimeData(op_name_, op_time_elapsed);
Profiler::SetRunTimeData(op_name_, op_cupti_time_start_, op_time_elapsed);
}
// StopCUPTI function
// This function stops CUPTI profiling, unsubscribing and disabling CUPTI activities.
void GPUProfiler::StopCUPTI() {
if (subscriber_ != nullptr) {
// Unsubscribe from CUPTI and flush activity records
CHECK_CUPTI_RET_WITH_ERROR(CuptiUnsubscribe(subscriber_), "CuptiUnsubscribe");
CHECK_CUPTI_RET_WITH_ERROR(CuptiActivityFlushAll(0), "CuptiActivityFlushAll");
// Disable CUPTI activities
for (std::vector<CUpti_ActivityKind>::iterator it = activities_enable_.begin(); it != activities_enable_.end();
++it) {
CHECK_CUPTI_RET_WITH_ERROR(CuptiActivityDisable(*it), "CuptiActivityDisable");
}
// Reset the subscriber to nullptr
subscriber_ = nullptr;
}
}
// Stop function
// This function stops GPU profiling and performs necessary cleanup.
void GPUProfiler::Stop() {
MS_LOG(INFO) << "Stop GPU Profiling";
// Stop CUPTI profiling
StopCUPTI();
// Parse and process profiling operations
OpsParser();
// Save profile data to the specified path
SaveProfileData();
// Clear the profiling instance
ClearInst();
}
// SaveExtraProfileData function
// This function saves extra profiling data for each profiling operation.
void GPUProfiler::SaveExtraProfileData() {
for (auto op : profiling_op_) {
op.second->SaveProfilingData();
@ -509,18 +641,29 @@ void GPUProfiler::SaveExtraProfileData() {
MS_LOG(INFO) << "Save extra profiling data end.";
}
// SaveProfileData function
// This function saves the GPU profiling data to the specified path.
void GPUProfiler::SaveProfileData() {
if (profile_data_path_.empty()) {
MS_LOG(WARNING) << "Profile data path is empty, skip save profile data.";
} else {
// Create a GpuDataSaver instance
GpuDataSaver dataSaver(step_trace_op_name_, all_step_start_end_info_);
// Parse operation information and events for saving
dataSaver.ParseOpInfo(op_info_map_);
dataSaver.ParseEvent(events_);
// Write the profile data to the specified path
dataSaver.WriteFile(profile_data_path_, base_time_);
// Save extra profiling data
SaveExtraProfileData();
}
}
// ClearInst function
// This function clears the GPU profiling instance and its associated data.
void GPUProfiler::ClearInst() {
op_info_map_.clear();
op_name_map_.clear();
@ -534,6 +677,8 @@ void GPUProfiler::ClearInst() {
cupti_activity_events_drop_count_ = 0l;
}
// ActivityAllocBuffer function
// This function allocates a buffer for GPU activity records.
void CUPTIAPI ActivityAllocBuffer(uint8_t **buffer, size_t *size, size_t *maxNumRecords) {
auto gpu_profiler_inst = GPUProfiler::GetInstance();
if (gpu_profiler_inst == nullptr) {
@ -543,6 +688,8 @@ void CUPTIAPI ActivityAllocBuffer(uint8_t **buffer, size_t *size, size_t *maxNum
gpu_profiler_inst->AllocBuffer(buffer, size, maxNumRecords);
}
// ActivityProcessBuffer function
// This function processes the GPU activity buffer and records.
void CUPTIAPI ActivityProcessBuffer(CUcontext ctx, uint32_t streamId, uint8_t *buffer, size_t size, size_t validSize) {
PROFILER_ERROR_IF_NULLPTR(buffer);
auto gpu_profiler_inst = GPUProfiler::GetInstance();
@ -553,8 +700,10 @@ void CUPTIAPI ActivityProcessBuffer(CUcontext ctx, uint32_t streamId, uint8_t *b
gpu_profiler_inst->ProcessBuffer(ctx, streamId, buffer, size, validSize);
}
void ProcessActivityMemcpyRecord(Event *profilingData, CUpti_Activity *record,
CUpti_ActivityMemcpy *cupti_activity_memcpy) {
// ProcessActivityMemcpyRecord function
// This function processes the CUPTI activity record related to memory copy operations.
void ProcessActivityMemcpyRecord(Event *profilingData, CUpti_Activity *record, CUpti_ActivityMemcpy *cupti_activity_memcpy) {
// Determine the type of memory copy operation and set the profiling data accordingly
switch (cupti_activity_memcpy->copyKind) {
case CUPTI_ACTIVITY_MEMCPY_KIND_HTOD:
profilingData->activity_type = ActivityType::kMemcpyH2D;
@ -599,6 +748,8 @@ void ProcessActivityMemcpyRecord(Event *profilingData, CUpti_Activity *record,
}
}
// HandleActivityMemcpyRecord function
// This function handles CUPTI activity records related to memory copy operations.
void HandleActivityMemcpyRecord(Event *profilingData, CUpti_Activity *record) {
CUpti_ActivityMemcpy *cupti_activity_memcpy = reinterpret_cast<CUpti_ActivityMemcpy *>(record);
ProcessActivityMemcpyRecord(profilingData, record, cupti_activity_memcpy);
@ -616,6 +767,8 @@ void HandleActivityMemcpyRecord(Event *profilingData, CUpti_Activity *record) {
profilingData->memcpy_info.dst_kind = cupti_activity_memcpy->dstKind;
}
// HandleActivityMemcpy2Record function
// This function handles CUPTI activity records related to memory copy operations (P2P).
void HandleActivityMemcpy2Record(Event *profilingData, CUpti_Activity *record) {
CUpti_ActivityMemcpy2 *memcpyP2P = reinterpret_cast<CUpti_ActivityMemcpy2 *>(record);
profilingData->activity_type = ActivityType::kMemcpyP2P;
@ -633,6 +786,8 @@ void HandleActivityMemcpy2Record(Event *profilingData, CUpti_Activity *record) {
profilingData->memcpy_info.dst_kind = memcpyP2P->dstKind;
}
// HandleActivityMemsetRecord function
// This function handles CUPTI activity records related to memory set operations.
void HandleActivityMemsetRecord(Event *profilingData, CUpti_Activity *record) {
CUpti_ActivityMemset *cupti_activity_memset = reinterpret_cast<CUpti_ActivityMemset *>(record);
profilingData->activity_type = ActivityType::kMemset;
@ -647,19 +802,32 @@ void HandleActivityMemsetRecord(Event *profilingData, CUpti_Activity *record) {
profilingData->memcpy_info.bytes = cupti_activity_memset->bytes;
}
// HandleActivityKernelRecord function
// This function handles CUpti_ActivityKernel4 records and populates profilingData with relevant information.
void HandleActivityKernelRecord(Event *profilingData, CUpti_Activity *record) {
// Cast the CUpti_Activity record to CUpti_ActivityKernel4 type
CUpti_ActivityKernel4 *kernel = reinterpret_cast<CUpti_ActivityKernel4 *>(record);
// Set the activity type and API type in profilingData
profilingData->activity_type = ActivityType::kKernel;
profilingData->api_type = CUPTIApiType::kActivity;
// Get the kernel name and update it with the simplified name
profilingData->kernel_name = GetKernelFunc(kernel->name);
profilingData->kernel_name = GetKernelFuncName(profilingData->kernel_name);
// Set the kernel type and timestamps
profilingData->kernel_type = "cuLaunchKernel";
profilingData->start_time_stamp = kernel->start;
profilingData->end_time_stamp = kernel->end;
// Set the device, context, stream, and correlation IDs
profilingData->device_id = kernel->deviceId;
profilingData->context_id = kernel->contextId;
profilingData->stream_id = kernel->streamId;
profilingData->correlation_id = kernel->correlationId;
// Populate kernel information
profilingData->kernel_info.registers_per_thread = kernel->registersPerThread;
profilingData->kernel_info.static_shared_memory = kernel->staticSharedMemory;
profilingData->kernel_info.dynamic_shared_memory = kernel->dynamicSharedMemory;
@ -671,10 +839,17 @@ void HandleActivityKernelRecord(Event *profilingData, CUpti_Activity *record) {
profilingData->kernel_info.grid_z = kernel->gridZ;
}
// GPUProfiler::HandleActivityRecord function
// This function processes different types of CUpti_Activity records and delegates to specific record handlers.
void GPUProfiler::HandleActivityRecord(CUpti_Activity *record) {
// Check for null record pointer
PROFILER_ERROR_IF_NULLPTR(record);
// Create an Event object for profiling data
Event profilingData;
profilingData.cb_id = 0;
// Determine the type of the CUpti_Activity record and call the appropriate handler
switch (record->kind) {
case CUPTI_ACTIVITY_KIND_MEMCPY: {
HandleActivityMemcpyRecord(&profilingData, record);
@ -698,48 +873,75 @@ void GPUProfiler::HandleActivityRecord(CUpti_Activity *record) {
return;
}
// Add the profilingData event to the profiler's data collection
AddEvent(std::move(profilingData));
}
// GPUProfiler::SetStepTraceOpName function
// This function sets the step_trace_op_name_ field in the GPUProfiler.
void GPUProfiler::SetStepTraceOpName(ProfilingTraceInfo trace_op_name) { step_trace_op_name_ = trace_op_name; }
// GPUProfiler::RegisterProfilingOp function
// This function registers a profiling operation in the profiler.
void GPUProfiler::RegisterProfilingOp(std::shared_ptr<ProfilingOp> node) {
// Check for null pointer and existing registration
PROFILER_ERROR_IF_NULLPTR(node);
if (profiling_op_.find(node->Name()) != profiling_op_.end()) {
return;
}
// Initialize the profiling operation
node->Init();
// Register the profiling operation
profiling_op_[node->Name()] = node;
}
// GPUProfiler::AllocBuffer function
// This function allocates memory for the GPU activity buffer.
void CUPTIAPI GPUProfiler::AllocBuffer(uint8_t **buffer, size_t *size, size_t *maxNumRecords) {
// Check for null size and maxNumRecords pointers
PROFILER_ERROR_IF_NULLPTR(size);
PROFILER_ERROR_IF_NULLPTR(maxNumRecords);
// Allocate memory for the activity buffer
int stat = posix_memalign(reinterpret_cast<void **>(buffer), ALIGN_SIZE, BUF_SIZE);
if (stat) {
MS_LOG(ERROR) << "Out of memory, activity buffer alloc failed.";
MS_LOG(ERROR) << "Out of memory, activity buffer allocation failed.";
return;
}
MS_LOG(DEBUG) << "Alloc activity buffer, buffer size: " << BUF_SIZE;
// Log the allocation size
MS_LOG(DEBUG) << "Allocated activity buffer, buffer size: " << BUF_SIZE;
// Set size and maxNumRecords values
*size = BUF_SIZE;
*maxNumRecords = 0;
}
// GPUProfiler::ProcessBuffer function
// This function processes the GPU activity buffer and handles CUpti_Activity records.
void CUPTIAPI GPUProfiler::ProcessBuffer(CUcontext ctx, uint32_t streamId, uint8_t *buffer, size_t size,
size_t validSize) {
// Skip processing if profiling is not enabled
if (!enable_flag_) {
MS_LOG(DEBUG) << "Profiler is not enable, skip to process activity record.";
MS_LOG(DEBUG) << "Profiler is not enabled, skipping processing of activity record.";
free(buffer);
return;
}
CUptiResult status;
CUpti_Activity *record = NULL;
MS_LOG(DEBUG) << "Process activity buffer, valid size:" << validSize << ",Stream ID:" << streamId;
// Log processing information
MS_LOG(DEBUG) << "Processing activity buffer, valid size: " << validSize << ", Stream ID: " << streamId;
// Process each CUpti_Activity record in the buffer
if (validSize > 0) {
do {
status = CuptiActivityGetNextRecord(buffer, validSize, &record);
if (status == CUPTI_SUCCESS) {
// Handle the current record
HandleActivityRecord(record);
} else if (status == CUPTI_ERROR_MAX_LIMIT_REACHED) {
break;
@ -748,7 +950,7 @@ void CUPTIAPI GPUProfiler::ProcessBuffer(CUcontext ctx, uint32_t streamId, uint8
}
} while (1);
// report any records dropped from the queue
// Report any records dropped from the queue
size_t dropped;
CHECK_CUPTI_RET_WITH_ERROR(CuptiActivityGetNumDroppedRecords(ctx, streamId, &dropped),
"CuptiActivityGetNumDroppedRecords");
@ -757,18 +959,20 @@ void CUPTIAPI GPUProfiler::ProcessBuffer(CUcontext ctx, uint32_t streamId, uint8
}
}
// Free the allocated buffer memory
free(buffer);
}
// PYBIND registration for GPUProfiler class
REGISTER_PYBIND_DEFINE(GPUProfiler_, ([](const py::module *m) {
(void)py::class_<GPUProfiler, std::shared_ptr<GPUProfiler>>(*m, "GPUProfiler")
.def_static("get_instance", &GPUProfiler::GetInstance, "GPUProfiler get_instance.")
.def("init", &GPUProfiler::Init, py::arg("profile_data_path"), "init")
.def("stop", &GPUProfiler::Stop, "stop")
.def("init", &GPUProfiler::Init, py::arg("profile_data_path"), "Initialize GPUProfiler")
.def("stop", &GPUProfiler::Stop, "Stop GPUProfiler")
.def("step_profiling_enable", &GPUProfiler::StepProfilingEnable, py::arg("enable_flag"),
"enable or disable step profiling")
"Enable or disable step profiling")
.def("sync_enable", &GPUProfiler::SyncEnable, py::arg("enable_flag"),
"enable or disable synchronization profiling");
"Enable or disable synchronization profiling");
}));
} // namespace gpu
} // namespace profiler

88
mindspore/ccsrc/profiler/device/gpu/gpu_profiling_utils.cc
View File

@ -25,34 +25,50 @@
namespace mindspore {
namespace profiler {
namespace gpu {
// Constants for environment variable names
constexpr char kFpStartNode[] = "PROFILING_FP_START";
constexpr char kBpEndNode[] = "PROFILING_BP_END";
constexpr char kIterEndNode[] = "PROFILING_ITER_END";
constexpr auto kInitDatasetQueueOpName = "InitDataSetQueue";
// Static member initialization
bool ProfilingUtils::have_communication_op = false;
ProfilingTraceInfo ProfilingUtils::profiling_trace = {"", "", ""};
std::unordered_map<uint32_t, bool> ProfilingUtils::is_first_step_map_ = {};
// GetProfilingTraceFromEnv function
// This function extracts profiling trace information from the environment variables and the given graph.
ProfilingTraceInfo ProfilingUtils::GetProfilingTraceFromEnv(NotNull<const session::KernelGraph *> graph_ptr) {
MS_LOG(INFO) << "get current subgraph op name start.";
// Log a message to indicate the start of the process
MS_LOG(INFO) << "Getting current subgraph op names start.";
// Get the execution order of CNodes in the graph
auto &cnode_exec_order = graph_ptr->execution_order();
// Check if there are no CNodes in the execution order
if (cnode_exec_order.empty()) {
// Return an empty profiling trace
return profiling_trace;
}
// Initialize variables
ProfilingTraceInfo empty_info;
ProfilingTraceInfo last_graph_profiling_trace = profiling_trace;
profiling_trace = empty_info;
// Step 1: Extract profiling trace information from environment variables and the graph
SetTraceIterEnd(cnode_exec_order);
SetTraceFpStart(cnode_exec_order);
SetTraceBpEnd(cnode_exec_order);
GetTraceHccl(cnode_exec_order);
// Step 2: Output step trace op name status
OutputStepTraceOpNameStatus();
// Step 3: Update the map to indicate that the current graph has been processed
is_first_step_map_[graph_ptr->graph_id()] = false;
// If current graph has only one node, the bp_end will be empty, so select the last graph node.
// If the current graph has only one node, the bp_end will be empty, so select the last graph node.
if (profiling_trace.trace_bp_end != "") {
return profiling_trace;
} else {
@ -60,19 +76,34 @@ ProfilingTraceInfo ProfilingUtils::GetProfilingTraceFromEnv(NotNull<const sessio
}
}
// OutputStepTraceOpNameStatus function
// This function logs the step trace op names and their statuses.
void ProfilingUtils::OutputStepTraceOpNameStatus() {
if (profiling_trace.IsValid()) {
MS_LOG(INFO) << "Get all the step_trace op name.";
// Log a message indicating that step trace op names are being obtained
MS_LOG(INFO) << "Getting all the step_trace op names.";
}
// Log the collected profiling trace information
MS_LOG(INFO) << "[profiling]trace_fp_start: " << profiling_trace.trace_fp_start
<< "trace_bp_end: " << profiling_trace.trace_bp_end
<< "trace_iter_end: " << profiling_trace.trace_iter_end;
MS_LOG(INFO) << "get step_trace op name end.";
// Log a message indicating the completion of step trace op name collection
MS_LOG(INFO) << "Getting step_trace op names end.";
}
// GetTraceHccl function
// This function extracts HCCL communication node names from the given list of CNodes.
void ProfilingUtils::GetTraceHccl(const std::vector<CNodePtr> &cnode_exec_order) {
// Iterate through the CNodes in the execution order
for (const auto &node : cnode_exec_order) {
// Check if the current node is a communication op
if (common::AnfAlgo::IsCommunicationOp(node)) {
// Log the name of the HCCL node found
MS_LOG(INFO) << "[profiling]Get hccl node:" << node->fullname_with_scope();
// Add the HCCL node name to the list of custom nodes in the profiling trace
MS_EXCEPTION_IF_NULL(node);
if (std::find(profiling_trace.trace_custom_node.begin(), profiling_trace.trace_custom_node.end(),
node->fullname_with_scope()) == profiling_trace.trace_custom_node.end()) {
@ -83,42 +114,60 @@ void ProfilingUtils::GetTraceHccl(const std::vector<CNodePtr> &cnode_exec_order)
}
}
// SetTraceFpStart function
// This function sets the trace_fp_start field in the profiling trace based on environment variables and the first CNode.
void ProfilingUtils::SetTraceFpStart(const std::vector<CNodePtr> &cnode_exec_order) {
// Step 1: Check if the trace_fp_start environment variable is set
const char *trace_fp_start = std::getenv(kFpStartNode);
if (trace_fp_start != nullptr) {
// Set the trace_fp_start field from the environment variable
profiling_trace.trace_fp_start = std::string(trace_fp_start);
MS_LOG(INFO) << "Set the Fp Start Op Name from Environment Variable:" << profiling_trace.trace_fp_start;
// Log the source of the trace_fp_start value
MS_LOG(INFO) << "Setting the Fp Start Op Name from Environment Variable:" << profiling_trace.trace_fp_start;
return;
}
// Step 2: Determine the trace_fp_start based on CNode order
auto first_node = cnode_exec_order.front();
MS_EXCEPTION_IF_NULL(first_node);
auto node_name = common::AnfAlgo::GetCNodeName(first_node);
// If the first node is an "InitDataSetQueue" operation, skip it
if (node_name == kInitDatasetQueueOpName) {
return;
}
// If the first node is "GetNext", check the node behind it
if (node_name == kGetNextOpName) {
if (cnode_exec_order.size() > 1) {
profiling_trace.trace_fp_start = cnode_exec_order.at(1)->fullname_with_scope();
} else {
// Log a warning if there is no operation behind "GetNext"
MS_LOG(WARNING) << "No Op Behind the GetNext Op" << std::endl;
}
} else {
// Set the trace_fp_start to the name of the first CNode
profiling_trace.trace_fp_start = first_node->fullname_with_scope();
}
}
// SetTraceBpEnd function
// This function sets the trace_bp_end field in the profiling trace based on environment variables and CNodes.
void ProfilingUtils::SetTraceBpEnd(const std::vector<CNodePtr> &cnode_exec_order) {
// Step 1: Check if the trace_bp_end environment variable is set
const char *trace_bp_end = std::getenv(kBpEndNode);
if (trace_bp_end != nullptr) {
// Set the trace_bp_end field from the environment variable
profiling_trace.trace_bp_end = std::string(trace_bp_end);
MS_LOG(INFO) << "Set the Bp End Op Name from Environment Variable:" << profiling_trace.trace_bp_end;
// Log the source of the trace_bp_end value
MS_LOG(INFO) << "Setting the Bp End Op Name from Environment Variable:" << profiling_trace.trace_bp_end;
return;
}
// Step 2: Determine the trace_bp_end based on CNode order and communication ops
std::string bp_end_str;
// Contain hccl kernel (try to find the last communication op)
// Look for the last communication op in the reverse order of execution
auto iter = cnode_exec_order.rbegin();
while (iter != cnode_exec_order.rend()) {
if (common::AnfAlgo::IsCommunicationOp(*iter)) {
@ -126,9 +175,10 @@ void ProfilingUtils::SetTraceBpEnd(const std::vector<CNodePtr> &cnode_exec_order
}
++iter;
}
// If find the communication op
// If a communication op is found, store its input nodes' names
if (iter != cnode_exec_order.rend()) {
// store communication op input nodes' name
// Store communication op input nodes' names
std::set<std::string> ar_input_node_names;
size_t input_num = common::AnfAlgo::GetInputTensorNum(*iter);
for (size_t i = 0; i < input_num; ++i) {
@ -136,9 +186,9 @@ void ProfilingUtils::SetTraceBpEnd(const std::vector<CNodePtr> &cnode_exec_order
auto input_node = input_node_with_index.first;
ar_input_node_names.insert(input_node->fullname_with_scope());
}
// start from previous node
// Start searching from the previous node
++iter;
// find input names in previous node
// Find input names in previous nodes
while (iter != cnode_exec_order.rend()) {
if (ar_input_node_names.find((*iter)->fullname_with_scope()) != ar_input_node_names.end()) {
bp_end_str = (*iter)->fullname_with_scope();
@ -148,27 +198,37 @@ void ProfilingUtils::SetTraceBpEnd(const std::vector<CNodePtr> &cnode_exec_order
}
}
// If bp_end_str is still empty and there are no communication ops, try to find the second last kernel name.
if (bp_end_str.empty() && !have_communication_op) {
bp_end_str = GetGraphSecondLastKernelName(cnode_exec_order);
}
// Set the trace_bp_end field to the determined value
if (!bp_end_str.empty()) {
profiling_trace.trace_bp_end = bp_end_str;
}
}
// SetTraceIterEnd function
// This function sets the trace_iter_end field in the profiling trace based on environment variables and CNodes.
void ProfilingUtils::SetTraceIterEnd(const std::vector<CNodePtr> &cnode_exec_order) {
// Step 1: Check if the trace_iter_end environment variable is set
const char *trace_iter_end = std::getenv(kIterEndNode);
if (trace_iter_end != nullptr) {
// Set the trace_iter_end field from the environment variable
profiling_trace.trace_iter_end = std::string(trace_iter_end);
MS_LOG(INFO) << "Set the Iter End Op Name from Environment Variable:" << profiling_trace.trace_iter_end;
// Log the source of the trace_iter_end value
MS_LOG(INFO) << "Setting the Iter End Op Name from Environment Variable:" << profiling_trace.trace_iter_end;
return;
}
// Step 2: Determine the trace_iter_end based on CNode order
auto iter_end = cnode_exec_order.rbegin();
profiling_trace.trace_iter_end = (*iter_end)->fullname_with_scope();
}
// GetGraphSecondLastKernelName function
// This function returns the name of the second last kernel in the given list of CNodes.
std::string ProfilingUtils::GetGraphSecondLastKernelName(const std::vector<CNodePtr> &cnode_exec_order) {
std::string second_last_kernel_name;
auto iter = cnode_exec_order.rbegin();
@ -180,6 +240,8 @@ std::string ProfilingUtils::GetGraphSecondLastKernelName(const std::vector<CNode
return second_last_kernel_name;
}
// IsFirstStep function
// This function checks if the graph with the given graph_id is the first step in profiling.
bool ProfilingUtils::IsFirstStep(const uint32_t graph_id) {
auto iter = is_first_step_map_.find(graph_id);
if (iter == is_first_step_map_.end()) {

71
mindspore/ccsrc/profiler/device/gpu/gpu_profiling_utils.h
View File

@ -43,30 +43,93 @@ struct ProfilingTraceInfo {
bool IsValid() const { return !(trace_fp_start.empty() || trace_bp_end.empty() || trace_iter_end.empty()); }
};
/**
* @brief A utility class for handling profiling trace points and information.
*/
class ProfilingUtils {
public:
ProfilingUtils() = default;
~ProfilingUtils() = default;
// Get profiling trace point from envs.
// export PROFILING_FP_START='full name of the first cnode to execute'
// export PROFILING_BP_END='full name of the last backpropagation cnode to execute'
// export PROFILING_ITER_END='full name of last cnode in graph to execute'
/**
* @brief Get profiling trace points from environment variables.
*
* This function retrieves profiling trace points from environment variables.
* It looks for specific environment variables and extracts trace points information.
*
* @param graph_ptr Pointer to the kernel graph.
* @return ProfilingTraceInfo containing trace point information.
*/
static ProfilingTraceInfo GetProfilingTraceFromEnv(NotNull<const session::KernelGraph *> graph_ptr);
/**
* @brief Output step trace op name and status.
*
* This function outputs the op names and their status related to profiling.
*/
static void OutputStepTraceOpNameStatus();
/**
* @brief Check if the current step is the first step of a graph.
*
* @param graph_id The identifier of the graph.
* @return True if it's the first step, false otherwise.
*/
static bool IsFirstStep(const uint32_t graph_id);
/**
* @brief A flag indicating whether there are communication ops in the graph.
*/
static bool have_communication_op;
/**
* @brief Profiling trace information containing trace points.
*/
static ProfilingTraceInfo profiling_trace;
private:
/**
* @brief Set the trace point for the first forward-propagation (FP) operation.
*
* @param cnode_exec_order The execution order of CNodes in the graph.
*/
static void SetTraceFpStart(const std::vector<CNodePtr> &cnode_exec_order);
/**
* @brief Set the trace point for the last back-propagation (BP) operation.
*
* @param cnode_exec_order The execution order of CNodes in the graph.
*/
static void SetTraceBpEnd(const std::vector<CNodePtr> &cnode_exec_order);
/**
* @brief Set the trace point for the last iteration (ITER) operation.
*
* @param cnode_exec_order The execution order of CNodes in the graph.
*/
static void SetTraceIterEnd(const std::vector<CNodePtr> &cnode_exec_order);
/**
* @brief Get the name of the second last kernel in the graph.
*
* @param cnode_exec_order The execution order of CNodes in the graph.
* @return The name of the second last kernel.
*/
static std::string GetGraphSecondLastKernelName(const std::vector<CNodePtr> &cnode_exec_order);
/**
* @brief Get trace information related to HCCL communication operations.
*
* @param cnode_exec_order The execution order of CNodes in the graph.
*/
static void GetTraceHccl(const std::vector<CNodePtr> &cnode_exec_order);
/**
* @brief A map to keep track of whether a graph is the first step.
*/
static std::unordered_map<uint32_t, bool> is_first_step_map_;
};
} // namespace gpu
} // namespace profiler
} // namespace mindspore

67
mindspore/ccsrc/profiler/device/profiling.cc
View File

@ -1,82 +1,71 @@
/**
* Copyright 2021 Huawei Technologies Co., Ltd
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
#include "profiler/device/profiling.h"
#include <cxxabi.h>
#include <cmath>
#include <ctime>
#include "include/common/pybind_api/api_register.h"
#include "utils/log_adapter.h"
#include "include/common/utils/utils.h"
#if ENABLE_GPU
#include "profiler/device/gpu/gpu_profiling.h"
#endif
#if ENABLE_D
#include "profiler/device/ascend/ascend_profiling.h"
#endif
namespace mindspore {
namespace profiler {
std::shared_ptr<ProfilerManager> ProfilerManager::profiler_manager_inst_ = std::make_shared<ProfilerManager>();
// Function to get the host monotonic timestamp in microseconds
// Returns: uint64_t - Current host monotonic timestamp in microseconds
uint64_t Profiler::GetHostMonoTimeStamp() const {
struct timespec ts;
#if defined(_WIN32) || defined(_WIN64)
// On Windows, use CLOCK_MONOTONIC for timestamp
if (clock_gettime(CLOCK_MONOTONIC, &ts) != 0) {
MS_LOG(ERROR) << "Get host timestamp failed";
return 0;
}
#else
// On non-Windows systems, use CLOCK_MONOTONIC_RAW for timestamp
if (clock_gettime(CLOCK_MONOTONIC_RAW, &ts) != 0) {
MS_LOG(ERROR) << "Get host timestamp failed";
return 0;
}
#endif
constexpr uint64_t kNSecondInSecond = 1000000000;
uint64_t cur_time_stamp = ts.tv_sec * kNSecondInSecond + ts.tv_nsec;
return cur_time_stamp;
}
// Function to get the real timestamp in microseconds
// Returns: uint64_t - Current real timestamp in microseconds
uint64_t Profiler::GetRealTimeStamp() const {
struct timeval tv = {0, 0};
(void)gettimeofday(&tv, NULL);
int64_t kUSecondInSecond = 1000000;
int64_t ts = kUSecondInSecond * static_cast<int64_t>(tv.tv_sec);
ts += static_cast<int64_t>(tv.tv_usec);
// us timestamp
// Return the timestamp in microseconds
return (uint64_t)ts;
}
// Function to set runtime data for an operation
// Parameters:
// op_name (const std::string&) - The name of the operation
// time_elapsed (const float) - Time elapsed for the operation
void Profiler::SetRunTimeData(const std::string &op_name, const float time_elapsed) {
std::shared_lock<std::shared_mutex> lock(op_map_mutex_);
auto iter = op_info_map_.find(op_name);
if (iter != op_info_map_.end()) {
// Update the host cost time for the operation
iter->second.op_host_cost_time += time_elapsed;
}
}
// Function to set runtime data with start timestamp and duration for an operation
// Parameters:
// op_name (const std::string&) - The name of the operation
// start (const uint64_t) - Start timestamp of the operation
// duration (const float) - Duration of the operation
void Profiler::SetRunTimeData(const std::string &op_name, const uint64_t start, const float duration) {
std::shared_lock<std::shared_mutex> lock(op_map_mutex_);
auto iter = op_info_map_.find(op_name);
if (iter != op_info_map_.end()) {
// Add start and duration information for the operation
iter->second.start_duration.emplace_back(StartDuration({start, duration}));
}
}
// Function to record start and end information for one step
// Explanation: This function records the start and end information for one step of the computation graph.
void Profiler::RecordOneStepStartEndInfo() {
// Multi-graph dotting data is not supported.
std::lock_guard<std::mutex> locker(record_mutex_);
@ -86,7 +75,7 @@ void Profiler::RecordOneStepStartEndInfo() {
step_start_end_info_.iter_start_op_name = step_start_end_info_vector_[0];
step_start_end_info_.fp_start_op_name = step_start_end_info_vector_[0];
// If is the first step, the step_start_end_info_vector_ length is 1.
// If it is the first step, the step_start_end_info_vector_ length is 1.
if (vector_size > 1) {
// Iterate through step_start_end_info_vector_ for the repeat operator, which is the operator of the next step and
// is preceded by iter_end_op of the current step.
@ -138,6 +127,9 @@ void Profiler::RecordOneStepStartEndInfo() {
step_start_end_info_.fp_start_op_name = "";
}
// Function to record start and end information for one step of an operation
// Parameters:
// op_name (const std::string&) - The name of the operation
void Profiler::RecordOneStepStartEndInfo(const std::string op_name) {
std::lock_guard<std::mutex> locker(record_mutex_);
if (step_start_end_info_.iter_start_op_name.empty()) {
@ -157,11 +149,15 @@ void Profiler::RecordOneStepStartEndInfo(const std::string op_name) {
step_start_end_info_vector_.push_back(op_name);
}
// Get the singleton instance of ProfilerManager
// Returns: std::shared_ptr<ProfilerManager> - Shared pointer to the ProfilerManager instance
std::shared_ptr<ProfilerManager> &ProfilerManager::GetInstance() {
MS_EXCEPTION_IF_NULL(profiler_manager_inst_);
return profiler_manager_inst_;
}
// Get the profiling enable flag
// Returns: bool - Profiling enable flag
bool ProfilerManager::GetProfilingEnableFlag() const {
#if ENABLE_GPU
return profiler::gpu::GPUProfiler::GetInstance()->GetEnableFlag();
@ -174,6 +170,7 @@ bool ProfilerManager::GetProfilingEnableFlag() const {
return false;
}
// Record start and end information for one step (if GPU profiling is enabled)
void ProfilerManager::RecordOneStepStartEndInfo() const {
#if ENABLE_GPU
auto gpu_profiler_inst = profiler::gpu::GPUProfiler::GetInstance();
@ -183,6 +180,8 @@ void ProfilerManager::RecordOneStepStartEndInfo() const {
#endif
}
// Get profiling options as a string (if Ascend profiling is enabled)
// Returns: std::string - Profiling options as a string
std::string ProfilerManager::GetProfilingOptions() const {
#if ENABLE_D
auto ascend_instance = profiler::ascend::AscendProfiler::GetInstance();

125
mindspore/ccsrc/profiler/device/profiling.h
View File

@ -1,21 +1,11 @@
/**
* Copyright 2021 Huawei Technologies Co., Ltd
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
* @file device_profiling.h
* @brief This header file contains declarations of classes and structures related to device profiling.
*/
#ifndef MINDSPORE_CCSRC_PROFILER_DEVICE_PROFILING_H
#define MINDSPORE_CCSRC_PROFILER_DEVICE_PROFILING_H
#include <algorithm>
#include <cstdio>
#include <map>
@ -30,32 +20,37 @@
namespace mindspore {
namespace profiler {
// Structure to store start timestamp, duration, and thread ID of an event
struct StartDuration {
uint64_t start_timestamp = 0l;
float duration = 0l;
size_t tid = 0;
uint64_t start_timestamp = 0l; /**< Start timestamp of the event in microseconds. */
float duration = 0l; /**< Duration of the event in microseconds. */
size_t tid = 0; /**< Thread ID associated with the event. */
};
// Structure to store start and end operation names for one step
struct OneStepStartEndInfo {
std::string iter_start_op_name;
std::string fp_start_op_name;
std::string iter_end_op_name;
std::string iter_start_op_name; /**< Operation name for iteration start. */
std::string fp_start_op_name; /**< Operation name for forward propagation start. */
std::string iter_end_op_name; /**< Operation name for iteration end. */
};
// Structure to store profiling information for an operation
struct OpInfo {
std::string op_name;
float cupti_api_call_time = 0l;
float cupti_activity_time = 0l;
float op_host_cost_time = 0;
int op_kernel_api_count = 0;
int op_kernel_count = 0;
int op_count = 0;
StartDuration tmp_start_duration;
std::vector<StartDuration> start_duration;
void *stream;
uint32_t pid;
std::string op_name; /**< Name of the operation. */
float cupti_api_call_time = 0l; /**< Time spent on CUPTI API calls for the operation in microseconds. */
float cupti_activity_time = 0l; /**< Time spent on CUPTI activities for the operation in microseconds. */
float op_host_cost_time = 0; /**< Host-side cost time for the operation in microseconds. */
int op_kernel_api_count = 0; /**< Number of kernel API calls for the operation. */
int op_kernel_count = 0; /**< Number of kernels launched for the operation. */
int op_count = 0; /**< Number of times the operation was executed. */
StartDuration tmp_start_duration; /**< Temporary start duration for the operation. */
std::vector<StartDuration> start_duration; /**< Vector of start durations for the operation. */
void *stream; /**< Stream associated with the operation. */
uint32_t pid; /**< Process ID associated with the operation. */
};
// Class to manage profiler settings and options
class ProfilerManager {
public:
static std::shared_ptr<ProfilerManager> &GetInstance();
@ -63,53 +58,49 @@ class ProfilerManager {
~ProfilerManager() = default;
ProfilerManager(const ProfilerManager &) = delete;
ProfilerManager &operator=(const ProfilerManager &) = delete;
bool GetProfilingEnableFlag() const;
void RecordOneStepStartEndInfo() const;
std::string GetProfilingOptions() const;
private:
static std::shared_ptr<ProfilerManager> profiler_manager_inst_;
bool GetProfilingEnableFlag() const; /**< Get the profiling enable flag. */
void RecordOneStepStartEndInfo() const; /**< Record one step start and end information. */
std::string GetProfilingOptions() const; /**< Get profiling options as a string. */
};
// Abstract base class for profiling
class Profiler {
public:
Profiler() = default;
virtual ~Profiler() = default;
virtual void Init(const std::string &profileDataPath) = 0;
virtual void Stop() = 0;
virtual void StepProfilingEnable(const bool enable_flag) = 0;
virtual void OpDataProducerEnd() = 0;
void RecordOneStepStartEndInfo();
bool GetEnableFlag() const { return enable_flag_; }
std::string ProfileDataPath() const { return profile_data_path_; }
void RecordOneStepStartEndInfo(std::string op_name);
std::pair<double, double> GetSingleOpLaunchTime() { return single_op_launch_start_time_end_time_; }
void SetSingleOpLaunchTime(const std::pair<double, double> &launch_start_end) {
single_op_launch_start_time_end_time_ = launch_start_end;
}
virtual void Init(const std::string &profileDataPath) = 0; /**< Initialize the profiler. */
virtual void Stop() = 0; /**< Stop the profiler. */
virtual void StepProfilingEnable(const bool enable_flag) = 0; /**< Enable or disable step profiling. */
virtual void OpDataProducerEnd() = 0; /**< Notify the end of operation data production. */
void RecordOneStepStartEndInfo(); /**< Record start and end information for one step. */
bool GetEnableFlag() const; /**< Get the enable flag for profiling. */
std::string ProfileDataPath() const; /**< Get the path for profile data storage. */
void RecordOneStepStartEndInfo(std::string op_name); /**< Record start and end information for one step of an operation. */
std::pair<double, double> GetSingleOpLaunchTime(); /**< Get the start and end time of a single operation launch. */
void SetSingleOpLaunchTime(const std::pair<double, double> &launch_start_end); /**< Set the start and end time of a single operation launch. */
protected:
void SetRunTimeData(const std::string &op_name, const float time_elapsed);
void SetRunTimeData(const std::string &op_name, const uint64_t start, const float duration);
uint64_t GetHostMonoTimeStamp() const;
// Get timestamp in us
uint64_t GetRealTimeStamp() const;
virtual void SaveProfileData() = 0;
virtual void ClearInst() = 0;
std::pair<double, double> single_op_launch_start_time_end_time_;
bool enable_flag_ = false;
bool has_find = false;
uint32_t iter_end_op_index = 0;
std::string profile_data_path_;
std::unordered_map<std::string, OpInfo> op_info_map_;
OneStepStartEndInfo step_start_end_info_;
std::vector<OneStepStartEndInfo> all_step_start_end_info_;
std::vector<std::string> step_start_end_info_vector_;
std::shared_mutex op_map_mutex_;
std::mutex record_mutex_;
bool init_flag_ = false;
void SetRunTimeData(const std::string &op_name, const float time_elapsed); /**< Set runtime data for an operation. */
void SetRunTimeData(const std::string &op_name, const uint64_t start, const float duration); /**< Set runtime data with start timestamp and duration for an operation. */
uint64_t GetHostMonoTimeStamp() const; /**< Get the host monotonic timestamp. */
uint64_t GetRealTimeStamp() const; /**< Get the real timestamp in microseconds. */
virtual void SaveProfileData() = 0; /**< Save the profile data. */
virtual void ClearInst() = 0; /**< Clear the profiler instance. */
std::pair<double, double> single_op_launch_start_time_end_time_; /**< Pair of start and end times for a single operation launch. */
bool enable_flag_ = false; /**< Flag indicating whether profiling is enabled. */
bool has_find = false; /**< Flag indicating whether an operation has been found. */
uint32_t iter_end_op_index = 0; /**< Index of iteration end operation. */
std::string profile_data_path_; /**< Path for profile data storage. */
std::unordered_map<std::string, OpInfo> op_info_map_; /**< Map to store profiling information for operations. */
OneStepStartEndInfo step_start_end_info_; /**< Information about the start and end of one step. */
std::vector<OneStepStartEndInfo> all_step_start_end_info_; /**< Vector of start and end information for all steps. */
std::vector<std::string> step_start_end_info_vector_; /**< Vector of start and end information for steps. */
std::shared_mutex op_map_mutex_; /**< Shared mutex for locking operation information map. */
std::mutex record_mutex_; /**< Mutex for recording information. */
bool init_flag_ = false; /**< Flag indicating whether the profiler has been initialized. */
};
} // namespace profiler
} // namespace mindspore