Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[PROFILER] Add configuration information to profiler #11530

Merged
merged 1 commit into from
Jun 6, 2022
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
17 changes: 14 additions & 3 deletions include/tvm/runtime/profiling.h
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,7 @@
#define TVM_RUNTIME_PROFILING_H_

#include <tvm/runtime/c_runtime_api.h>
#include <tvm/runtime/container/map.h>
#include <tvm/runtime/device_api.h>
#include <tvm/runtime/object.h>
#include <tvm/runtime/packed_func.h>
Expand Down Expand Up @@ -192,6 +193,11 @@ class ReportNode : public Object {
* because these metrics include the overhead of the executor.
*/
Map<String, Map<String, ObjectRef>> device_metrics;
/*! Configuration used for this profiling run. Includes number of threads, executor.
*
* Values must be an object type that can be used with device_metrics.
*/
Map<String, ObjectRef> configuration;
/*! \brief Output `calls` in CSV format.
*
* Note that this does not include `device_metrics`, it only includes per-call metrics.
Expand Down Expand Up @@ -255,9 +261,11 @@ class Report : public ObjectRef {
/*! Construct a Report from a set of calls (with associated metrics) and per-device metrics.
* \param calls Function calls and associated metrics.
* \param device_metrics Per-device metrics for overall execution.
* \param configuration Configuration data specific to this profiling run.
*/
explicit Report(Array<Map<String, ObjectRef>> calls,
Map<String, Map<String, ObjectRef>> device_metrics);
Map<String, Map<String, ObjectRef>> device_metrics,
Map<String, ObjectRef> configuration);

/*! Deserialize a Report from a JSON object. Needed for sending the report over RPC.
* \param json Serialized json report from `ReportNode::AsJSON`.
Expand Down Expand Up @@ -366,8 +374,10 @@ class Profiler {
* \param devs The list of devices the profiler will be running on. Should
* include all devices used by profiled operators.
* \param metric_collectors Additional `MetricCollector`s to use with this profiler.
* \param configuration Additional configuration data to add to the outputted profiling report.
*/
explicit Profiler(std::vector<Device> devs, std::vector<MetricCollector> metric_collectors);
explicit Profiler(std::vector<Device> devs, std::vector<MetricCollector> metric_collectors,
std::unordered_map<String, ObjectRef> configuration = {});
/*! \brief Start the profiler.
*
* This function should only be called once per object.
Expand Down Expand Up @@ -400,7 +410,7 @@ class Profiler {
* \returns A `Report` that can either be formatted as CSV (with `.AsCSV`)
* or as a human readable table (with `.AsTable`).
*/
profiling::Report Report(bool aggregate = true, bool sort = true);
profiling::Report Report();
/*! \brief Check if the profiler is currently running.
* \returns Whether or not the profiler is running.
*/
Expand All @@ -412,6 +422,7 @@ class Profiler {
std::vector<CallFrame> calls_;
std::stack<CallFrame> in_flight_;
std::vector<MetricCollector> collectors_;
std::unordered_map<String, ObjectRef> configuration_;
};

/* \brief A duration in time. */
Expand Down
11 changes: 9 additions & 2 deletions python/tvm/runtime/profiling/__init__.py
Original file line number Diff line number Diff line change
Expand Up @@ -36,7 +36,10 @@ class Report(Object):
"""

def __init__(
self, calls: Sequence[Dict[str, Object]], device_metrics: Dict[str, Dict[str, Object]]
self,
calls: Sequence[Dict[str, Object]],
device_metrics: Dict[str, Dict[str, Object]],
configuration: Dict[str, Object],
):
"""Construct a profiling report from a list of metrics and per-device metrics.

Expand All @@ -47,8 +50,12 @@ def __init__(

device_metrics : Dict[str, Dict[str, Object]]
Per device metrics.

configuration : Dict[str, Object]
Configuration of TVM for this profiling run. Includes number of
threads, executor.
"""
self.__init_handle_by_constructor__(_ffi_api.Report, calls, device_metrics)
self.__init_handle_by_constructor__(_ffi_api.Report, calls, device_metrics, configuration)

def csv(self):
"""Convert this profiling report into CSV format.
Expand Down
5 changes: 4 additions & 1 deletion python/tvm/utils/roofline.py
Original file line number Diff line number Diff line change
Expand Up @@ -400,7 +400,10 @@ def roofline_from_existing(
new_calls.append(call)
else:
new_calls.append(call)
return profiling.Report(new_calls, report.device_metrics)
new_configuration = dict(report.configuration.items())
new_configuration["Estimated Peak FMA FLOP/s"] = profiling.Ratio(peak_flops)
new_configuration["Estimated Peak Bandwidth (byte/second)"] = profiling.Ratio(peak_bandwidth)
return profiling.Report(new_calls, report.device_metrics, new_configuration)


def roofline_analysis(
Expand Down
1 change: 1 addition & 0 deletions src/node/structural_hash.cc
Original file line number Diff line number Diff line change
Expand Up @@ -521,6 +521,7 @@ struct ReportNodeTrait {
static void VisitAttrs(runtime::profiling::ReportNode* report, AttrVisitor* attrs) {
attrs->Visit("calls", &report->calls);
attrs->Visit("device_metrics", &report->device_metrics);
attrs->Visit("configuration", &report->configuration);
}
static constexpr std::nullptr_t SEqualReduce = nullptr;
static constexpr std::nullptr_t SHashReduce = nullptr;
Expand Down
2 changes: 1 addition & 1 deletion src/runtime/graph_executor/debug/graph_executor_debug.cc
Original file line number Diff line number Diff line change
Expand Up @@ -294,7 +294,7 @@ class GraphExecutorDebug : public GraphExecutor {
*/
profiling::Report Profile(Array<profiling::MetricCollector> collectors) {
std::vector<profiling::MetricCollector> cs(collectors.begin(), collectors.end());
profiling::Profiler prof(devices_, cs);
profiling::Profiler prof(devices_, cs, {{String("Executor"), String("Graph")}});

// warm up. 1 iteration does not seem enough.
for (int i = 0; i < 3; i++) {
Expand Down
111 changes: 74 additions & 37 deletions src/runtime/profiling.cc
Original file line number Diff line number Diff line change
Expand Up @@ -105,8 +105,9 @@ TVM_REGISTER_GLOBAL("profiling.start_timer").set_body_typed(Timer::Start);

namespace profiling {

Profiler::Profiler(std::vector<Device> devs, std::vector<MetricCollector> metric_collectors)
: devs_(devs), collectors_(metric_collectors) {
Profiler::Profiler(std::vector<Device> devs, std::vector<MetricCollector> metric_collectors,
std::unordered_map<String, ObjectRef> configuration)
: devs_(devs), collectors_(metric_collectors), configuration_(configuration) {
is_running_ = false;
std::vector<DeviceWrapper> wrapped_devs;
for (auto dev : devs) {
Expand All @@ -117,6 +118,9 @@ Profiler::Profiler(std::vector<Device> devs, std::vector<MetricCollector> metric
}
// reset the thread pool so that PAPI eventset hooks are set in all threads.
threading::ResetThreadPool();

configuration_[String("Number of threads")] =
ObjectRef(make_object<CountNode>(threading::NumThreads()));
}

void Profiler::Start() {
Expand Down Expand Up @@ -279,7 +283,7 @@ String ReportNode::AsCSV() const {
}

namespace {
void print_metric(std::ostream& os, ObjectRef o) {
void metric_as_json(std::ostream& os, ObjectRef o) {
if (o.as<StringObj>()) {
os << "{\"string\":"
<< "\"" << Downcast<String>(o) << "\""
Expand Down Expand Up @@ -309,13 +313,14 @@ String ReportNode::AsJSON() const {
// value we want to print. Instead we construct the json by hand because it
// is easier.
s << "{";

s << "\"calls\":[";
for (size_t i = 0; i < calls.size(); i++) {
size_t j = 0;
s << "{";
for (const auto& kv : calls[i]) {
s << "\"" << kv.first << "\":";
print_metric(s, kv.second);
metric_as_json(s, kv.second);
if (j < calls[i].size() - 1) {
s << ",";
}
Expand All @@ -326,15 +331,16 @@ String ReportNode::AsJSON() const {
s << ",";
}
}
s << "],";
s << "],"; // end calls

s << "\"device_metrics\":{";
size_t i = 0;
for (const auto& dev_kv : device_metrics) {
size_t j = 0;
s << "\"" << dev_kv.first << "\":{";
for (const auto& metric_kv : dev_kv.second) {
s << "\"" << metric_kv.first << "\":";
print_metric(s, metric_kv.second);
metric_as_json(s, metric_kv.second);
if (j < dev_kv.second.size() - 1) {
s << ",";
}
Expand All @@ -346,7 +352,20 @@ String ReportNode::AsJSON() const {
}
i++;
}
s << "}}";
s << "},"; // end device metrics

s << "\"configuration\":{";
size_t k = 0;
for (const auto& kv : configuration) {
s << "\"" << kv.first << "\":";
metric_as_json(s, kv.second);
if (k < configuration.size() - 1) {
s << ",";
}
k++;
}
s << "}"; // end configuration
s << "}";
return s.str();
}

Expand Down Expand Up @@ -395,6 +414,35 @@ ObjectRef AggregateMetric(const std::vector<ObjectRef>& metrics) {
}
}

static String print_metric(ObjectRef metric) {
std::string val;
if (metric.as<CountNode>()) {
std::stringstream s;
s.imbue(std::locale("")); // for 1000s seperators
s << std::fixed << metric.as<CountNode>()->value;
val = s.str();
} else if (metric.as<DurationNode>()) {
std::stringstream s;
s.imbue(std::locale("")); // for 1000s seperators
s << std::fixed << std::setprecision(2) << metric.as<DurationNode>()->microseconds;
val = s.str();
} else if (metric.as<PercentNode>()) {
std::stringstream s;
s << std::fixed << std::setprecision(2) << metric.as<PercentNode>()->percent;
val = s.str();
} else if (metric.as<RatioNode>()) {
std::stringstream s;
s.imbue(std::locale("")); // for 1000s seperators
s << std::setprecision(2) << metric.as<RatioNode>()->ratio;
val = s.str();
} else if (metric.as<StringObj>()) {
val = Downcast<String>(metric);
} else {
LOG(FATAL) << "Cannot print metric of type " << metric->GetTypeKey();
}
return val;
}

String ReportNode::AsTable(bool sort, bool aggregate, bool compute_col_sums) const {
// aggregate calls by op hash (or op name if hash is not set) + argument shapes
std::vector<Map<String, ObjectRef>> aggregated_calls;
Expand Down Expand Up @@ -533,30 +581,7 @@ String ReportNode::AsTable(bool sort, bool aggregate, bool compute_col_sums) con
// fill empty data with empty strings
cols[i].push_back("");
} else {
std::string val;
if ((*it).second.as<CountNode>()) {
std::stringstream s;
s.imbue(std::locale("")); // for 1000s seperators
s << std::fixed << (*it).second.as<CountNode>()->value;
val = s.str();
} else if ((*it).second.as<DurationNode>()) {
std::stringstream s;
s.imbue(std::locale("")); // for 1000s seperators
s << std::fixed << std::setprecision(2) << (*it).second.as<DurationNode>()->microseconds;
val = s.str();
} else if ((*it).second.as<PercentNode>()) {
std::stringstream s;
s << std::fixed << std::setprecision(2) << (*it).second.as<PercentNode>()->percent;
val = s.str();
} else if ((*it).second.as<RatioNode>()) {
std::stringstream s;
s.imbue(std::locale("")); // for 1000s seperators
s << std::setprecision(2) << (*it).second.as<RatioNode>()->ratio;
val = s.str();
} else if ((*it).second.as<StringObj>()) {
val = Downcast<String>((*it).second);
}
cols[i].push_back(val);
cols[i].push_back(print_metric((*it).second));
}
}
}
Expand Down Expand Up @@ -592,14 +617,20 @@ String ReportNode::AsTable(bool sort, bool aggregate, bool compute_col_sums) con
}
s << std::endl;
}

// Add configuration information. It will not be aligned with the columns.
s << std::endl << "Configuration" << std::endl << "-------------" << std::endl;
for (auto kv : configuration) {
s << kv.first << ": " << print_metric(kv.second) << std::endl;
}
return s.str();
}

std::string DeviceString(Device dev) {
return DeviceName(dev.device_type) + std::to_string(dev.device_id);
}

Report Profiler::Report(bool aggregate, bool sort) {
Report Profiler::Report() {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Interesting these variables were never used

// sync all timers and normalize rows
std::vector<std::unordered_map<String, ObjectRef>> rows;
for (auto& cf : calls_) {
Expand Down Expand Up @@ -638,14 +669,16 @@ Report Profiler::Report(bool aggregate, bool sort) {
converted_rows.push_back(row);
}

return profiling::Report(converted_rows, device_metrics);
return profiling::Report(converted_rows, device_metrics, configuration_);
}

Report::Report(Array<Map<String, ObjectRef>> calls,
Map<String, Map<String, ObjectRef>> device_metrics) {
Map<String, Map<String, ObjectRef>> device_metrics,
Map<String, ObjectRef> configuration) {
auto node = make_object<ReportNode>();
node->calls = std::move(calls);
node->device_metrics = std::move(device_metrics);
node->configuration = std::move(configuration);
data_ = std::move(node);
}

Expand Down Expand Up @@ -697,6 +730,7 @@ Report Report::FromJSON(String json) {
std::string key;
Array<Map<String, ObjectRef>> calls;
Map<String, Map<String, ObjectRef>> device_metrics;
Map<String, ObjectRef> configuration;

reader.BeginObject();
while (reader.NextObjectItem(&key)) {
Expand All @@ -713,10 +747,12 @@ Report Report::FromJSON(String json) {
device_metrics.Set(device_name, parse_metrics(&reader));
}
// reader.EndObject();
} else if (key == "configuration") {
configuration = parse_metrics(&reader);
}
}

return Report(calls, device_metrics);
return Report(calls, device_metrics, configuration);
}

TVM_REGISTER_OBJECT_TYPE(DurationNode);
Expand Down Expand Up @@ -855,8 +891,9 @@ PackedFunc WrapTimeEvaluator(PackedFunc pf, Device dev, int number, int repeat,

TVM_REGISTER_GLOBAL("runtime.profiling.Report")
.set_body_typed([](Array<Map<String, ObjectRef>> calls,
Map<String, Map<String, ObjectRef>> device_metrics) {
return Report(calls, device_metrics);
Map<String, Map<String, ObjectRef>> device_metrics,
Map<String, ObjectRef> configuration) {
return Report(calls, device_metrics, configuration);
});

TVM_REGISTER_GLOBAL("runtime.profiling.Count").set_body_typed([](int64_t count) {
Expand Down
6 changes: 3 additions & 3 deletions src/runtime/vm/profiler/vm.cc
Original file line number Diff line number Diff line change
Expand Up @@ -58,9 +58,9 @@ PackedFunc VirtualMachineDebug::GetFunction(const std::string& name,
// on remotes, we accept a nullptr for collectors.
if (collectors.defined()) {
std::vector<profiling::MetricCollector> cs(collectors.begin(), collectors.end());
prof_ = profiling::Profiler(devices, cs);
prof_ = profiling::Profiler(devices, cs, {{String("Executor"), String("VM")}});
} else {
prof_ = profiling::Profiler(devices, {});
prof_ = profiling::Profiler(devices, {}, {{String("Executor"), String("VM")}});
}

auto invoke = VirtualMachine::GetFunction("invoke", sptr_to_self);
Expand All @@ -77,7 +77,7 @@ PackedFunc VirtualMachineDebug::GetFunction(const std::string& name,
return report;
});
} else if (name == "profile_rpc") {
// We cannot return a Report over RPC because TMV RPC mechanism only
// We cannot return a Report over RPC because TVM RPC mechanism only
// supports a subset of Object classes. Instead we serialize it on the
// remote (here) and deserialize it on the other end.
return TypedPackedFunc<std::string(std::string)>([sptr_to_self, this](std::string arg_name) {
Expand Down
3 changes: 3 additions & 0 deletions tests/python/unittest/test_runtime_profiling.py
Original file line number Diff line number Diff line change
Expand Up @@ -69,6 +69,7 @@ def test_vm(target, dev):
assert "Total" in str(report)
assert "AllocTensorReg" in str(report)
assert "AllocStorage" in str(report)
assert report.configuration["Executor"] == "VM"

csv = read_csv(report)
assert "Hash" in csv.keys()
Expand Down Expand Up @@ -102,6 +103,7 @@ def test_graph_executor(target, dev):
assert "fused_nn_softmax" in str(report)
assert "Total" in str(report)
assert "Hash" in str(report)
assert "Graph" in str(report)


@tvm.testing.parametrize_targets("cuda", "llvm")
Expand Down Expand Up @@ -147,6 +149,7 @@ def test_json():
parsed = json.loads(report.json())
assert "device_metrics" in parsed
assert "calls" in parsed
assert "configuration" in parsed
assert "Duration (us)" in parsed["calls"][0]
assert "microseconds" in parsed["calls"][0]["Duration (us)"]
assert len(parsed["calls"]) > 0
Expand Down