Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add optional structured logs of RPC related events #66

Merged
merged 12 commits into from
Feb 24, 2024

Conversation

rem1-dev
Copy link

@rem1-dev rem1-dev commented Feb 13, 2024

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:

  • --rpc-logging full results in logs:
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}}
  • --rpc-logging no-params excludes RPC request params to be logged, results in logs like:
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}}```

src/config.rs Outdated Show resolved Hide resolved
src/electrum/server.rs Outdated Show resolved Hide resolved
src/electrum/server.rs Outdated Show resolved Hide resolved
src/electrum/server.rs Outdated Show resolved Hide resolved
src/electrum/server.rs Outdated Show resolved Hide resolved
src/electrum/server.rs Outdated Show resolved Hide resolved
@shesek
Copy link
Collaborator

shesek commented Feb 21, 2024

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
Copy link
Author

rem1-dev commented Feb 21, 2024

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.

rem1-dev and others added 4 commits February 22, 2024 16:26
This makes `method_into` unnecessary and allows using the `id` variable
instead of reading `cmd` again. This also makes it easier to log time
durations (added in a followup commit).
@shesek
Copy link
Collaborator

shesek commented Feb 22, 2024

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

@rem1-dev
Copy link
Author

rem1-dev commented Feb 22, 2024

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

@shesek
Copy link
Collaborator

shesek commented Feb 23, 2024

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

@rem1-dev
Copy link
Author

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 shesek self-requested a review February 24, 2024 06:49
@shesek shesek merged commit f9eeb34 into Blockstream:new-index Feb 24, 2024
1 check passed
@shesek
Copy link
Collaborator

shesek commented Feb 24, 2024

Thanks!

I accidentally merged without squashing, looking into fixing this

junderw pushed a commit to junderw/electrs that referenced this pull request May 1, 2024
…rogress

Feature: Log every 10k blocks to help show progress during initial sync
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants