Node discovery periodically revalidates the nodes in its table by sending PING, checking
if they are still alive. I recently noticed some issues with the implementation of this
process, which can cause strange results such as nodes dropping unexpectedly, certain
nodes not getting revalidated often enough, and bad results being returned to incoming
FINDNODE queries.
In this change, the revalidation process is improved with the following logic:
- We maintain two 'revalidation lists' containing the table nodes, named 'fast' and 'slow'.
- The process chooses random nodes from each list on a randomized interval, the interval being
faster for the 'fast' list, and performs revalidation for the chosen node.
- Whenever a node is newly inserted into the table, it goes into the 'fast' list.
Once validation passes, it transfers to the 'slow' list. If a request fails, or the
node changes endpoint, it transfers back into 'fast'.
- livenessChecks is incremented by one for successful checks. Unlike the old implementation,
we will not drop the node on the first failing check. We instead quickly decay the
livenessChecks give it another chance.
- Order of nodes in bucket doesn't matter anymore.
I am also adding a debug API endpoint to dump the node table content.
Co-authored-by: Martin HS <martin@swende.se>
This change
- Removes interface `log.Format`,
- Removes method `log.FormatFunc`,
- unexports `TerminalHandler.TerminalFormat` formatting methods (renamed to `TerminalHandler.format`)
- removes the notion of `log.Lazy` values
The lazy handler was useful in the old log package, since it
could defer the evaluation of costly attributes until later in the
log pipeline: thus, if the logging was done at 'Trace', we could
skip evaluation if logging only was set to 'Info'.
With the move to slog, this way of deferring evaluation is no longer
needed, since slog introduced 'Enabled': the caller can thus do
the evaluate-or-not decision at the callsite, which is much more
straight-forward than dealing with lazy reflect-based evaluation.
Also, lazy evaluation would not work with 'native' slog, as in, these
two statements would be evaluated differently:
```golang
log.Info("foo", "my lazy", lazyObj)
slog.Info("foo", "my lazy", lazyObj)
```
These changes improves the performance of the non-coloured terminal formatting, _quite a lot_.
```
name old time/op new time/op delta
TerminalHandler-8 10.2µs ±15% 5.4µs ± 9% -47.02% (p=0.008 n=5+5)
name old alloc/op new alloc/op delta
TerminalHandler-8 2.17kB ± 0% 0.40kB ± 0% -81.46% (p=0.008 n=5+5)
name old allocs/op new allocs/op delta
TerminalHandler-8 33.0 ± 0% 5.0 ± 0% -84.85% (p=0.008 n=5+5)
```
I tried to _somewhat_ organize the commits, but the it might still be a bit chaotic. Some core insights:
- The function `terminalHandler.Handl` uses a mutex, and writes all output immediately to 'upstream'. Thus, it can reuse a scratch-buffer every time.
- This buffer can be propagated internally, making all the internal formatters either write directly to it,
- OR, make use of the `tmp := buf.AvailableBuffer()` in some cases, where a byte buffer "extra capacity" can be temporarily used.
- The `slog` package uses `Attr` by value. It makes sense to minimize operating on them, since iterating / collecting into a new slice, iterating again etc causes copy-on-heap. Better to operate on them only once.
- If we want to do padding, it's better to copy from a constant `space`-buffer than to invoke `bytes.Repeat` every single time.
This PR replaces Geth's logger package (a fork of [log15](https://github.com/inconshreveable/log15)) with an implementation using slog, a logging library included as part of the Go standard library as of Go1.21.
Main changes are as follows:
* removes any log handlers that were unused in the Geth codebase.
* Json, logfmt, and terminal formatters are now slog handlers.
* Verbosity level constants are changed to match slog constant values. Internal translation is done to make this opaque to the user and backwards compatible with existing `--verbosity` and `--vmodule` options.
* `--log.backtraceat` and `--log.debug` are removed.
The external-facing API is largely the same as the existing Geth logger. Logger method signatures remain unchanged.
A small semantic difference is that a `Handler` can only be set once per `Logger` and not changed dynamically. This just means that a new logger must be instantiated every time the handler of the root logger is changed.
----
For users of the `go-ethereum/log` module. If you were using this module for your own project, you will need to change the initialization. If you previously did
```golang
log.Root().SetHandler(log.LvlFilterHandler(log.LvlInfo, log.StreamHandler(os.Stderr, log.TerminalFormat(true))))
```
You now instead need to do
```golang
log.SetDefault(log.NewLogger(log.NewTerminalHandlerWithLevel(os.Stderr, log.LevelInfo, true)))
```
See more about reasoning here: https://github.com/ethereum/go-ethereum/issues/28558#issuecomment-1820606613
* internal/testlog: print file+line number of log call in test log
This changes the unit test logger to print the actual file and line
number of the logging call instead of "testlog.go:44".
Output of 'go test -v -run TestServerListen ./p2p' before this change:
=== RUN TestServerListen
--- PASS: TestServerListen (0.00s)
testlog.go:44: DEBUG[01-08|15:16:31.651] UDP listener up addr=127.0.0.1:62678
testlog.go:44: DEBUG[01-08|15:16:31.651] TCP listener up addr=127.0.0.1:62678
testlog.go:44: TRACE[01-08|15:16:31.652] Accepted connection addr=127.0.0.1:62679
And after:
=== RUN TestServerListen
--- PASS: TestServerListen (0.00s)
server.go:868: DEBUG[01-08|15:25:35.679] TCP listener up addr=127.0.0.1:62712
server.go:557: DEBUG[01-08|15:25:35.679] UDP listener up addr=127.0.0.1:62712
server.go:912: TRACE[01-08|15:25:35.680] Accepted connection addr=127.0.0.1:62713
* internal/testlog: document use of t.Helper
- Moved fuse related code in a new package, swarm/fuse
- Added write support
- Create new files
- Delete existing files
- Append to files (with limitations)
- More test coverage
* swarm/api: fix build/tests on unsupported platforms
Skip FUSE tests if FUSE is unavailable and change build constraints so
the 'lesser' platforms aren't mentioned explicitly. The test are
compiled on all platforms to prevent regressions in _fallback.go
Also gofmt -w -s because why not.
* internal/web3ext: fix swarmfs wrappers
Remove inputFormatter specifications so users get an error
when passing the wrong number of arguments.
* swarm/api: improve FUSE-related logging and APIs
The API now returns JSON objects instead of strings.
Log messages for invalid arguments are removed.
On Windows, UDPConn.ReadFrom returns an error for packets larger
than the receive buffer. The error is not marked temporary, causing
our loop to exit when the first oversized packet arrived. The fix
is to treat this particular error as temporary.
Fixes: #1579, #2087
Updates: #2082
Felix Lange
Martin HS
Sebastian Stammler
jwasinger
Péter Szilágyi
Zahoor Mohamed
Felix Lange
obscuren