-
Notifications
You must be signed in to change notification settings - Fork 44
optimize(otel): Improve performance of otel log processing with sync.Pool
#673
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Conversation
sync.Poolsync.Pool
|
Hello. Thanks for the pull request! Just curious, what happen if we just use func getFields() []logstorage.Field {
if v := fieldsPool.Get(); v != nil {
return v.([]logstorage.Field)
}
return []logstorage.Field{}
}
func putFields(fields []logstorage.Field) {
fields = fields[:0]
fieldsPool.Put(fields)
}and change only commonFields := getFields()
defer putFields(commonFields)
for _, rl := range req.ResourceLogs {
commonFields = commonFields[:0]
commonFields = appendKeyValues(commonFields, rl.Resource.Attributes, "")
commonFieldsLen := len(commonFields)
for _, sc := range rl.ScopeLogs {
commonFields = pushFieldsFromScopeLogs(&sc, commonFields[:commonFieldsLen], lmp, msgFields, useDefaultStreamFields)
}
}By using a pointer to a slice, the underlying array of the slice will still be replaced when its cap (capacity) is about to be exceeded. So I'm curious about the benefits of using pointers here, and it would be even better if comparison result could be provided! |
|
hi, @jiekun return a pointer to avoid extra allocation on goarch: amd64
pkg: github.com/VictoriaMetrics/VictoriaLogs/app/vlinsert/opentelemetry
cpu: Intel(R) Core(TM) i7-14700
│ .\before_fixed.txt │ .\after_fixed.txt │
│ sec/op │ sec/op vs base │
ParseProtobufRequest/scopes_1/rows_100/attributes_5-28 16.77µ ± 38% 16.06µ ± 56% ~ (p=0.481 n=10)
ParseProtobufRequest/scopes_1/rows_100/attributes_10-28 15.68µ ± 6% 16.40µ ± 9% ~ (p=0.684 n=10)
ParseProtobufRequest/scopes_1/rows_1000/attributes_5-28 110.1µ ± 13% 100.8µ ± 8% -8.40% (p=0.043 n=10)
ParseProtobufRequest/scopes_1/rows_1000/attributes_10-28 109.8µ ± 8% 102.8µ ± 2% -6.36% (p=0.001 n=10)
ParseProtobufRequest/scopes_2/rows_100/attributes_5-28 30.80µ ± 5% 31.27µ ± 47% ~ (p=0.218 n=10)
ParseProtobufRequest/scopes_2/rows_100/attributes_10-28 32.48µ ± 7% 32.29µ ± 5% ~ (p=0.190 n=10)
ParseProtobufRequest/scopes_2/rows_1000/attributes_5-28 190.2µ ± 5% 187.8µ ± 3% ~ (p=0.912 n=10)
ParseProtobufRequest/scopes_2/rows_1000/attributes_10-28 186.2µ ± 6% 188.1µ ± 4% ~ (p=0.811 n=10)
geomean 57.08µ 56.05µ -1.80%
│ .\before_fixed.txt │ .\after_fixed.txt │
│ B/s │ B/s vs base │
ParseProtobufRequest/scopes_1/rows_100/attributes_5-28 5.684Mi ± 28% 5.941Mi ± 36% ~ (p=0.492 n=10)
ParseProtobufRequest/scopes_1/rows_100/attributes_10-28 6.080Mi ± 6% 5.813Mi ± 10% ~ (p=0.739 n=10)
ParseProtobufRequest/scopes_1/rows_1000/attributes_5-28 8.664Mi ± 11% 9.456Mi ± 7% +9.14% (p=0.037 n=10)
ParseProtobufRequest/scopes_1/rows_1000/attributes_10-28 8.688Mi ± 8% 9.274Mi ± 2% +6.75% (p=0.001 n=10)
ParseProtobufRequest/scopes_2/rows_100/attributes_5-28 6.194Mi ± 4% 6.099Mi ± 32% ~ (p=0.218 n=10)
ParseProtobufRequest/scopes_2/rows_100/attributes_10-28 5.870Mi ± 7% 5.903Mi ± 5% ~ (p=0.184 n=10)
ParseProtobufRequest/scopes_2/rows_1000/attributes_5-28 10.03Mi ± 5% 10.16Mi ± 3% ~ (p=0.926 n=10)
ParseProtobufRequest/scopes_2/rows_1000/attributes_10-28 10.24Mi ± 6% 10.15Mi ± 4% ~ (p=0.839 n=10)
geomean 7.472Mi 7.609Mi +1.84%
│ .\before_fixed.txt │ .\after_fixed.txt │
│ B/op │ B/op vs base │
ParseProtobufRequest/scopes_1/rows_100/attributes_5-28 48.22Ki ± 1% 47.77Ki ± 1% -0.93% (p=0.000 n=10)
ParseProtobufRequest/scopes_1/rows_100/attributes_10-28 49.37Ki ± 0% 48.43Ki ± 0% -1.91% (p=0.000 n=10)
ParseProtobufRequest/scopes_1/rows_1000/attributes_5-28 389.9Ki ± 0% 389.5Ki ± 0% -0.11% (p=0.000 n=10)
ParseProtobufRequest/scopes_1/rows_1000/attributes_10-28 391.5Ki ± 0% 390.4Ki ± 0% -0.29% (p=0.000 n=10)
ParseProtobufRequest/scopes_2/rows_100/attributes_5-28 95.26Ki ± 0% 94.84Ki ± 1% -0.44% (p=0.014 n=10)
ParseProtobufRequest/scopes_2/rows_100/attributes_10-28 96.54Ki ± 0% 95.71Ki ± 0% -0.86% (p=0.000 n=10)
ParseProtobufRequest/scopes_2/rows_1000/attributes_5-28 784.5Ki ± 0% 784.3Ki ± 0% ~ (p=0.529 n=10)
ParseProtobufRequest/scopes_2/rows_1000/attributes_10-28 786.0Ki ± 0% 785.3Ki ± 0% ~ (p=0.143 n=10)
geomean 194.7Ki 193.5Ki -0.58%
│ .\before_fixed.txt │ .\after_fixed.txt │
│ allocs/op │ allocs/op vs base │
ParseProtobufRequest/scopes_1/rows_100/attributes_5-28 346.0 ± 0% 342.0 ± 0% -1.16% (p=0.000 n=10)
ParseProtobufRequest/scopes_1/rows_100/attributes_10-28 377.0 ± 0% 371.0 ± 0% -1.59% (p=0.000 n=10)
ParseProtobufRequest/scopes_1/rows_1000/attributes_5-28 3.051k ± 0% 3.048k ± 0% -0.11% (p=0.000 n=10)
ParseProtobufRequest/scopes_1/rows_1000/attributes_10-28 3.082k ± 0% 3.078k ± 0% -0.13% (p=0.000 n=10)
ParseProtobufRequest/scopes_2/rows_100/attributes_5-28 656.0 ± 0% 651.0 ± 0% -0.76% (p=0.000 n=10)
ParseProtobufRequest/scopes_2/rows_100/attributes_10-28 687.0 ± 0% 682.0 ± 0% -0.73% (p=0.000 n=10)
ParseProtobufRequest/scopes_2/rows_1000/attributes_5-28 6.064k ± 0% 6.060k ± 0% -0.07% (p=0.000 n=10)
ParseProtobufRequest/scopes_2/rows_1000/attributes_10-28 6.095k ± 0% 6.090k ± 0% -0.08% (p=0.000 n=10)
geomean 1.458k 1.450k -0.58% |
Mentioned in an old Go article ;) |
Welcome to Codecov 🎉Once you merge this PR into your default branch, you're all set! Codecov will compare coverage reports and display results in all future pull requests. Thanks for integrating Codecov - We've got you covered ☂️ |
| ) | ||
|
|
||
| var ( | ||
| exportLogsReqPool = sync.Pool{ |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
In my opinion, to optimize OpenTelemetry format parsing we should:
- Avoid using unnecessary pointers or consider an arena-style allocator (see example: https://github.com/valyala/fastjson/blob/master/arena.go). Since the OpenTelemetry format is relatively flat, I think avoiding extra pointers is the better option.
- Eliminate memory copies during unmarshal – instead, reference the original buffer. This will require refactoring the code to use
[]byteinstead ofstring.
These two optimizations would significantly reduce allocations and improve performance.
Using sync.Pool here won't help much, as it only reduces allocations by a few percent. If you run into performance issues with OpenTelemetry, let us know – in that case, we should apply the optimizations above.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Sorry for the delay in responding.
I agree that optimize OpenTelemetry format parsing does not necessarily require the use of sync.Pool. Also, I think that deeply optimizing it in the two ways mentioned above would introduce more complexity.
I believe it is best to stick with the original code.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Agreed with the @vadimalekseev recommendations.
@vadimalekseev , could you create a feature request for optimizing the parse performance for logs ingested via OpenTelemetry data ingestion protocol? Then we can start working on this issue according to your recommendations.
|
Closing this pull request in favor of #720 - it implements more fundamental performance improvements for parsing of OpenTelemetry-encoded logs. |
Describe Your Changes
Added two
sync.Poolto reduce memory allocationsexportLogsReqPoolforpb.ExportLogsServiceRequest{}objectsfieldsPoolfor[]logstorage.Fieldslicesgoarch: arm64 pkg: github.com/VictoriaMetrics/VictoriaLogs/app/vlinsert/opentelemetry cpu: Apple M3 │ before.txt │ after.txt │ │ sec/op │ sec/op vs base │ ParseProtobufRequest/scopes_1/rows_100/attributes_5-8 11.79µ ± 2% 11.97µ ± 16% ~ (p=0.394 n=6) ParseProtobufRequest/scopes_1/rows_100/attributes_10-8 12.74µ ± 11% 12.31µ ± 3% ~ (p=0.132 n=6) ParseProtobufRequest/scopes_1/rows_1000/attributes_5-8 101.94µ ± 3% 86.01µ ± 3% -15.64% (p=0.002 n=6) ParseProtobufRequest/scopes_1/rows_1000/attributes_10-8 101.59µ ± 23% 87.54µ ± 3% -13.83% (p=0.002 n=6) ParseProtobufRequest/scopes_2/rows_100/attributes_5-8 24.85µ ± 7% 24.03µ ± 4% ~ (p=0.240 n=6) ParseProtobufRequest/scopes_2/rows_100/attributes_10-8 25.00µ ± 8% 25.23µ ± 5% ~ (p=0.619 n=6) ParseProtobufRequest/scopes_2/rows_1000/attributes_5-8 172.9µ ± 19% 163.4µ ± 9% ~ (p=0.180 n=6) ParseProtobufRequest/scopes_2/rows_1000/attributes_10-8 183.1µ ± 6% 159.6µ ± 1% -12.84% (p=0.002 n=6) geomean 48.50µ 45.24µ -6.72% │ before.txt │ after.txt │ │ B/s │ B/s vs base │ ParseProtobufRequest/scopes_1/rows_100/attributes_5-8 8.087Mi ± 2% 7.973Mi ± 14% ~ (p=0.327 n=6) ParseProtobufRequest/scopes_1/rows_100/attributes_10-8 7.496Mi ± 10% 7.749Mi ± 3% ~ (p=0.126 n=6) ParseProtobufRequest/scopes_1/rows_1000/attributes_5-8 9.356Mi ± 3% 11.086Mi ± 3% +18.50% (p=0.002 n=6) ParseProtobufRequest/scopes_1/rows_1000/attributes_10-8 9.389Mi ± 19% 10.896Mi ± 3% +16.05% (p=0.002 n=6) ParseProtobufRequest/scopes_2/rows_100/attributes_5-8 7.677Mi ± 7% 7.939Mi ± 4% ~ (p=0.221 n=6) ParseProtobufRequest/scopes_2/rows_100/attributes_10-8 7.629Mi ± 7% 7.558Mi ± 4% ~ (p=0.604 n=6) ParseProtobufRequest/scopes_2/rows_1000/attributes_5-8 11.03Mi ± 16% 11.68Mi ± 9% ~ (p=0.180 n=6) ParseProtobufRequest/scopes_2/rows_1000/attributes_10-8 10.42Mi ± 6% 11.95Mi ± 1% +14.74% (p=0.002 n=6) geomean 8.797Mi 9.430Mi +7.20% │ before.txt │ after.txt │ │ B/op │ B/op vs base │ ParseProtobufRequest/scopes_1/rows_100/attributes_5-8 48.12Ki ± 0% 47.68Ki ± 0% -0.91% (p=0.002 n=6) ParseProtobufRequest/scopes_1/rows_100/attributes_10-8 49.35Ki ± 0% 48.45Ki ± 0% -1.83% (p=0.002 n=6) ParseProtobufRequest/scopes_1/rows_1000/attributes_5-8 387.6Ki ± 0% 387.1Ki ± 0% -0.13% (p=0.002 n=6) ParseProtobufRequest/scopes_1/rows_1000/attributes_10-8 388.9Ki ± 0% 388.0Ki ± 0% -0.25% (p=0.002 n=6) ParseProtobufRequest/scopes_2/rows_100/attributes_5-8 95.03Ki ± 0% 94.71Ki ± 0% -0.34% (p=0.002 n=6) ParseProtobufRequest/scopes_2/rows_100/attributes_10-8 96.28Ki ± 0% 95.54Ki ± 0% -0.77% (p=0.002 n=6) ParseProtobufRequest/scopes_2/rows_1000/attributes_5-8 775.2Ki ± 0% 774.6Ki ± 0% -0.07% (p=0.002 n=6) ParseProtobufRequest/scopes_2/rows_1000/attributes_10-8 776.4Ki ± 0% 775.5Ki ± 0% -0.11% (p=0.002 n=6) geomean 193.6Ki 192.5Ki -0.55% │ before.txt │ after.txt │ │ allocs/op │ allocs/op vs base │ ParseProtobufRequest/scopes_1/rows_100/attributes_5-8 346.0 ± 0% 341.0 ± 0% -1.45% (p=0.002 n=6) ParseProtobufRequest/scopes_1/rows_100/attributes_10-8 377.0 ± 0% 371.5 ± 0% -1.46% (p=0.002 n=6) ParseProtobufRequest/scopes_1/rows_1000/attributes_5-8 3.052k ± 0% 3.047k ± 0% -0.16% (p=0.002 n=6) ParseProtobufRequest/scopes_1/rows_1000/attributes_10-8 3.083k ± 0% 3.078k ± 0% -0.16% (p=0.002 n=6) ParseProtobufRequest/scopes_2/rows_100/attributes_5-8 655.0 ± 0% 651.0 ± 0% -0.61% (p=0.002 n=6) ParseProtobufRequest/scopes_2/rows_100/attributes_10-8 687.0 ± 0% 682.0 ± 0% -0.73% (p=0.002 n=6) ParseProtobufRequest/scopes_2/rows_1000/attributes_5-8 6.064k ± 0% 6.060k ± 0% -0.07% (p=0.002 n=6) ParseProtobufRequest/scopes_2/rows_1000/attributes_10-8 6.095k ± 0% 6.090k ± 0% -0.08% (p=0.002 n=6) geomean 1.458k 1.449k -0.59%