Object GET/HEAD/RANGE logger improvements#3408
Merged
roman-khimov merged 2 commits intomasterfrom Jun 20, 2025
Merged
Conversation
8a35166 to
e87e195
Compare
Codecov ReportAttention: Patch coverage is
Additional details and impacted files@@ Coverage Diff @@
## master #3408 +/- ##
==========================================
- Coverage 21.19% 21.16% -0.03%
==========================================
Files 708 708
Lines 52883 52887 +4
==========================================
- Hits 11208 11194 -14
- Misses 40879 40898 +19
+ Partials 796 795 -1 ☔ View full report in Codecov by Sentry. 🚀 New features to boost your workflow:
|
e87e195 to
ac958cd
Compare
Previously, SN could waste memory in these ops' processing by cloning
zap logger:
1. there is only one conditional case when message can be written at
non-debug level;
2. debug level is never enabled in production.
This could be observed when applying a high read load. For example, when
reading same object with a 4K payload in 100 threads from SN, its local
allocation profile showed the following:
```
flat flat% sum% cum cum%
7.05GB 9.45% 9.45% 8.12GB 10.89% github.com/nspcc-dev/neofs-sdk-go/crypto.encodeMessage
6.64GB 8.90% 18.35% 6.64GB 8.90% google.golang.org/protobuf/internal/impl.consumeBytesNoZero
6.25GB 8.38% 26.73% 6.25GB 8.38% github.com/nspcc-dev/neofs-node/pkg/local_object_storage/blobstor/fstree.extractCombinedObject
4.51GB 6.05% 32.78% 4.64GB 6.21% crypto/cipher.NewCTR
3.85GB 5.16% 37.94% 3.85GB 5.16% crypto/aes.newCipher
3.40GB 4.56% 42.50% 5.05GB 6.77% vendor/golang.org/x/crypto/cryptobyte.(*Builder).addLengthPrefixed
2.99GB 4.01% 46.51% 2.99GB 4.01% reflect.New
2.72GB 3.65% 50.16% 2.72GB 3.65% go.uber.org/zap/internal/bufferpool.init.NewPool.func1
2.18GB 2.92% 53.08% 2.18GB 2.92% crypto/internal/bigmod.NewNat
1.87GB 2.51% 55.58% 1.87GB 2.51% crypto/internal/nistec.NewP256Point
```
As you can see, a decent amount of memory is used up for zap needs. At
the same time, not a single entry appeared in the log regarding the
submitted load.
This disables logger cloning for non-debug mode. Profile is now like:
```
flat flat% sum% cum cum%
6.66GB 9.92% 9.92% 7.66GB 11.41% github.com/nspcc-dev/neofs-sdk-go/crypto.encodeMessage
6.13GB 9.13% 19.05% 6.13GB 9.13% google.golang.org/protobuf/internal/impl.consumeBytesNoZero
5.84GB 8.70% 27.75% 5.84GB 8.70% github.com/nspcc-dev/neofs-node/pkg/local_object_storage/blobstor/fstree.extractCombinedObject
4.25GB 6.33% 34.08% 4.37GB 6.51% crypto/cipher.NewCTR
3.67GB 5.47% 39.54% 3.67GB 5.47% crypto/aes.newCipher
3.21GB 4.78% 44.32% 4.80GB 7.16% vendor/golang.org/x/crypto/cryptobyte.(*Builder).addLengthPrefixed
2.84GB 4.23% 48.56% 2.84GB 4.23% reflect.New
2.01GB 3.00% 51.55% 2.01GB 3.00% crypto/internal/bigmod.NewNat
1.73GB 2.57% 54.13% 1.73GB 2.57% crypto/internal/nistec.NewP256Point
1.68GB 2.50% 56.62% 1.68GB 2.50% vendor/golang.org/x/crypto/cryptobyte.(*Builder).add (inline)
```
The only functional change is the error message when decoding some SN's
network address written at error level. Now the message does not contain
information about the request during which an error occurred. Since the
error is not related to a specific request, this change is considered
appropriate.
The optimization is also reflected in the test benchmarks:
```
goos: linux
goarch: amd64
pkg: github.com/nspcc-dev/neofs-node/pkg/services/object/get
cpu: Intel(R) Core(TM) i5-10210U CPU @ 1.60GHz
│ old.txt │ new.txt │
│ sec/op │ sec/op vs base │
ExecCtxSetLoggerProduction-8 1721.00n ± 3% 19.43n ± 6% -98.87% (p=0.000 n=10)
│ old.txt │ new.txt │
│ B/op │ B/op vs base │
ExecCtxSetLoggerProduction-8 2.627Ki ± 0% 0.000Ki ± 0% -100.00% (p=0.000 n=10)
│ old.txt │ new.txt │
│ allocs/op │ allocs/op vs base │
ExecCtxSetLoggerProduction-8 14.00 ± 0% 0.00 ± 0% -100.00% (p=0.000 n=10)
```
Refs #3409.
Signed-off-by: Leonard Lyubich <leonard@morphbits.io>
Follow 91bb4e2. Same test showed following alloc objects ``` 1299856 0.19% 88.10% 5310102 0.76% go.uber.org/zap/zapcore.(*ioCore).clone (inline) ``` and space ``` 1.27GB 1.90% 64.69% 1.27GB 1.90% go.uber.org/zap/internal/bufferpool.init.NewPool.func1 ``` profiles. This replaces logger cloning with explicit field parameterization. The behavior is kept the same. Allocations mentioned above are no longer visible. Go benchmark test: ``` goos: linux goarch: amd64 pkg: github.com/nspcc-dev/neofs-node/pkg/services/object/acl/v2 cpu: Intel(R) Core(TM) i5-10210U CPU @ 1.60GHz │ old.txt │ new.txt │ │ sec/op │ sec/op vs base │ ClassifierLoggerProduction-8 3855.0n ± 2% 661.1n ± 8% -82.85% (p=0.000 n=10) │ old.txt │ new.txt │ │ B/op │ B/op vs base │ ClassifierLoggerProduction-8 1.704Ki ± 0% 0.000Ki ± 0% -100.00% (p=0.000 n=10) │ old.txt │ new.txt │ │ allocs/op │ allocs/op vs base │ ClassifierLoggerProduction-8 13.00 ± 0% 0.00 ± 0% -100.00% (p=0.000 n=10) ``` Refs #3409. Signed-off-by: Leonard Lyubich <leonard@morphbits.io>
ac958cd to
efd8bc2
Compare
roman-khimov
approved these changes
Jun 20, 2025
This file contains hidden or 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
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.
No description provided.