logging: creating a logger.WithFields is not lazily initialized and will lead to significant allocations in the hot loop

[dshulyak]

In particular, https://github.com/spacemeshos/go-spacemesh/blob/develop/tortoise/verifying.go#L203-L210 leads to 60Gb of memory allocated on the heap in an hour. The fix is simple, fields should be duplicated for every logline.

Adding this issue as a reminder to be wary of this pattern.

[countvonzero]

@dshulyak i don't understand the root of this issue. i want to understand fully so i don't make mistake. can you give an example of fields should be duplicated for every logline, as opposed to

if _, exists := v.badBeaconBallots[ballot.id]; exists {
		logger.With().Debug("ballot is not good. ballot has a bad beacon")
		return bad
	}

thanks

[countvonzero]

are you basically saying not to use logger = logger.WithFields()?

[dshulyak]

So the problem came up with logging in determineGoodness. see pyroscope from current devnet. if log.WithFields is in the hot path it will cause a lot of allocations, even if log is not printed later.

are you basically saying not to use logger = logger.WithFields()?

i am not sure. it definitely should not be used in the hot path. but maybe there is some mistake in our wrapper, need to take a closer look