Substantial overhead caused by encoding messages for logging #215

I'm working on a multiprocess branch that passes a lot of data back and forth between server and client.

When looking at a flamegraph, it's clear that >50% of my client's cpu time is spent on logging (encoding) sends. Likewise for the server with responses.

The culprit is toString() from the params/results/request/response, which ends up in kj::_::encodeCEscapeImpl(), which is horribly slow.

Current master: <img width="1211" height="686" alt="Image" src="https://github.com/user-attachments/assets/5adca468-669c-4f2e-b4d9-b820d2b95f30" /> Fixed: <img width="1208" height="541" alt="Image" src="https://github.com/user-attachments/assets/ae6515a5-0287-46c0-b75d-ae08f1e9bb42" />

As you can see, before removing the logging, 52% of my thread's runtime is spent in serverInvoke (which calls foo.toString(), which calls structString(), which calls kj::_::encodeCEscapeImpl(). With the debug lines removed, serverInvoke is no longer visible in the flamegraph at all.

I would imagine the sv2 implementation suffers from this as well, though I'm not sure how chatty it is, so I can't speak to the potential impact.

~I'll open a RFC PR which fixes the issue rather naively. A more robust solution would introduce logging categories similar to Bitcoin Core's.~

Edit: See #216. Also, toned down the original title :)

Ping @Sjors, you might be seeing this as well.

Do I understand correctly that this "only" impacts Bitcoin Core when running with -debug=ipc?

@Sjors No, that's the issue I'm afraid.

The stringification happens in Core regardless of the selected logging level, and on the client even if no log callback is set.

Ah, ok that sounds more urgent then. I'll go and review your fix.