From 59413c10d86e10d948af0bc56c1c5a2fa572c427 Mon Sep 17 00:00:00 2001 From: Andrew Reusch Date: Thu, 7 Jan 2021 14:01:32 -0800 Subject: [PATCH 1/7] Add FrontendTestModule, a Module which can have Python functions. --- python/tvm/support.py | 24 +++++++++++++++++++++ src/support/ffi_testing.cc | 43 ++++++++++++++++++++++++++++++++++++++ 2 files changed, 67 insertions(+) diff --git a/python/tvm/support.py b/python/tvm/support.py index e0d688abb9e8..4f34b1acf458 100644 --- a/python/tvm/support.py +++ b/python/tvm/support.py @@ -15,7 +15,10 @@ # specific language governing permissions and limitations # under the License. """Support infra of TVM.""" +import ctypes import tvm._ffi +from .runtime.module import Module +from . import get_global_func def libinfo(): @@ -29,4 +32,25 @@ def libinfo(): return {k: v for k, v in GetLibInfo().items()} # pylint: disable=unnecessary-comprehension +class FrontendTestModule(Module): + + def __init__(self, entry_name=None): + underlying_mod = get_global_func("testing.FrontendTestModule")() + handle = underlying_mod.handle + + # Set handle to NULL to avoid cleanup in c++ runtime, transferring ownership. + # Both cython and ctypes FFI use c_void_p, so this is safe to assign here. + underlying_mod.handle = ctypes.c_void_p(0) + + super(FrontendTestModule, self).__init__(handle) + if entry_name is not None: + self.entry_name = entry_name + + def add_function(self, name, func): + self.get_function("__add_function")(name, func) + + def __setitem__(self, key, value): + self.add_function(key, value) + + tvm._ffi._init_api("support", __name__) diff --git a/src/support/ffi_testing.cc b/src/support/ffi_testing.cc index 839f52968b82..b9d19a8ce049 100644 --- a/src/support/ffi_testing.cc +++ b/src/support/ffi_testing.cc @@ -23,6 +23,7 @@ */ #include #include +#include #include #include #include @@ -99,4 +100,46 @@ TVM_REGISTER_GLOBAL("testing.object_use_count").set_body([](TVMArgs args, TVMRet // and get another value. *ret = (obj.use_count() - 1); }); + +class FrontendTestModuleNode : public runtime::ModuleNode { + public: + virtual const char* type_key() const { + return "frontend_test"; + } + + static constexpr const char* kAddFunctionName = "__add_function"; + + virtual PackedFunc GetFunction(const std::string& name, const ObjectPtr& sptr_to_self); + + private: + std::unordered_map functions_; +}; + +constexpr const char* FrontendTestModuleNode::kAddFunctionName; + +PackedFunc FrontendTestModuleNode::GetFunction(const std::string& name, const ObjectPtr& sptr_to_self) { + if (name == kAddFunctionName) { + return TypedPackedFunc( + [this,sptr_to_self](std::string func_name, PackedFunc pf) { + CHECK_NE(func_name, kAddFunctionName) + << "func_name: cannot be special function " << kAddFunctionName; + functions_[func_name] = pf; + }); + } + + auto it = functions_.find(name); + if (it == functions_.end()) { + return PackedFunc(); + } + + return it->second; +} + +runtime::Module NewFrontendTestModule() { + auto n = make_object(); + return runtime::Module(n); +} + +TVM_REGISTER_GLOBAL("testing.FrontendTestModule").set_body_typed(NewFrontendTestModule); + } // namespace tvm From a761794ea80652abf140f8d327549ebbf2e4f0bd Mon Sep 17 00:00:00 2001 From: Andrew Reusch Date: Thu, 7 Jan 2021 14:02:02 -0800 Subject: [PATCH 2/7] fix units and use of scientific notation in debug_runtime variable names --- python/tvm/contrib/debugger/debug_result.py | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/python/tvm/contrib/debugger/debug_result.py b/python/tvm/contrib/debugger/debug_result.py index 0b9810e74bb1..3159ab34397a 100644 --- a/python/tvm/contrib/debugger/debug_result.py +++ b/python/tvm/contrib/debugger/debug_result.py @@ -212,7 +212,7 @@ def get_debug_result(self, sort_by_time=True): continue name = node["name"] shape = str(self._output_tensor_list[eid].shape) - time_us = round(time[0] * 1000000, 3) + time_us = round(time[0] * 1e6, 3) time_percent = round(((time[0] / total_time) * 100), 3) inputs = str(node["attrs"]["num_inputs"]) outputs = str(node["attrs"]["num_outputs"]) @@ -224,8 +224,8 @@ def get_debug_result(self, sort_by_time=True): # Sort on the basis of execution time. Prints the most expensive ops in the start. data = sorted(data, key=lambda x: x[2], reverse=True) # Insert a row for total time at the end. - rounded_total_time = round(total_time * 1000000, 3) - data.append(["Total_time", "-", rounded_total_time, "-", "-", "-", "-", "-"]) + rounded_total_time_us = round(total_time * 1e6, 3) + data.append(["Total_time", "-", rounded_total_time_us, "-", "-", "-", "-", "-"]) fmt = "" for i, _ in enumerate(header): From b0371cdfb552fd9d5e5597fbc321712fd63317f7 Mon Sep 17 00:00:00 2001 From: Andrew Reusch Date: Thu, 7 Jan 2021 14:02:34 -0800 Subject: [PATCH 3/7] remaining updates to formalize debug_runtime returns time in sec --- python/tvm/contrib/debugger/debug_runtime.py | 2 +- .../graph/debug/graph_runtime_debug.cc | 20 +++++++++---------- 2 files changed, 11 insertions(+), 11 deletions(-) diff --git a/python/tvm/contrib/debugger/debug_runtime.py b/python/tvm/contrib/debugger/debug_runtime.py index 4d2fab4358ba..289ac4c467e0 100644 --- a/python/tvm/contrib/debugger/debug_runtime.py +++ b/python/tvm/contrib/debugger/debug_runtime.py @@ -175,7 +175,7 @@ def _run_debug(self): Time consumed for each execution will be set as debug output. """ - self.debug_datum._time_list = [[float(t) * 1e-6] for t in self.run_individual(10, 1, 1)] + self.debug_datum._time_list = [[float(t)] for t in self.run_individual(10, 1, 1)] for i, node in enumerate(self.debug_datum.get_graph_nodes()): num_outputs = self.debug_datum.get_graph_node_output_num(node) for j in range(num_outputs): diff --git a/src/runtime/graph/debug/graph_runtime_debug.cc b/src/runtime/graph/debug/graph_runtime_debug.cc index 3353c117318b..0b8f39dd9f94 100644 --- a/src/runtime/graph/debug/graph_runtime_debug.cc +++ b/src/runtime/graph/debug/graph_runtime_debug.cc @@ -59,11 +59,11 @@ class GraphRuntimeDebug : public GraphRuntime { // warmup run GraphRuntime::Run(); std::string tkey = module_->type_key(); - std::vector time_per_op(op_execs_.size(), 0); + std::vector time_sec_per_op(op_execs_.size(), 0); if (tkey == "rpc") { // RPC modules rely on remote timing which implements the logic from the else branch. for (size_t index = 0; index < op_execs_.size(); ++index) { - time_per_op[index] += RunOpRPC(index, number, repeat, min_repeat_ms); + time_sec_per_op[index] += RunOpRPC(index, number, repeat, min_repeat_ms); } } else { for (int i = 0; i < repeat; ++i) { @@ -71,7 +71,7 @@ class GraphRuntimeDebug : public GraphRuntime { tbegin, tend; double duration_ms = 0.0; do { - std::fill(time_per_op.begin(), time_per_op.end(), 0); + std::fill(time_sec_per_op.begin(), time_sec_per_op.end(), 0); if (duration_ms > 0.0) { number = static_cast(std::max((min_repeat_ms / (duration_ms / number) + 1), number * 1.618)); // 1.618 is chosen by random @@ -80,7 +80,7 @@ class GraphRuntimeDebug : public GraphRuntime { for (int k = 0; k < number; k++) { for (size_t index = 0; index < op_execs_.size(); ++index) { if (op_execs_[index]) { - time_per_op[index] += RunOpHost(index); + time_sec_per_op[index] += RunOpHost(index); } } } @@ -92,19 +92,19 @@ class GraphRuntimeDebug : public GraphRuntime { LOG(INFO) << "Iteration: " << i; int op = 0; - for (size_t index = 0; index < time_per_op.size(); index++) { + for (size_t index = 0; index < time_sec_per_op.size(); index++) { if (op_execs_[index]) { - time_per_op[index] /= number; - LOG(INFO) << "Op #" << op++ << " " << GetNodeName(index) << ": " << time_per_op[index] - << " us/iter"; + time_sec_per_op[index] /= number; + LOG(INFO) << "Op #" << op++ << " " << GetNodeName(index) << ": " + << time_sec_per_op[index] * 1e6 << " us/iter"; } } } } std::ostringstream os; - for (size_t index = 0; index < time_per_op.size(); index++) { - os << time_per_op[index] << ","; + for (size_t index = 0; index < time_sec_per_op.size(); index++) { + os << time_sec_per_op[index] << ","; } return os.str(); } From 89cff6ec84e5297b86ffd3409b74d2e50d480987 Mon Sep 17 00:00:00 2001 From: Andrew Reusch Date: Thu, 7 Jan 2021 14:03:16 -0800 Subject: [PATCH 4/7] Add test for debug runtime output --- .../unittest/test_runtime_graph_debug.py | 45 ++++++++++++++++--- 1 file changed, 40 insertions(+), 5 deletions(-) diff --git a/tests/python/unittest/test_runtime_graph_debug.py b/tests/python/unittest/test_runtime_graph_debug.py index 8aeaf1a1a23b..1cb4c2621a3b 100644 --- a/tests/python/unittest/test_runtime_graph_debug.py +++ b/tests/python/unittest/test_runtime_graph_debug.py @@ -16,13 +16,19 @@ # under the License. import json import os +import re +import sys +import time + +import pytest + import tvm import tvm.testing from tvm import te import numpy as np from tvm import rpc from tvm.contrib import utils -from tvm.contrib.debugger import debug_runtime as graph_runtime +from tvm.contrib.debugger import debug_runtime @tvm.testing.requires_llvm @@ -60,8 +66,16 @@ def test_graph_simple(): def check_verify(): mlib = tvm.build(s, [A, B], "llvm", name="myadd") + + def myadd(*args): + to_return = mlib["myadd"](*args) + time.sleep(0.25) + return to_return + + mlib_proxy = tvm.support.FrontendTestModule() + mlib_proxy["myadd"] = myadd try: - mod = graph_runtime.create(graph, mlib, tvm.cpu(0)) + mod = debug_runtime.create(graph, mlib_proxy, tvm.cpu(0)) except ValueError: return @@ -92,6 +106,27 @@ def check_verify(): # Verify the tensors are dumped assert len(os.listdir(directory)) > 1 + debug_lines = mod.debug_datum.get_debug_result().split('\n') + def split_debug_line(i): + to_return = re.split(r" [ ]*", debug_lines[i]) + assert to_return[-1] == "" + to_return = to_return[:-1] # strip empty trailing part + return to_return + + assert split_debug_line(0) == ["Node Name", "Ops", "Time(us)", "Time(%)", "Shape", "Inputs", "Outputs"] + myadd_lines = split_debug_line(2) + assert myadd_lines[0] == "add" + assert myadd_lines[1] == "myadd" + runtime_sec = float(myadd_lines[2]) / 1e6 # printed in us + + # Ensure runtime is at least the sleep time and less than a unit prefix order of magnitude. + # Here we just care that the prefix is correct. + assert runtime_sec > 0.25 and runtime_sec < 0.25 * 1000 + + total_lines = split_debug_line(3) + assert total_lines[0] == "Total_time" + assert total_lines[2] == myadd_lines[2] + CHROME_TRACE_FILE_NAME = "_tvmdbg_execution_trace.json" assert os.path.exists(os.path.join(directory, CHROME_TRACE_FILE_NAME)) @@ -127,9 +162,9 @@ def check_remote(): remote.upload(path_dso) mlib = remote.load_module("dev_lib.so") try: - mod = graph_runtime.create(graph, mlib, remote.cpu(0)) + mod = debug_runtime.create(graph, mlib, remote.cpu(0)) except ValueError: - print("Skip because debug graph_runtime not enabled") + print("Skip because debug runtime not enabled") return a = np.random.uniform(size=(n,)).astype(A.dtype) mod.run(x=tvm.nd.array(a, ctx)) @@ -142,4 +177,4 @@ def check_remote(): if __name__ == "__main__": - test_graph_simple() + sys.exit(pytest.main([__file__] + sys.argv[1:])) From 33bff20931232a82b1ea97494516e51178ff10b9 Mon Sep 17 00:00:00 2001 From: Andrew Reusch Date: Thu, 7 Jan 2021 14:03:47 -0800 Subject: [PATCH 5/7] black format --- python/tvm/support.py | 1 - tests/python/unittest/test_runtime_graph_debug.py | 13 +++++++++++-- 2 files changed, 11 insertions(+), 3 deletions(-) diff --git a/python/tvm/support.py b/python/tvm/support.py index 4f34b1acf458..f7057cedc421 100644 --- a/python/tvm/support.py +++ b/python/tvm/support.py @@ -33,7 +33,6 @@ def libinfo(): class FrontendTestModule(Module): - def __init__(self, entry_name=None): underlying_mod = get_global_func("testing.FrontendTestModule")() handle = underlying_mod.handle diff --git a/tests/python/unittest/test_runtime_graph_debug.py b/tests/python/unittest/test_runtime_graph_debug.py index 1cb4c2621a3b..996d426efaa9 100644 --- a/tests/python/unittest/test_runtime_graph_debug.py +++ b/tests/python/unittest/test_runtime_graph_debug.py @@ -106,14 +106,23 @@ def myadd(*args): # Verify the tensors are dumped assert len(os.listdir(directory)) > 1 - debug_lines = mod.debug_datum.get_debug_result().split('\n') + debug_lines = mod.debug_datum.get_debug_result().split("\n") + def split_debug_line(i): to_return = re.split(r" [ ]*", debug_lines[i]) assert to_return[-1] == "" to_return = to_return[:-1] # strip empty trailing part return to_return - assert split_debug_line(0) == ["Node Name", "Ops", "Time(us)", "Time(%)", "Shape", "Inputs", "Outputs"] + assert split_debug_line(0) == [ + "Node Name", + "Ops", + "Time(us)", + "Time(%)", + "Shape", + "Inputs", + "Outputs", + ] myadd_lines = split_debug_line(2) assert myadd_lines[0] == "add" assert myadd_lines[1] == "myadd" From ac5df3448f7c3fdba739093335b3420e77f0751a Mon Sep 17 00:00:00 2001 From: Andrew Reusch Date: Thu, 7 Jan 2021 14:04:00 -0800 Subject: [PATCH 6/7] git-clang-format --- src/support/ffi_testing.cc | 21 ++++++++++----------- 1 file changed, 10 insertions(+), 11 deletions(-) diff --git a/src/support/ffi_testing.cc b/src/support/ffi_testing.cc index b9d19a8ce049..b06a8bb461be 100644 --- a/src/support/ffi_testing.cc +++ b/src/support/ffi_testing.cc @@ -103,28 +103,27 @@ TVM_REGISTER_GLOBAL("testing.object_use_count").set_body([](TVMArgs args, TVMRet class FrontendTestModuleNode : public runtime::ModuleNode { public: - virtual const char* type_key() const { - return "frontend_test"; - } + virtual const char* type_key() const { return "frontend_test"; } static constexpr const char* kAddFunctionName = "__add_function"; virtual PackedFunc GetFunction(const std::string& name, const ObjectPtr& sptr_to_self); private: - std::unordered_map functions_; + std::unordered_map functions_; }; constexpr const char* FrontendTestModuleNode::kAddFunctionName; -PackedFunc FrontendTestModuleNode::GetFunction(const std::string& name, const ObjectPtr& sptr_to_self) { +PackedFunc FrontendTestModuleNode::GetFunction(const std::string& name, + const ObjectPtr& sptr_to_self) { if (name == kAddFunctionName) { - return TypedPackedFunc( - [this,sptr_to_self](std::string func_name, PackedFunc pf) { - CHECK_NE(func_name, kAddFunctionName) - << "func_name: cannot be special function " << kAddFunctionName; - functions_[func_name] = pf; - }); + return TypedPackedFunc( + [this, sptr_to_self](std::string func_name, PackedFunc pf) { + CHECK_NE(func_name, kAddFunctionName) + << "func_name: cannot be special function " << kAddFunctionName; + functions_[func_name] = pf; + }); } auto it = functions_.find(name); From d7ca522b7a6ae2240705eabf835af5d848ee6bc7 Mon Sep 17 00:00:00 2001 From: Andrew Reusch Date: Thu, 7 Jan 2021 14:09:56 -0800 Subject: [PATCH 7/7] pylint --- python/tvm/support.py | 2 ++ 1 file changed, 2 insertions(+) diff --git a/python/tvm/support.py b/python/tvm/support.py index f7057cedc421..800bfe4e2546 100644 --- a/python/tvm/support.py +++ b/python/tvm/support.py @@ -33,6 +33,8 @@ def libinfo(): class FrontendTestModule(Module): + """A tvm.runtime.Module whose member functions are PackedFunc.""" + def __init__(self, entry_name=None): underlying_mod = get_global_func("testing.FrontendTestModule")() handle = underlying_mod.handle