Skip to content
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

[pkg/stanza] make log emitter and entry conversion in adapter synchronous #35669

Merged

Conversation

bacherfl
Copy link
Contributor

@bacherfl bacherfl commented Oct 8, 2024

Description

This PR changes the LogEmitter to accept a synchronous consumer callback function for processing a batch of log entries as an alternative to sending log entry batches to a channel.
The components that use the LogEmitter (adapter and parser) have been adapted accordingly. Also, in the case of the adapter, the log entries are converted directly, rather than sending them over a channel to the converter and receiving the converted results over a different channel.

Link to tracking issue

Fixes #35453

Testing

I did some initial performance tests using the TestLogLargeFiles load test to see how this change affects the performance. Below are the results:

Before the change (i.e. with async log entry batch processing)

=== RUN   TestLogLargeFiles/filelog-largefiles-2Gb-lifetime
2024/10/08 09:02:53  | Sent:17,769,795 logs (179,507/sec) | Received:17,755,188 items (179,346/sec)

=== RUN   TestLogLargeFiles/filelog-largefiles-6GB-lifetime
2024/10/08 09:06:29  | Sent:42,857,755 logs (216,465/sec) | Received:42,851,987 items (216,424/sec)

Test                                         |Result|Duration|CPU Avg%|CPU Max%|RAM Avg MiB|RAM Max MiB|Sent Items|Received Items|
---------------------------------------------|------|-------:|-------:|-------:|----------:|----------:|---------:|-------------:|
LogLargeFiles/filelog-largefiles-2Gb-lifetime|PASS  |    100s|    73.1|    78.4|        106|        118|  18249451|      18249451|
LogLargeFiles/filelog-largefiles-6GB-lifetime|PASS  |    200s|    87.5|    98.1|        110|        116|  44358460|      44358460|

After the change (i.e. with sync log entry batch processing)

=== RUN   TestLogLargeFiles/filelog-largefiles-2Gb-lifetime
2024/10/08 10:09:51 Agent RAM (RES): 139 MiB, CPU:71.7% | Sent:17,802,561 logs (179,836/sec) | Received:17,788,273 items (179,680/sec)

=== RUN   TestLogLargeFiles/filelog-largefiles-6GB-lifetime
2024/10/08 10:05:15 Agent RAM (RES): 140 MiB, CPU:95.6% | Sent:42,912,030 logs (216,744/sec) | Received:42,904,306 items (216,689/sec)

Test                                         |Result|Duration|CPU Avg%|CPU Max%|RAM Avg MiB|RAM Max MiB|Sent Items|Received Items|
---------------------------------------------|------|-------:|-------:|-------:|----------:|----------:|---------:|-------------:|
LogLargeFiles/filelog-largefiles-2Gb-lifetime|PASS  |    100s|    74.8|    78.9|        127|        139|  17984687|      17984687|
LogLargeFiles/filelog-largefiles-6GB-lifetime|PASS  |    200s|    89.3|   100.9|        134|        140|  43376210|      43376210|

Those results seem to indicate comparable throughput, but with an increased resource consumption, especially in terms of memory.

I also did a test comparing the performance between the synchronous and asynchronous log emitter using the same methodology as in #35454.

The results were the following, and indicate an increase in the time it takes for reading the generated log file (see #35454 for details on how the file is generated and the test execution):

  • Async Log Emitter: ~8s
  • Sync Log Emitter: ~12s
output-async.log === Step 3: Thu Oct 10 08:54:23 CEST 2024 otelcol_receiver_accepted_log_records{receiver="filelog",service_instance_id="3744d4cb-5080-427c-8c16-a96cb40a57d4",service_name="otelcontribcol",service_version="0.111.0-dev",transport=""} 2.209674e+06 === Step 4: Thu Oct 10 08:54:25 CEST 2024 otelcol_receiver_accepted_log_records{receiver="filelog",service_instance_id="3744d4cb-5080-427c-8c16-a96cb40a57d4",service_name="otelcontribcol",service_version="0.111.0-dev",transport=""} 5.428103e+06 === Step 5: Thu Oct 10 08:54:26 CEST 2024 otelcol_receiver_accepted_log_records{receiver="filelog",service_instance_id="3744d4cb-5080-427c-8c16-a96cb40a57d4",service_name="otelcontribcol",service_version="0.111.0-dev",transport=""} 7.337017e+06 === Step 6: Thu Oct 10 08:54:27 CEST 2024 otelcol_receiver_accepted_log_records{receiver="filelog",service_instance_id="3744d4cb-5080-427c-8c16-a96cb40a57d4",service_name="otelcontribcol",service_version="0.111.0-dev",transport=""} 9.258843e+06 === Step 7: Thu Oct 10 08:54:29 CEST 2024 otelcol_receiver_accepted_log_records{receiver="filelog",service_instance_id="3744d4cb-5080-427c-8c16-a96cb40a57d4",service_name="otelcontribcol",service_version="0.111.0-dev",transport=""} 1.3082428e+07 === Step 8: Thu Oct 10 08:54:31 CEST 2024 otelcol_receiver_accepted_log_records{receiver="filelog",service_instance_id="3744d4cb-5080-427c-8c16-a96cb40a57d4",service_name="otelcontribcol",service_version="0.111.0-dev",transport=""} 1.6519068e+07
output-sync.log === Step 2: Thu Oct 10 08:51:27 CEST 2024 otelcol_receiver_accepted_log_records{receiver="filelog",service_instance_id="dcf5371b-19eb-47b3-a820-756c1832b448",service_name="otelcontribcol",service_version="0.111.0-dev",transport=""} 1.580891e+06 === Step 3: Thu Oct 10 08:51:28 CEST 2024 otelcol_receiver_accepted_log_records{receiver="filelog",service_instance_id="dcf5371b-19eb-47b3-a820-756c1832b448",service_name="otelcontribcol",service_version="0.111.0-dev",transport=""} 3.01034e+06 === Step 4: Thu Oct 10 08:51:29 CEST 2024 otelcol_receiver_accepted_log_records{receiver="filelog",service_instance_id="dcf5371b-19eb-47b3-a820-756c1832b448",service_name="otelcontribcol",service_version="0.111.0-dev",transport=""} 4.434627e+06 === Step 5: Thu Oct 10 08:51:31 CEST 2024 otelcol_receiver_accepted_log_records{receiver="filelog",service_instance_id="dcf5371b-19eb-47b3-a820-756c1832b448",service_name="otelcontribcol",service_version="0.111.0-dev",transport=""} 7.416612e+06 === Step 6: Thu Oct 10 08:51:34 CEST 2024 otelcol_receiver_accepted_log_records{receiver="filelog",service_instance_id="dcf5371b-19eb-47b3-a820-756c1832b448",service_name="otelcontribcol",service_version="0.111.0-dev",transport=""} 1.0496072e+07 === Step 7: Thu Oct 10 08:51:36 CEST 2024 otelcol_receiver_accepted_log_records{receiver="filelog",service_instance_id="dcf5371b-19eb-47b3-a820-756c1832b448",service_name="otelcontribcol",service_version="0.111.0-dev",transport=""} 1.3523882e+07 === Step 8: Thu Oct 10 08:51:37 CEST 2024 otelcol_receiver_accepted_log_records{receiver="filelog",service_instance_id="dcf5371b-19eb-47b3-a820-756c1832b448",service_name="otelcontribcol",service_version="0.111.0-dev",transport=""} 1.4929707e+07 === Step 9: Thu Oct 10 08:51:39 CEST 2024 otelcol_receiver_accepted_log_records{receiver="filelog",service_instance_id="dcf5371b-19eb-47b3-a820-756c1832b448",service_name="otelcontribcol",service_version="0.111.0-dev",transport=""} 1.6519105e+07

@github-actions github-actions bot added the processor/logstransform Logs Transform processor label Oct 9, 2024
@github-actions github-actions bot requested a review from dehaansa October 9, 2024 11:47
@bacherfl bacherfl changed the title [pkg/stanza] make log emitter and entry conversion in adapter synchronous [chore] make log emitter and entry conversion in adapter synchronous Oct 9, 2024
@bacherfl bacherfl changed the title [chore] make log emitter and entry conversion in adapter synchronous [pkg/stanza] make log emitter and entry conversion in adapter synchronous Oct 10, 2024
@bacherfl bacherfl marked this pull request as ready for review October 10, 2024 08:53
@bacherfl bacherfl requested a review from a team as a code owner October 10, 2024 08:53
Copy link
Member

@djaglowski djaglowski left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for working on this.

I am not very certain that the testbed benchmarks are a fair comparison for these changes, since they rely on so many external factors besides the adapter code itself. I left some suggestions about how we can update the adapter benchmarks to give us a better comparison.

pkg/stanza/operator/helper/emitter.go Outdated Show resolved Hide resolved
testbed/tests/scenarios.go Outdated Show resolved Hide resolved
testbed/tests/log_test.go Show resolved Hide resolved
processor/logstransformprocessor/processor.go Outdated Show resolved Hide resolved
pkg/stanza/operator/parser/container/parser.go Outdated Show resolved Hide resolved
pkg/stanza/adapter/receiver.go Outdated Show resolved Hide resolved
pkg/stanza/operator/helper/emitter.go Outdated Show resolved Hide resolved
pkg/stanza/adapter/receiver_test.go Show resolved Hide resolved
pkg/stanza/adapter/receiver_test.go Show resolved Hide resolved
pkg/stanza/adapter/receiver_test.go Outdated Show resolved Hide resolved
@bacherfl
Copy link
Contributor Author

Thanks for the thorough review @djaglowski and sorry for the late reply - I will go through all comments today and address them

Signed-off-by: Florian Bacher <[email protected]>
pkg/stanza/adapter/converter.go Outdated Show resolved Hide resolved
pkg/stanza/adapter/receiver_test.go Outdated Show resolved Hide resolved
djaglowski pushed a commit that referenced this pull request Oct 24, 2024
<!--Ex. Fixing a bug - Describe the bug and how this fixes the issue.
Ex. Adding a feature - Explain what this achieves.-->
#### Description

This PR introduces a benchmark test for the receiver adapter which tests
the performance of handling the log entries sent to the `LogEmitter`,
which are then received and converted by the receiver adapter. The
changes have been made based on the comment linked here:
#35669 (comment)

<!-- Issue number (e.g. #1234) or full URL to issue, if applicable. -->
#### Link to tracking issue
Part of #35453

<!--Describe what testing was performed and which tests were added.-->
#### Testing

Added additional benchmark tests

---------

Signed-off-by: Florian Bacher <[email protected]>
@andrzej-stencel
Copy link
Member

Looks great, thank you @bacherfl! I believe this implements exactly what the issue #35453 describes. 🚀

Can we remove the adapter.Converter type altogether and only leave the ConvertEntries function in converter.go?

Also, is this pull request still "work in progress and only a proof of concept" as described in the description? If yes, please let me know when it's ready for a "final" review (perhaps by switching to Draft and then back to non-draft when it's ready).

@bacherfl
Copy link
Contributor Author

Looks great, thank you @bacherfl! I believe this implements exactly what the issue #35453 describes. 🚀

Can we remove the adapter.Converter type altogether and only leave the ConvertEntries function in converter.go?

Also, is this pull request still "work in progress and only a proof of concept" as described in the description? If yes, please let me know when it's ready for a "final" review (perhaps by switching to Draft and then back to non-draft when it's ready).

Thanks @andrzej-stencel! Sure, I will remove the Converter - once that is done, I think the PR should be ready for a final review :)

@bacherfl bacherfl marked this pull request as draft October 29, 2024 06:17
@bacherfl
Copy link
Contributor Author

bacherfl commented Oct 29, 2024

Regarding the performance, I did a comparison between the synchronous and the asynchronous adapter using the updated benchmark tests:

Sync adapter:

BenchmarkReceiver/100_Log_entries_per_iteration-10     	    4591	    259252 ns/op
BenchmarkReceiver/1_000_Log_entries_per_iteration
BenchmarkReceiver/1_000_Log_entries_per_iteration-10   	     477	   2518785 ns/op
BenchmarkReceiver/10_000_Log_entries_per_iteration
BenchmarkReceiver/10_000_Log_entries_per_iteration-10  	      46	  25200357 ns/op

Async adapter:

BenchmarkReceiver/100_Log_entries_per_iteration-10     	    4568	    264706 ns/op
BenchmarkReceiver/1_000_Log_entries_per_iteration
BenchmarkReceiver/1_000_Log_entries_per_iteration-10   	     638	   1677500 ns/op
BenchmarkReceiver/10_000_Log_entries_per_iteration
BenchmarkReceiver/10_000_Log_entries_per_iteration-10  	      75	  15614962 ns/op

# Conflicts:
#	testbed/tests/scenarios.go
@bacherfl
Copy link
Contributor Author

@andrzej-stencel One question regarding the removal of the converter: I've found that this is currently used in two places other than pkg/stanza:

In both cases it seems like the converter is used to generate test data, and can likely be replaced easily with the Convert function. Do you think we can include the adaptations for the tests of these two receivers in this PR, or would you prefer to have this done in a separate PR?
In the latter case we would need to keep the Converter type for now and then remove it as part of the follow up PR.

Signed-off-by: Florian Bacher <[email protected]>
@djaglowski
Copy link
Member

I agree it should be possible to refactor those tests to remove the converter. Seems like a good followup PR.

Regarding the benchmarks, do you mind running them multiple times and using benchstat to compare?

go test -benchmem -run=^$ -bench . ./path/to/package -count=10 | tee before.txt
...
go test -benchmem -run=^$ -bench . ./path/to/package -count=10 | tee after.txt

benchstat before.txt after.txt

Based on the one run it looks promising but given the impact here I think we should have a more statistically significant comparison. If these are running quickly, it'd be interesting to see another order of magnitude too (not required though).

@bacherfl
Copy link
Contributor Author

I agree it should be possible to refactor those tests to remove the converter. Seems like a good followup PR.

Regarding the benchmarks, do you mind running them multiple times and using benchstat to compare?

go test -benchmem -run=^$ -bench . ./path/to/package -count=10 | tee before.txt
...
go test -benchmem -run=^$ -bench . ./path/to/package -count=10 | tee after.txt

benchstat before.txt after.txt

Based on the one run it looks promising but given the impact here I think we should have a more statistically significant comparison. If these are running quickly, it'd be interesting to see another order of magnitude too (not required though).

Sure, will post the updated results soon

@bacherfl
Copy link
Contributor Author

Alright, here is the result of the benchstat comparison:

goos: darwin
goarch: arm64
pkg: github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza/adapter
                                                │ before.txt  │              after.txt               │
                                                │   sec/op    │    sec/op     vs base                │
Receiver/1_Log_entry_per_iteration-10             100.1m ± 0%   100.1m ±  0%        ~ (p=0.631 n=10)
Receiver/10_Log_entries_per_iteration-10          100.1m ± 0%   100.1m ±  0%        ~ (p=0.218 n=10)
Receiver/100_Log_entries_per_iteration-10         258.1µ ± 8%   253.4µ ±  1%   -1.82% (p=0.000 n=10)
Receiver/1_000_Log_entries_per_iteration-10       1.615m ± 8%   2.518m ±  1%  +55.94% (p=0.000 n=10)
Receiver/10_000_Log_entries_per_iteration-10      15.49m ± 2%   25.14m ±  6%  +62.30% (p=0.000 n=10)
Receiver/100_000_Log_entries_per_iteration-10     159.0m ± 5%   251.9m ± 44%  +58.45% (p=0.000 n=10)
Receiver/1_000_000_Log_entries_per_iteration-10    1.545 ± 4%    2.506 ±  0%  +62.19% (p=0.000 n=10)
geomean                                           28.66m        37.35m        +30.33%

                                                │  before.txt  │              after.txt              │
                                                │     B/op     │     B/op      vs base               │
Receiver/1_Log_entry_per_iteration-10             4.365Ki ± 2%   4.320Ki ± 1%       ~ (p=0.100 n=10)
Receiver/10_Log_entries_per_iteration-10          18.49Ki ± 1%   18.44Ki ± 0%  -0.28% (p=0.000 n=10)
Receiver/100_Log_entries_per_iteration-10         158.5Ki ± 0%   158.5Ki ± 0%  +0.01% (p=0.000 n=10)
Receiver/1_000_Log_entries_per_iteration-10       1.549Mi ± 0%   1.548Mi ± 0%  -0.08% (p=0.000 n=10)
Receiver/10_000_Log_entries_per_iteration-10      15.48Mi ± 0%   15.48Mi ± 0%  -0.06% (p=0.000 n=10)
Receiver/100_000_Log_entries_per_iteration-10     154.8Mi ± 0%   154.8Mi ± 0%  -0.05% (p=0.000 n=10)
Receiver/1_000_000_Log_entries_per_iteration-10   1.512Gi ± 0%   1.511Gi ± 0%  -0.05% (p=0.000 n=10)
geomean                                           1.829Mi        1.825Mi       -0.22%

                                                │ before.txt  │              after.txt               │
                                                │  allocs/op  │  allocs/op   vs base                 │
Receiver/1_Log_entry_per_iteration-10              83.00 ± 1%    82.00 ± 1%  -1.20% (p=0.010 n=10)
Receiver/10_Log_entries_per_iteration-10           510.0 ± 0%    509.0 ± 0%  -0.20% (p=0.001 n=10)
Receiver/100_Log_entries_per_iteration-10         4.734k ± 0%   4.734k ± 0%       ~ (p=1.000 n=10) ¹
Receiver/1_000_Log_entries_per_iteration-10       47.36k ± 0%   47.34k ± 0%  -0.04% (p=0.000 n=10)
Receiver/10_000_Log_entries_per_iteration-10      473.5k ± 0%   473.4k ± 0%  -0.03% (p=0.000 n=10)
Receiver/100_000_Log_entries_per_iteration-10     4.735M ± 0%   4.734M ± 0%  -0.03% (p=0.000 n=10)
Receiver/1_000_000_Log_entries_per_iteration-10   47.35M ± 0%   47.34M ± 0%  -0.03% (p=0.000 n=10)
geomean                                           51.85k        51.74k       -0.22%

@bacherfl bacherfl marked this pull request as ready for review October 30, 2024 10:32
@bacherfl
Copy link
Contributor Author

@andrzej-stencel @djaglowski I think this is ready for review now, since the removal of the converter type will be done as a follow up

@djaglowski
Copy link
Member

goos: darwin
goarch: arm64
pkg: github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza/adapter
                                                │ before.txt  │              after.txt               │
                                                │   sec/op    │    sec/op     vs base                │
Receiver/1_Log_entry_per_iteration-10             100.1m ± 0%   100.1m ±  0%        ~ (p=0.631 n=10)
Receiver/10_Log_entries_per_iteration-10          100.1m ± 0%   100.1m ±  0%        ~ (p=0.218 n=10)
Receiver/100_Log_entries_per_iteration-10         258.1µ ± 8%   253.4µ ±  1%   -1.82% (p=0.000 n=10)
Receiver/1_000_Log_entries_per_iteration-10       1.615m ± 8%   2.518m ±  1%  +55.94% (p=0.000 n=10)
Receiver/10_000_Log_entries_per_iteration-10      15.49m ± 2%   25.14m ±  6%  +62.30% (p=0.000 n=10)
Receiver/100_000_Log_entries_per_iteration-10     159.0m ± 5%   251.9m ± 44%  +58.45% (p=0.000 n=10)
Receiver/1_000_000_Log_entries_per_iteration-10    1.545 ± 4%    2.506 ±  0%  +62.19% (p=0.000 n=10)
geomean                                           28.66m        37.35m        +30.33%

                                                │  before.txt  │              after.txt              │
                                                │     B/op     │     B/op      vs base               │
Receiver/1_Log_entry_per_iteration-10             4.365Ki ± 2%   4.320Ki ± 1%       ~ (p=0.100 n=10)
Receiver/10_Log_entries_per_iteration-10          18.49Ki ± 1%   18.44Ki ± 0%  -0.28% (p=0.000 n=10)
Receiver/100_Log_entries_per_iteration-10         158.5Ki ± 0%   158.5Ki ± 0%  +0.01% (p=0.000 n=10)
Receiver/1_000_Log_entries_per_iteration-10       1.549Mi ± 0%   1.548Mi ± 0%  -0.08% (p=0.000 n=10)
Receiver/10_000_Log_entries_per_iteration-10      15.48Mi ± 0%   15.48Mi ± 0%  -0.06% (p=0.000 n=10)
Receiver/100_000_Log_entries_per_iteration-10     154.8Mi ± 0%   154.8Mi ± 0%  -0.05% (p=0.000 n=10)
Receiver/1_000_000_Log_entries_per_iteration-10   1.512Gi ± 0%   1.511Gi ± 0%  -0.05% (p=0.000 n=10)
geomean                                           1.829Mi        1.825Mi       -0.22%

                                                │ before.txt  │              after.txt               │
                                                │  allocs/op  │  allocs/op   vs base                 │
Receiver/1_Log_entry_per_iteration-10              83.00 ± 1%    82.00 ± 1%  -1.20% (p=0.010 n=10)
Receiver/10_Log_entries_per_iteration-10           510.0 ± 0%    509.0 ± 0%  -0.20% (p=0.001 n=10)
Receiver/100_Log_entries_per_iteration-10         4.734k ± 0%   4.734k ± 0%       ~ (p=1.000 n=10) ¹
Receiver/1_000_Log_entries_per_iteration-10       47.36k ± 0%   47.34k ± 0%  -0.04% (p=0.000 n=10)
Receiver/10_000_Log_entries_per_iteration-10      473.5k ± 0%   473.4k ± 0%  -0.03% (p=0.000 n=10)
Receiver/100_000_Log_entries_per_iteration-10     4.735M ± 0%   4.734M ± 0%  -0.03% (p=0.000 n=10)
Receiver/1_000_000_Log_entries_per_iteration-10   47.35M ± 0%   47.34M ± 0%  -0.03% (p=0.000 n=10)
geomean                                           51.85k        51.74k       -0.22%

@bacherfl, this appears to show a ~60% increase in CPU consumption, but the earlier (single run) result showed just about the opposite. Just double checking, is it possible before/after were switched?

Copy link
Member

@andrzej-stencel andrzej-stencel left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I re-ran the manual test "Run the collector binary reading a 1 GiB file" described in detail in #35454 (comment), comparing v0.112.0 to this PR. Surprisingly, the results say pretty consistently that this change decreases the time for File Log receiver to read a 1 GB file from ~17 seconds to ~14-15 seconds. This is about 15% improvement in performance!

@bacherfl
Copy link
Contributor Author

bacherfl commented Nov 4, 2024

goos: darwin
goarch: arm64
pkg: github.com/open-telemetry/opentelemetry-collector-contrib/pkg/stanza/adapter
                                                │ before.txt  │              after.txt               │
                                                │   sec/op    │    sec/op     vs base                │
Receiver/1_Log_entry_per_iteration-10             100.1m ± 0%   100.1m ±  0%        ~ (p=0.631 n=10)
Receiver/10_Log_entries_per_iteration-10          100.1m ± 0%   100.1m ±  0%        ~ (p=0.218 n=10)
Receiver/100_Log_entries_per_iteration-10         258.1µ ± 8%   253.4µ ±  1%   -1.82% (p=0.000 n=10)
Receiver/1_000_Log_entries_per_iteration-10       1.615m ± 8%   2.518m ±  1%  +55.94% (p=0.000 n=10)
Receiver/10_000_Log_entries_per_iteration-10      15.49m ± 2%   25.14m ±  6%  +62.30% (p=0.000 n=10)
Receiver/100_000_Log_entries_per_iteration-10     159.0m ± 5%   251.9m ± 44%  +58.45% (p=0.000 n=10)
Receiver/1_000_000_Log_entries_per_iteration-10    1.545 ± 4%    2.506 ±  0%  +62.19% (p=0.000 n=10)
geomean                                           28.66m        37.35m        +30.33%

                                                │  before.txt  │              after.txt              │
                                                │     B/op     │     B/op      vs base               │
Receiver/1_Log_entry_per_iteration-10             4.365Ki ± 2%   4.320Ki ± 1%       ~ (p=0.100 n=10)
Receiver/10_Log_entries_per_iteration-10          18.49Ki ± 1%   18.44Ki ± 0%  -0.28% (p=0.000 n=10)
Receiver/100_Log_entries_per_iteration-10         158.5Ki ± 0%   158.5Ki ± 0%  +0.01% (p=0.000 n=10)
Receiver/1_000_Log_entries_per_iteration-10       1.549Mi ± 0%   1.548Mi ± 0%  -0.08% (p=0.000 n=10)
Receiver/10_000_Log_entries_per_iteration-10      15.48Mi ± 0%   15.48Mi ± 0%  -0.06% (p=0.000 n=10)
Receiver/100_000_Log_entries_per_iteration-10     154.8Mi ± 0%   154.8Mi ± 0%  -0.05% (p=0.000 n=10)
Receiver/1_000_000_Log_entries_per_iteration-10   1.512Gi ± 0%   1.511Gi ± 0%  -0.05% (p=0.000 n=10)
geomean                                           1.829Mi        1.825Mi       -0.22%

                                                │ before.txt  │              after.txt               │
                                                │  allocs/op  │  allocs/op   vs base                 │
Receiver/1_Log_entry_per_iteration-10              83.00 ± 1%    82.00 ± 1%  -1.20% (p=0.010 n=10)
Receiver/10_Log_entries_per_iteration-10           510.0 ± 0%    509.0 ± 0%  -0.20% (p=0.001 n=10)
Receiver/100_Log_entries_per_iteration-10         4.734k ± 0%   4.734k ± 0%       ~ (p=1.000 n=10) ¹
Receiver/1_000_Log_entries_per_iteration-10       47.36k ± 0%   47.34k ± 0%  -0.04% (p=0.000 n=10)
Receiver/10_000_Log_entries_per_iteration-10      473.5k ± 0%   473.4k ± 0%  -0.03% (p=0.000 n=10)
Receiver/100_000_Log_entries_per_iteration-10     4.735M ± 0%   4.734M ± 0%  -0.03% (p=0.000 n=10)
Receiver/1_000_000_Log_entries_per_iteration-10   47.35M ± 0%   47.34M ± 0%  -0.03% (p=0.000 n=10)
geomean                                           51.85k        51.74k       -0.22%

@bacherfl, this appears to show a ~60% increase in CPU consumption, but the earlier (single run) result showed just about the opposite. Just double checking, is it possible before/after were switched?

@djaglowski this does seem a bit odd, I will double check the results again

I just re-ran the tests and got the same results - However I noticed that I posted the sync results (i.e. after) before the async (before) results in the single run results, so that may have been misleading. Considering this, the results seem to be consistent also with the multiple-run results

Copy link
Member

@djaglowski djaglowski left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for taking this on @bacherfl.

The performance hit is unfortunate but it appears necessary to increase reliability (and maintainability).

@djaglowski djaglowski merged commit c840e69 into open-telemetry:main Nov 7, 2024
158 checks passed
@github-actions github-actions bot added this to the next release milestone Nov 7, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

[pkg/stanza] Make Stanza adapter more synchronous by removing channels and workers
4 participants