Blockstream / electrs

An efficient re-implementation of Electrum Server in Rust
MIT License
301 stars 125 forks source link

Add optional structured logs of RPC related events #66

Closed rem1-dev closed 6 months ago

rem1-dev commented 7 months ago

Adding RPC related event logs that will be used in Blockstream Explorer project. The logs are structured as json object. This optional logging may be used in an enterprise/internal scenario for billing purposes. By default it's turned off.

The logs are controlled with a new --rpc-logging command line option. Command line option possible values, and example structured logs they produce, are as following:

ELECTRUM-RPC-LOGGER: {"event":"connection established","source":{"ip":"127.0.0.1","port":59877}}
ELECTRUM-RPC-LOGGER: {"event":"rpc request","id":18,"method":"blockchain.scripthash.get_history","params":["6b63eef944d982701eb2d0dbb8ee900f42d8e79fe3d1ea473602c0edc87c34f6"],"source":{"ip":"127.0.0.1","port":59877}}
ELECTRUM-RPC-LOGGER: {"duration_µs":114,"event":"rpc response","id":18,"method":"blockchain.scripthash.get_history","payload_size":37,"source":{"ip":"127.0.0.1","port":59877}}
ELECTRUM-RPC-LOGGER: {"event":"connection closed","source":{"ip":"127.0.0.1","port":59877}}

ELECTRUM-RPC-LOGGER: {"event":"connection established","source":{"ip":"127.0.0.1","port":59886}}
ELECTRUM-RPC-LOGGER: {"event":"rpc request","id":18,"method":"blockchain.scripthash.get_history","params":null,"source":{"ip":"127.0.0.1","port":59886}}
ELECTRUM-RPC-LOGGER: {"duration_µs":78,"event":"rpc response","id":18,"method":"blockchain.scripthash.get_history","payload_size":37,"source":{"ip":"127.0.0.1","port":59886}}
ELECTRUM-RPC-LOGGER: {"event":"connection closed","source":{"ip":"127.0.0.1","port":59886}}```
shesek commented 7 months ago

I was thinking that it might be useful to log two extra things - the jsonrpc id field so that the rpc request and rpc response entries can be matched to each-other, and the time it took to process the request.

I'm not sure whether these are necessary or not. If not, we can go ahead and merge.

rem1-dev commented 7 months ago

Yes, it's good idea to add id into req and resp logs. Did you mean id that we can get from cmd variable: cmd.get("id")? I added that.

shesek commented 6 months ago

I made some minor formatting/refactoring suggestions and added the time duration for processing requests in a branch. What do you think?

rem1-dev commented 6 months ago

It looks good to me. I also updated PR description to be more verbose on why we're adding it.

shesek commented 6 months ago

Great :) Can you apply the changes on your branch and rebase?

rem1-dev commented 6 months ago

I applied your changes + I changed duration timestamp field to microseconds because when I tested it I never got duration > 1s and that field was always 0. Re rebase: not sure what should I rebase on. Branch is up-to date with new-index

shesek commented 6 months ago

Thanks!

I accidentally merged without squashing, looking into fixing this