slog: faster and easier on the memory #8

holiman · 2023-11-07T21:47:10Z

These changes improves the performance of the non-coloured terminal formatting, quite a lot.

ok      github.com/ethereum/go-ethereum/log     17.305s
[user@work go-ethereum]$ benchstat slog.before slog.after 
name               old time/op    new time/op    delta
GloggerTerminal-8    9.46µs ± 8%    6.07µs ±20%  -35.85%  (p=0.000 n=10+10)

name               old alloc/op   new alloc/op   delta
GloggerTerminal-8    1.96kB ± 0%    0.23kB ± 0%  -88.47%  (p=0.000 n=10+10)

name               old allocs/op  new allocs/op  delta
GloggerTerminal-8      33.0 ± 0%       5.0 ± 0%  -84.85%  (p=0.000 n=10+10)

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.

I haven't merged it directly into the slog PR, maybe we should get that fixed and merged first? We can do either way, putting it up here for some feeback.

namiloh · 2023-11-08T06:06:17Z

log/handler.go

 		}
 	case *uint256.Int:
 		if v == nil {
 			attr.Value = slog.AnyValue("<nil>")
 		} else {
-			attr.Value = slog.AnyValue(formatLogfmtUint256(v))
+			attr.Value = slog.AnyValue(appendU256(nil, v))


log/format.go

holiman · 2023-11-14T21:45:37Z

Rebased on latest, also improved some.

$ benchstat slog.before slog.after4 
name               old time/op    new time/op    delta
GloggerTerminal-8    9.10µs ± 9%    4.86µs ±14%  -46.55%  (p=0.000 n=10+10)

name               old alloc/op   new alloc/op   delta
GloggerTerminal-8    1.89kB ± 0%    0.18kB ± 0%  -90.57%  (p=0.000 n=10+10)

name               old allocs/op  new allocs/op  delta
GloggerTerminal-8      30.0 ± 0%       4.0 ± 0%  -86.67%  (p=0.000 n=10+10)

(still, let's merge the original one first)

jwasinger · 2023-11-20T05:42:09Z

log/format.go

-		key := escapeString(attr.Key)
-		rawVal := attr.Value.Any()
-		val := FormatLogfmtValue(rawVal, true)
+		tmp := buf.AvailableBuffer()


bytes.AvailableBuffer was introduced in go1.21 . for now, can we make use of a separate temporary buffer, clearing it on each call to appendEscapeString?

Good catch! Something temporary yes, lemme think about it...

…ereum#28600)

…28584) This change exposes more information from sync module internally

This changes removes the package 'light', which is currently unused.

…aintests) (ethereum#28504) There were several problems related to dumping state. - If a preimage was missing, even if we had set the `OnlyWithAddresses` to `false`, to export them anyway, the way the mapping was constructed (using `common.Address` as key) made the entries get lost anyway. Concerns both state- and blockchain tests. - Blockchain test execution was not configured to store preimages. This changes makes it so that the block test executor takes a callback, just like the state test executor already does. This callback can be used to examine the post-execution state, e.g. to aid debugging of test failures.

This change fixes two type-inconsistencies in the JS tracer: - In most places we return byte arrays as a `Uint8Array` to the tracer. However it seems we missed doing the conversion for `ctx` fields which are passed to the tracer during `result`. They are passed as simple arrays. I think Uint8Arrays are more suitable and we should change this inconsistency. Note: this will be a breaking-change. But I believe the effect is small. If we look at our tracers we see that these fields (`ctx.from`, `ctx.to`, etc.) are used in 2 ways. Passed to `toHex` which takes both array or buffer. Or the length was measured which is the same for both types. - The `slice` taking in `int, int` params versus `memory.slice` taking `int64, int64` params. I suggest changing `slice` types to `int64`. This should have no effect almost in any case.

…eader fields (ethereum#28605)

…ations (ethereum#28618) * eth/gasestimator: early exit for plain transfer and error allowance * core, eth/gasestimator: hard guess at a possible required gas * internal/ethapi: update estimation tests with the error ratio * eth/gasestimator: I hate you linter * graphql: fix gas estimation test --------- Co-authored-by: Oren <orenyomtov@users.noreply.github.com>

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: ethereum#28558 (comment)

- implement custom time writer, - better padding with spaces - better use of spaces - log: more efficient handling of slog.Value - log: utilize scratch-buffer in terminal handler - log: use scratch-space for value formatting

namiloh reviewed Nov 8, 2023

View reviewed changes

log/format.go Show resolved Hide resolved

jwasinger force-pushed the slog branch from 5ffd27e to e2db1a2 Compare November 9, 2023 10:34

holiman force-pushed the slog branch from 5e4cebf to 47718a6 Compare November 14, 2023 19:40

holiman force-pushed the faster_slog branch from 5824c2c to 79910c4 Compare November 14, 2023 20:54

jwasinger force-pushed the slog branch from c2f528a to a6198da Compare November 15, 2023 10:05

holiman force-pushed the faster_slog branch from 2b3e08f to 53126d7 Compare November 15, 2023 20:13

jwasinger reviewed Nov 20, 2023

View reviewed changes

karalabe and others added 15 commits November 27, 2023 16:20

eth/gasestimator, internal/ethapi: move gas estimator out of rpc (eth…

1e28e0b

…ereum#28600)

go.mod: update uint256 to v1.2.4 (ethereum#28612)

5b57727

eth/catalyst, eth/downloader: expose more sync information (ethereum#…

71817f3

…28584) This change exposes more information from sync module internally

light: remove package light(ethereum#28614)

58297e3

This changes removes the package 'light', which is currently unused.

ethereum: remove TODO comment about subscription (ethereum#28609)

248dc50

crypto/secp256k1: fix 32-bit tests when CGO_ENABLED=0 (ethereum#28602)

34dcd74

consensus: verify the nonexistence of shanghai- and cancun-specific h…

e0c7ad0

…eader fields (ethereum#28605)

log: better benchmark

0c8b6ca

log: lots of optimizations to terminal output

1bc4719

- implement custom time writer, - better padding with spaces - better use of spaces - log: more efficient handling of slog.Value - log: utilize scratch-buffer in terminal handler - log: use scratch-space for value formatting

log: save some cpu by simplifying coloring, avoid many cases of escaping

3093e9a

remove commented code and no-op space

8dc81f2

holiman force-pushed the faster_slog branch from 43779e1 to 8dc81f2 Compare November 29, 2023 07:43

holiman closed this Nov 29, 2023

holiman mentioned this pull request Nov 29, 2023

slog: faster and less memory-consumption ethereum/go-ethereum#28621

Merged

1 task

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

slog: faster and easier on the memory #8

slog: faster and easier on the memory #8

holiman commented Nov 7, 2023

namiloh Nov 8, 2023

holiman commented Nov 14, 2023

jwasinger Nov 20, 2023 •

edited

Loading

holiman Nov 20, 2023

slog: faster and easier on the memory #8

slog: faster and easier on the memory #8

Conversation

holiman commented Nov 7, 2023

namiloh Nov 8, 2023

Choose a reason for hiding this comment

holiman commented Nov 14, 2023

jwasinger Nov 20, 2023 • edited Loading

Choose a reason for hiding this comment

holiman Nov 20, 2023

Choose a reason for hiding this comment

jwasinger Nov 20, 2023 •

edited

Loading