[rpc] Implemented rpc logging #10967

mkatanbaf · 2022-04-11T22:09:48Z

This adds logging to rpc communications, by adding a wrapper around "RPCChannel". The wrapper, "RPCChannelLogging", has a "NanoRPCListener" that only listens to ongoing communication and log them in a human readable way. "NanoRPCListener" uses a "MinRPCSniffer" to decode the rpc commands. "MinRPCSniffer" is based on "MinRPCServer" and shares the same code to decode the packets, but replaces the execution and return handling with no-operation functions. The log is disabled by default for backward compatibility, and a test case ("test_rpc_simple_wlog") is added to the "test_runtime_rpc.py" with logging enabled.

src/runtime/minrpc/minrpc_logger.h

src/runtime/minrpc/minrpc_server_logging.h

src/runtime/minrpc/minrpc_logger.h

src/runtime/rpc/rpc_channel_logger.h

src/runtime/minrpc/minrpc_server_logging.h

src/runtime/minrpc/minrpc_intrfc.h

src/runtime/minrpc/minrpc_logger.cc

src/runtime/minrpc/minrpc_logger.h

src/runtime/minrpc/minrpc_server_logging.h

kparzysz-quic

This is looking pretty good, but there is one more issue.

kparzysz-quic · 2022-04-18T21:02:02Z

src/runtime/minrpc/minrpc_server.h

+        ret_handler_(new MinRPCReturns<TIOHandler>(io_)),
+        exec_handler_(new MinRPCExecute<TIOHandler>(io_, ret_handler_)) {}


These two members are allocated, but never deleted. In the logging classes you pass addresses of members to the MinRPCServer constructor, so it doesn't have a way of knowing whether it should delete these objects or not. This needs to be fixed or it will cause memory leaks.

Thank you very much for taking the time to read through the code, and for valuable comments.
Initially, I wanted to address this using unique_ptrs, but including "memory" resulted in "redefinition of operator new" error in rpc_server.cc. So, I simply use the "ret_handler_" variable as a flag to infer which constructor is used, and delete the allocated variables when needed.

ah i see. i think we could likely remove operator new in rpc_server.cc if it's defined in . it's been long enough that I don't remember why i needed to explicitly override that anyhow--i do think though that we should verify by testing on Zephyr/Arduino to make sure behaves the same way there.

I think this needs a better solution---where the object ownership is fixed, i.e. either this class owns these objects or not. This will need a few more changes to the code creating objects of this class. I'm not sure what solution is the best for this, though.

I changed the implementation to use smart pointer for exec_handler_, I hope that addresses the object ownership concern.

areusch

thanks @mkatanbaf ! i have a few suggestions around the overall interface, mainly fixes to arguments/names and the way things are passed around to remove reinterpret_casts. otherwise this all looks pretty good.

it would be nice to find a way to test the logger output. right now i think we could merge without that explicitly, since we at least have a test that it doesn't crash, though.

areusch · 2022-04-21T16:48:44Z

python/tvm/rpc/client.py

@@ -505,7 +508,7 @@ def connect(url, port, key="", session_timeout=0, session_constructor_args=None)
        client_via_proxy = rpc.connect(
            proxy_server_url, proxy_server_port, proxy_server_key,
            session_constructor_args=[
-                "rpc.Connect", internal_url, internal_port, internal_key])
+                "rpc.Connect", internal_url, internal_port, internal_key, enable_logging])


i think here you mean

Suggested change

"rpc.Connect", internal_url, internal_port, internal_key, enable_logging])

"rpc.Connect", internal_url, internal_port, internal_key],

enable_logging=True)

Not sure if I understand your comment. This is not a function call, it's a list of parameters that would later pass to rpc.Connect on the device. so, I believe we cannot write down the param_name=value, it only has to be the value.

python/tvm/rpc/client.py

src/runtime/minrpc/minrpc_interfaces.h

src/runtime/minrpc/minrpc_logger.h

src/runtime/minrpc/minrpc_interfaces.h

areusch · 2022-04-21T17:23:36Z

src/runtime/minrpc/minrpc_logger.h

+class MinRPCExecuteWithLog : public ExecInterface {
+ public:
+  explicit MinRPCExecuteWithLog(ExecInterface* next) : next_(next) {
+    ret_handler_ = reinterpret_cast<MinRPCReturnsWithLog*>(next_->GetReturnInterface());


since this is the logging version of the ExecInterface, it's reasonable that the constructor should explicitly take a Logger*. i think you could add that argument here and that would remove the need to reinterpret_cast here.

done, but I still need to keep the reinterpret_cast, to access functions such as GetHandleName, UpdateHandleName, ...

src/runtime/minrpc/minrpc_interfaces.h

areusch · 2022-04-21T17:36:11Z

src/runtime/minrpc/minrpc_logger.cc

+
+      if ((*tcodes)[i] == kTVMStr) {
+        if (strlen((*values)[i].v_str) > 0) {
+          ret_handler_->UpdateCurrHandleName((*values)[i].v_str);


i think this is specific to ModuleGetFunction and GetGlobalFunc and CallFunc, right?

As we talked, I kept the code as is for the moment (i.e. it adds all the strings in parameters to the handle name). In future we can change it once we have a better vision of what should or should not be logged.

src/runtime/minrpc/minrpc_logger.h

areusch

thanks @mkatanbaf, i think just one last minor (but probably important to address) thing and then this is ready to go

src/runtime/minrpc/minrpc_server.h

src/runtime/minrpc/minrpc_logger.cc

src/runtime/minrpc/minrpc_server.h

areusch

@kparzysz-quic do you want to take another look?

kparzysz-quic

LGTM, thanks!

mehrdadh · 2022-05-05T00:11:08Z

Thanks @mkatanbaf @areusch @kparzysz-quic @alanmacd! This PR is merged now.

This reverts commit aa3bcd9, because it fails on Windows CI as reported in issue apache#11220. PR apache#11223 tries to address it but is is failing in the regular CI with testing issue on Hexagon.

This reverts commit aa3bcd9, because it fails on Windows CI as reported in issue #11220. PR #11223 tries to address it but is is failing in the regular CI with testing issue on Hexagon.

Co-authored-by: Mohamad <mkatanbaf@users.noreply.github.com>

This reverts commit aa3bcd9, because it fails on Windows CI as reported in issue apache#11220. PR apache#11223 tries to address it but is is failing in the regular CI with testing issue on Hexagon.

Co-authored-by: Mohamad <mkatanbaf@users.noreply.github.com>

This reverts commit aa3bcd9, because it fails on Windows CI as reported in issue apache#11220. PR apache#11223 tries to address it but is is failing in the regular CI with testing issue on Hexagon.

mehrdadh self-assigned this Apr 11, 2022

mkatanbaf force-pushed the rpc_logger branch from e5d56f1 to 3935e6b Compare April 13, 2022 16:36

mkatanbaf marked this pull request as ready for review April 13, 2022 22:18

alanmacd reviewed Apr 13, 2022

View reviewed changes

src/runtime/minrpc/minrpc_logger.h Outdated Show resolved Hide resolved

alanmacd reviewed Apr 13, 2022

View reviewed changes

src/runtime/minrpc/minrpc_server_logging.h Outdated Show resolved Hide resolved

alanmacd reviewed Apr 13, 2022

View reviewed changes

src/runtime/minrpc/minrpc_logger.h Outdated Show resolved Hide resolved

alanmacd reviewed Apr 13, 2022

View reviewed changes

src/runtime/rpc/rpc_channel_logger.h Outdated Show resolved Hide resolved

alanmacd reviewed Apr 13, 2022

View reviewed changes

src/runtime/rpc/rpc_channel_logger.h Outdated Show resolved Hide resolved

alanmacd reviewed Apr 14, 2022

View reviewed changes

src/runtime/minrpc/minrpc_server_logging.h Show resolved Hide resolved

mkatanbaf force-pushed the rpc_logger branch 4 times, most recently from 6ff5271 to b3a00c5 Compare April 14, 2022 20:53

kparzysz-quic reviewed Apr 16, 2022

View reviewed changes

mkatanbaf force-pushed the rpc_logger branch from 6cc7cc5 to 1f618cf Compare April 18, 2022 18:49

kparzysz-quic reviewed Apr 18, 2022

View reviewed changes

areusch requested changes Apr 21, 2022

View reviewed changes

mkatanbaf force-pushed the rpc_logger branch 2 times, most recently from 3759a62 to 5fcf577 Compare April 30, 2022 02:08

areusch reviewed May 3, 2022

View reviewed changes

src/runtime/minrpc/minrpc_server.h Outdated Show resolved Hide resolved

alanmacd reviewed May 3, 2022

View reviewed changes

src/runtime/minrpc/minrpc_logger.cc Show resolved Hide resolved

src/runtime/minrpc/minrpc_server.h Outdated Show resolved Hide resolved

mkatanbaf force-pushed the rpc_logger branch from 5fcf577 to 511d2b8 Compare May 3, 2022 21:48

Implemented rpc logging

111e6ff

mkatanbaf force-pushed the rpc_logger branch from 511d2b8 to 111e6ff Compare May 3, 2022 22:11

mkatanbaf requested a review from areusch May 4, 2022 15:42

areusch approved these changes May 4, 2022

View reviewed changes

kparzysz-quic approved these changes May 4, 2022

View reviewed changes

alanmacd approved these changes May 4, 2022

View reviewed changes

mehrdadh merged commit aa3bcd9 into apache:main May 5, 2022

Mousius mentioned this pull request May 5, 2022

[CI Problem] Windows build fails when compiling RPC server #11220

Closed

leandron mentioned this pull request May 6, 2022

[RPC] Revert "Implemented rpc logging (#10967)" #11227

Merged

mkatanbaf mentioned this pull request May 9, 2022

[rpc] Implemented rpc logging #11232

Merged

shtinsa pushed a commit to Deelvin/tvm that referenced this pull request May 17, 2022

Implemented rpc logging (apache#10967)

a884a99

Co-authored-by: Mohamad <mkatanbaf@users.noreply.github.com>

mkatanbaf mentioned this pull request May 20, 2022

unify ssize_t definition #11384

Merged

SebastianBoblest pushed a commit to SebastianBoblest/tvm that referenced this pull request May 27, 2022

Implemented rpc logging (apache#10967)

11ebfff

Co-authored-by: Mohamad <mkatanbaf@users.noreply.github.com>

driazati mentioned this pull request Jul 14, 2022

TVM v0.9.0.rc0 Release Candidate Notes #12102

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[rpc] Implemented rpc logging #10967

[rpc] Implemented rpc logging #10967

mkatanbaf commented Apr 11, 2022 •

edited

Loading

kparzysz-quic left a comment

kparzysz-quic Apr 18, 2022

mkatanbaf Apr 20, 2022 •

edited

Loading

areusch Apr 21, 2022

kparzysz-quic Apr 21, 2022

mkatanbaf Apr 29, 2022

areusch left a comment

areusch Apr 21, 2022

mkatanbaf Apr 29, 2022

areusch Apr 21, 2022

mkatanbaf Apr 29, 2022

areusch Apr 21, 2022

mkatanbaf Apr 29, 2022 •

edited

Loading

areusch left a comment

areusch left a comment

kparzysz-quic left a comment

mehrdadh commented May 5, 2022

		ret_handler_(new MinRPCReturns<TIOHandler>(io_)),
		exec_handler_(new MinRPCExecute<TIOHandler>(io_, ret_handler_)) {}

	"rpc.Connect", internal_url, internal_port, internal_key, enable_logging])
	"rpc.Connect", internal_url, internal_port, internal_key],
	enable_logging=True)

[rpc] Implemented rpc logging #10967

[rpc] Implemented rpc logging #10967

Conversation

mkatanbaf commented Apr 11, 2022 • edited Loading

kparzysz-quic left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

mkatanbaf Apr 20, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

areusch left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

mkatanbaf Apr 29, 2022 • edited Loading

Choose a reason for hiding this comment

areusch left a comment

Choose a reason for hiding this comment

areusch left a comment

Choose a reason for hiding this comment

kparzysz-quic left a comment

Choose a reason for hiding this comment

mehrdadh commented May 5, 2022

mkatanbaf commented Apr 11, 2022 •

edited

Loading

mkatanbaf Apr 20, 2022 •

edited

Loading

mkatanbaf Apr 29, 2022 •

edited

Loading