fix: improve jsonRPC error UX for eth1 + execution #5949
Merged
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
nazarhussain
changed the title
Performance Report✔️ no performance regression detected Full benchmark results
|
nazarhussain
force-pushed
the
nh/4348-eth1-error
branch
from
e3c106a
to
cbcce56
Compare
g11tech
requested changes
Sep 25, 2023
|
The log format does not change. it still shows the error exactly like before. The only change would be the error will be shown once connection have any issue. |
|
can we have the "eth1 communication restored/online" etc kind of messages like how you did in the engine when state changes |
|
g11tech
reviewed
Sep 29, 2023
g11tech
reviewed
Sep 29, 2023
g11tech
reviewed
Sep 29, 2023
g11tech
reviewed
Sep 29, 2023
g11tech
reviewed
Sep 29, 2023
g11tech
approved these changes
Sep 29, 2023
nflaig
reviewed
Sep 30, 2023
| } | ||
|
|
||
| private async fetchJson<R, T = unknown>(json: T, opts?: ReqOpts): Promise<R> { | ||
| if (this.urls.length === 0) throw Error("No url provided"); |
There was a problem hiding this comment.
I previously removed a similar check like this in #5884 as we already check the URLs in the constructor
lodestar/packages/beacon-node/src/eth1/provider/jsonRpcHttpClient.ts
Lines 115 to 117 in 3cfa9cd
I don't think this error is reachable but if it is we should make sure to validate the URLs earlier.
| @@ -35,3 +36,29 @@ describe("waitFor", () => { | |||
| await expect(waitFor(() => true, {interval, timeout, signal: controller.signal})).to.be.rejectedWith(ErrorAborted); | |||
| }); | |||
| }); | |||
|
|
|||
| describe("waitForElapsedTime", () => { | |||
There was a problem hiding this comment.
Test case name does not match function name, looks like this was missed during renaming
|
🎉 This PR is included in v1.12.0 🎉 |
nflaig
reviewed
Feb 17, 2024
Comment on lines
+184
to
-183
| // only log error if state switched from online to some other state | ||
| } else if (!isErrorAborted(e)) { | ||
| this.logger.error("Error updating eth1 chain cache", {}, e as Error); |
There was a problem hiding this comment.
@nazarhussain can you please explain this change, does the comment relate to the removed log?
And is the log on line 183 supposed to be replaced by the error log added in the eth1 provider?
There was a problem hiding this comment.
Yes this log line should be replaced with eth1Provider error handling, but because we log the error once per minute so it could be the case you don't see the errors often.
| } | ||
|
|
||
| if (this.state !== Eth1ProviderState.ONLINE) { | ||
| if (isOneMinutePassed()) { |
There was a problem hiding this comment.
@nazarhussain can you please explain how this should behave
- should it invoke the error log at most once a minute
- or should it just invoke the error log once and never again, until there is a period of 1 minute where there are no errors?
See issue reported on discord, we are not actually printing out any errors and just spam the logs with info: Eth1Provider is back online oldState=ERROR, newState=ONLINE.
I pushed a few changes that might partially solve this by fixing createElapsedTimeTracker function, see unstable...nflaig/eth1-error-logging
There was a problem hiding this comment.
Another issue was reported to this, see discord. Does not seem to happen if EL is still synincing but needs more investigation as they use openexecution and not directly connect to EL client.
There was a problem hiding this comment.
When ever JsonRpcHttpClient encounter an error, it bubbles up to this function. We log the the error once per minute because once the rpc encounter error it's usually because the RPC node is offline or some other issue then it's stay that way very long we end up tons of error logs with same error.
There was a problem hiding this comment.
We log the the error once per minute
that's what it should do but the function has a bug, fixed in unstable...nflaig/eth1-error-logging
The other issue I see is how we do the status logging, as single failed request will set the status to ERROR while a single success request sets it to ONLINE.
If some request succeed and some fail which is the cause if nethermind can't serve historical logs but it can serve other requests then what ends up happning is that the logs are spammed with
info: Eth1Provider is back online oldState=ERROR, newState=ONLINE.
It more of an issue of the intended behavior vs. the acutal behavior, if we fix the implementation it should be fine. I added more details in the issue #6469.
There was a problem hiding this comment.
I went over the discussions I had for it's implementation, that was the inspiration or this change:
also maybe every minute log the error message as well if the eth1 is still down ... ( i.e. if we make the request and its still error and the last error display message > 60 seconds , log the message and update last error display time)
So yes there is a bug in the implementation, but not in the createElapsedTimeTracker. That one seems to be good as what is intended for, it's just tracking time since first invocation.
For eth1 provider we should do via rate limiting helpers for rate limit error per minute.
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
Motivation
Manage the state transition for the eth1 provider to log the errors with right context.
Description
Closes #4348
Steps to test or reproduce