Skip to content

Commit 69974f3

Browse files
SS-JIAssjia
andauthored
[ET-VK] Pass detailed op information to event tracer (pytorch#16266)
Stack from [ghstack](https://github.com/ezyang/ghstack) (oldest at bottom): * pytorch#16267 * __->__ pytorch#16266 ## Context Currently, when using the event tracer API to log shader execution times, only the shader name is recorded as the event name. However, this provides very minimal context to use when interpreting profiling data. For example, if we see that a convolution shader is running slow, it's is impossible to know from the profiling data alone what the input/output sizes were, what convolution parameters (i.e. stride/padding/dilation) were used, etc. ## Changes This diff makes it so that for each shader dispatch, a JSON is recorded as the event name instead which contains the complete details of all the arguments the operator was invoked with. The JSON will look something like ```json { "name": "aten.where.self", "args": [ { "type": "TENSOR", "value_ref": 25, "dtype": "Bool", "sizes": [ 1, 1, 1, 8 ], "storage": "TEXTURE_3D", "packed_dim": 2 }, { "type": "TENSOR", "value_ref": 30, "dtype": "Float", "sizes": [ 1, 6, 43, 8 ], "storage": "TEXTURE_3D", "packed_dim": 2 }, { "type": "TENSOR", "value_ref": 32, "dtype": "Float", "sizes": [ 1, 6, 43, 8 ], "storage": "TEXTURE_3D", "packed_dim": 2 }, { "type": "TENSOR", "value_ref": 33, "dtype": "Float", "sizes": [ 1, 6, 43, 8 ], "storage": "TEXTURE_3D", "packed_dim": 2 } ] } ``` Then, when processing the profiling data, the JSON can be post-processed to provide useful information to contextualize the shader execution times, for example: * Memory Throughput * GFLOPS Differential Revision: [D84646748](https://our.internmc.facebook.com/intern/diff/D84646748/) Co-authored-by: ssjia <ssjia@devvm1479.ncg0.facebook.com>
1 parent 54b3f56 commit 69974f3

8 files changed

Lines changed: 148 additions & 6 deletions

File tree

backends/vulkan/runtime/VulkanBackend.cpp

Lines changed: 14 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -19,6 +19,7 @@
1919
#include <executorch/runtime/core/error.h>
2020
#include <executorch/runtime/core/evalue.h>
2121
#ifdef ET_EVENT_TRACER_ENABLED
22+
#include <executorch/backends/vulkan/runtime/graph/Logging.h>
2223
#include <executorch/runtime/core/event_tracer_hooks_delegate.h>
2324
#endif // ET_EVENT_TRACER_ENABLED
2425
#include <executorch/runtime/core/exec_aten/util/tensor_util.h>
@@ -422,6 +423,13 @@ class GraphBuilder {
422423
args.push_back(get_fb_id_valueref(static_cast<int>(arg_fb_id)));
423424
}
424425

426+
#ifdef ET_EVENT_TRACER_ENABLED
427+
std::string operator_json =
428+
make_operator_json(compute_graph_, op_name, args);
429+
set_and_get_current_operator_json(operator_json);
430+
get_current_operator_count(true);
431+
#endif // ET_EVENT_TRACER_ENABLED
432+
425433
auto vkFn = VK_GET_OP_FN(op_name);
426434
vkFn(*compute_graph_, args);
427435
}
@@ -431,6 +439,9 @@ class GraphBuilder {
431439
for (const uint32_t fb_id : *flatbuffer_->output_ids()) {
432440
const ValueRef ref = get_fb_id_valueref(fb_id);
433441
if (compute_graph_->val_is_tensor(ref)) {
442+
#ifdef ET_EVENT_TRACER_ENABLED
443+
get_current_operator_count(true);
444+
#endif // ET_EVENT_TRACER_ENABLED
434445
compute_graph_->set_output_tensor(
435446
ref, get_staging_scalar_type_of(fb_id));
436447
} else {
@@ -694,16 +705,14 @@ class VulkanBackend final : public ::executorch::runtime::BackendInterface {
694705
compute_graph->context()->querypool().extract_results();
695706
for (const auto& r :
696707
compute_graph->context()->querypool().get_shader_timestamp_data()) {
697-
std::string event_name =
698-
r.kernel_name + "_" + std::to_string(r.dispatch_id);
708+
std::string event_name = "{" + r.kernel_name +
709+
", \"dispatch_id\": " + std::to_string(r.dispatch_id) + "}";
699710
event_tracer_log_profiling_delegate(
700711
event_tracer,
701712
event_name.c_str(),
702713
/* delegate_debug_id = */ -1,
703714
r.start_time_ns,
704-
r.end_time_ns,
705-
(void*)(&r.metadata),
706-
sizeof(r.metadata));
715+
r.end_time_ns);
707716
}
708717
#endif // ET_EVENT_TRACER_ENABLED
709718

backends/vulkan/runtime/graph/ComputeGraph.cpp

Lines changed: 18 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -15,6 +15,24 @@
1515

1616
#include <executorch/backends/vulkan/runtime/graph/ops/utils/StagingUtils.h>
1717

18+
#ifdef ET_EVENT_TRACER_ENABLED
19+
std::string& set_and_get_current_operator_json(const std::string& json) {
20+
static std::string current_operator_json;
21+
if (json.size() > 0) {
22+
current_operator_json = json;
23+
}
24+
return current_operator_json;
25+
}
26+
27+
size_t get_current_operator_count(const bool increment) {
28+
static int count = 0;
29+
if (increment) {
30+
count++;
31+
}
32+
return count;
33+
}
34+
#endif /* ET_EVENT_TRACER_ENABLED */
35+
1836
namespace vkcompute {
1937

2038
//

backends/vulkan/runtime/graph/ComputeGraph.h

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -25,6 +25,11 @@
2525
#include <executorch/backends/vulkan/runtime/graph/ops/ExecuteNode.h>
2626
#include <executorch/backends/vulkan/runtime/graph/ops/PrepackNode.h>
2727

28+
#ifdef ET_EVENT_TRACER_ENABLED
29+
std::string& set_and_get_current_operator_json(const std::string& json);
30+
size_t get_current_operator_count(const bool increment = false);
31+
#endif
32+
2833
namespace vkcompute {
2934

3035
// Define valid scalar types that the Value class can

backends/vulkan/runtime/graph/Logging.cpp

Lines changed: 76 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,82 @@
1717

1818
namespace vkcompute {
1919

20+
std::ostream& operator<<(std::ostream& os, const std::vector<int64_t>& sizes) {
21+
if (sizes.size() == 0) {
22+
os << "[]";
23+
return os;
24+
}
25+
os << "[";
26+
for (int i = 0; i < sizes.size() - 1; ++i) {
27+
os << sizes.at(i) << ", ";
28+
}
29+
os << sizes.at(sizes.size() - 1);
30+
os << "]";
31+
return os;
32+
}
33+
34+
std::string make_arg_json(ComputeGraph* const compute_graph, ValueRef arg) {
35+
std::stringstream ss;
36+
ss << "{\"type\": \"" << compute_graph->get_val_type(arg) << "\", ";
37+
ss << "\"value_ref\": " << arg;
38+
if (compute_graph->val_is_tensor(arg)) {
39+
ss << ", \"dtype\": \"";
40+
ss << compute_graph->dtype_of(arg) << "\"";
41+
ss << ", \"sizes\": ";
42+
ss << compute_graph->sizes_of(arg);
43+
ss << ", \"storage\": \"";
44+
ss << compute_graph->storage_type_of(arg) << "\"";
45+
ss << ", \"packed_dim\": ";
46+
ss << compute_graph->packed_dim_of(arg);
47+
} else if (compute_graph->val_is_tref(arg)) {
48+
ss << ", \"sizes\": ";
49+
ss << compute_graph->sizes_of(arg);
50+
ss << ", \"dtype\": \"";
51+
ss << compute_graph->dtype_of(arg) << "\"";
52+
} else if (compute_graph->val_is_value_list(arg)) {
53+
ValueListPtr val_list = compute_graph->get_value_list(arg);
54+
ss << ", \"values\": [";
55+
for (const ValueRef& value : *val_list) {
56+
ss << value << ", ";
57+
}
58+
ss << "]";
59+
} else if (compute_graph->val_is_int_list(arg)) {
60+
ss << ", \"values\": ";
61+
ss << *compute_graph->get_int_list(arg);
62+
} else if (compute_graph->val_is_int(arg)) {
63+
ss << ", \"value\": ";
64+
ss << compute_graph->get_int(arg);
65+
} else if (compute_graph->val_is_double(arg)) {
66+
ss << ", \"value\": ";
67+
ss << compute_graph->get_double(arg);
68+
} else if (compute_graph->val_is_bool(arg)) {
69+
ss << ", \"value\": ";
70+
ss << compute_graph->get_bool(arg);
71+
} else if (compute_graph->val_is_symint(arg)) {
72+
ss << ", \"value\": ";
73+
ss << compute_graph->read_symint(arg);
74+
}
75+
ss << "}";
76+
77+
return ss.str();
78+
}
79+
80+
std::string make_operator_json(
81+
ComputeGraph* const compute_graph,
82+
std::string& op_name,
83+
std::vector<ValueRef>& args) {
84+
std::stringstream ss;
85+
ss << "\"name\": \"" << op_name << "\", \"args\": [";
86+
for (size_t i = 0; i < args.size(); ++i) {
87+
ss << make_arg_json(compute_graph, args[i]);
88+
if (i + 1 < args.size()) {
89+
ss << ", ";
90+
}
91+
}
92+
ss << "]";
93+
return ss.str();
94+
}
95+
2096
void ComputeGraph::print_readable() {
2197
std::set<ValueRef> input_set;
2298
for (const IOValueRef& io_val : inputs()) {

backends/vulkan/runtime/graph/Logging.h

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,8 @@
1010

1111
#include <executorch/backends/vulkan/runtime/api/api.h>
1212

13+
#include <executorch/backends/vulkan/runtime/graph/ComputeGraph.h>
14+
1315
#include <optional>
1416
#include <ostream>
1517
#include <vector>
@@ -42,6 +44,8 @@ inline std::ostream& operator<<(std::ostream& os, const utils::ivec4& v) {
4244
return utils::operator<<(os, v);
4345
}
4446

47+
std::ostream& operator<<(std::ostream& os, const std::vector<int64_t>& sizes);
48+
4549
template <typename T>
4650
inline std::ostream& operator<<(std::ostream& os, const std::optional<T>& opt) {
4751
os << "[";
@@ -52,4 +56,11 @@ inline std::ostream& operator<<(std::ostream& os, const std::optional<T>& opt) {
5256
return os;
5357
}
5458

59+
std::string make_arg_json(ComputeGraph* const compute_graph, ValueRef arg);
60+
61+
std::string make_operator_json(
62+
ComputeGraph* const compute_graph,
63+
std::string& op_name,
64+
std::vector<ValueRef>& args);
65+
5566
} // namespace vkcompute

backends/vulkan/runtime/graph/ops/DispatchNode.cpp

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -60,8 +60,21 @@ void DispatchNode::encode(ComputeGraph* graph) {
6060

6161
write_push_constant_data();
6262

63+
#ifdef ET_EVENT_TRACER_ENABLED
64+
std::string event_name;
65+
if (!operator_json.empty()) {
66+
event_name += "\"operator\": {" + operator_json + "}, ";
67+
}
68+
event_name += "\"kernel_name\": \"" + shader_.kernel_name + "\", ";
69+
event_name += "\"operator_id\": " + std::to_string(operator_count);
70+
#endif
71+
6372
context->report_shader_dispatch_start(
73+
#ifdef ET_EVENT_TRACER_ENABLED
74+
event_name,
75+
#else
6476
shader_.kernel_name,
77+
#endif
6578
global_workgroup_size_,
6679
local_workgroup_size_,
6780
node_id_);

backends/vulkan/runtime/graph/ops/ExecuteNode.cpp

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -20,7 +20,12 @@ ExecuteNode::ExecuteNode(
2020
resize_args_(resize_args),
2121
args_(args),
2222
name_(name),
23-
has_data_dependent_shape_(has_data_dependent_shape) {}
23+
has_data_dependent_shape_(has_data_dependent_shape) {
24+
#ifdef ET_EVENT_TRACER_ENABLED
25+
operator_json = set_and_get_current_operator_json("");
26+
operator_count = get_current_operator_count();
27+
#endif
28+
}
2429

2530
bool ExecuteNode::trigger_resize(ComputeGraph* graph) {
2631
bool any_arg_updated = was_any_arg_updated(graph);

backends/vulkan/runtime/graph/ops/ExecuteNode.h

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -89,6 +89,11 @@ class ExecuteNode {
8989
const std::vector<ArgGroup> args_;
9090
const std::string name_;
9191
bool has_data_dependent_shape_ = false;
92+
93+
#ifdef ET_EVENT_TRACER_ENABLED
94+
std::string operator_json;
95+
size_t operator_count = 0;
96+
#endif
9297
};
9398

9499
} // namespace vkcompute

0 commit comments

Comments
 (0)