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

Set timeout for requests made by the EVP proxy #26336

Merged
merged 3 commits into from
Jun 10, 2024

Conversation

albertvaka
Copy link
Contributor

@albertvaka albertvaka commented Jun 4, 2024

Motivation

Despite the trace-agent API server having a timeout (that defaults to 5 seconds), requests to the EVP proxy endpoint could continue running past this timeout because they were not cancelled themselves. In either case we would close the connection with the client without propagating the response from the server, but we would take way longer than intended.

Describe how to test/QA your changes

Before the patch (and hardcoding the endpoint to a local python server that takes 8 seconds to respond):

$ time curl -v 127.0.0.1:8126/evp_proxy/v1/
*   Trying 127.0.0.1:8126...
* Connected to 127.0.0.1 (127.0.0.1) port 8126
> GET /evp_proxy/v1/ HTTP/1.1
> Host: 127.0.0.1:8126
> User-Agent: curl/8.4.0
> Accept: */*
> 
* Empty reply from server
* Closing connection
curl: (52) Empty reply from server

real	0m8.033s
user	0m0.006s
sys	0m0.010s

After the patch:

$ time curl -v 127.0.0.1:8126/evp_proxy/v1/
*   Trying 127.0.0.1:8126...
* Connected to 127.0.0.1 (127.0.0.1) port 8126
> GET /evp_proxy/v1/ HTTP/1.1
> Host: 127.0.0.1:8126
> User-Agent: curl/8.4.0
> Accept: */*
> 
* Empty reply from server
* Closing connection
curl: (52) Empty reply from server

real	0m5.033s
user	0m0.006s
sys	0m0.010s

Both close the connection without response, but the first one goes over the timeout.

@albertvaka albertvaka added this to the 7.56.0 milestone Jun 4, 2024
@albertvaka albertvaka requested a review from a team as a code owner June 4, 2024 15:00
Copy link

codecov bot commented Jun 4, 2024

Codecov Report

All modified and coverable lines are covered by tests ✅

Project coverage is 70.24%. Comparing base (f4e0649) to head (89c8a3e).
Report is 34 commits behind head on main.

Additional details and impacted files
@@             Coverage Diff             @@
##             main   #26336       +/-   ##
===========================================
+ Coverage   44.96%   70.24%   +25.28%     
===========================================
  Files        2353      123     -2230     
  Lines      272670    10969   -261701     
===========================================
- Hits       122595     7705   -114890     
+ Misses     140403     2906   -137497     
+ Partials     9672      358     -9314     
Flag Coverage Δ
amzn_aarch64 70.15% <100.00%> (+24.34%) ⬆️
centos_x86_64 70.19% <100.00%> (+24.47%) ⬆️
ubuntu_aarch64 70.21% <100.00%> (+24.41%) ⬆️
ubuntu_x86_64 70.24% <100.00%> (+24.44%) ⬆️
windows_amd64 68.24% <100.00%> (+17.44%) ⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

@albertvaka albertvaka force-pushed the albertvaka/evp-proxy-timeout branch from 65b2507 to a58d386 Compare June 4, 2024 15:25
@pr-commenter

This comment has been minimized.

@albertvaka albertvaka requested review from a team as code owners June 4, 2024 15:59
@pr-commenter

This comment has been minimized.

Copy link
Contributor

github-actions bot commented Jun 4, 2024

Serverless Benchmark Results

BenchmarkStartEndInvocation comparison between fb139ec and 6a7aace.

tl;dr

Use these benchmarks as an insight tool during development.

  1. Skim down the vs base column in each chart. If there is a ~, then there was no statistically significant change to the benchmark. Otherwise, ensure the estimated percent change is either negative or very small.

  2. The last row of each chart is the geomean. Ensure this percentage is either negative or very small.

What is this benchmarking?

The BenchmarkStartEndInvocation compares the amount of time it takes to call the start-invocation and end-invocation endpoints. For universal instrumentation languages (Dotnet, Golang, Java, Ruby), this represents the majority of the duration overhead added by our tracing layer.

The benchmark is run using a large variety of lambda request payloads. In the charts below, there is one row for each event payload type.

How do I interpret these charts?

The charts below comes from benchstat. They represent the statistical change in duration (sec/op), memory overhead (B/op), and allocations (allocs/op).

The benchstat docs explain how to interpret these charts.

Before the comparison table, we see common file-level configuration. If there are benchmarks with different configuration (for example, from different packages), benchstat will print separate tables for each configuration.

The table then compares the two input files for each benchmark. It shows the median and 95% confidence interval summaries for each benchmark before and after the change, and an A/B comparison under "vs base". ... The p-value measures how likely it is that any differences were due to random chance (i.e., noise). The "~" means benchstat did not detect a statistically significant difference between the two inputs. ...

Note that "statistically significant" is not the same as "large": with enough low-noise data, even very small changes can be distinguished from noise and considered statistically significant. It is, of course, generally easier to distinguish large changes from noise.

Finally, the last row of the table shows the geometric mean of each column, giving an overall picture of how the benchmarks changed. Proportional changes in the geomean reflect proportional changes in the benchmarks. For example, given n benchmarks, if sec/op for one of them increases by a factor of 2, then the sec/op geomean will increase by a factor of ⁿ√2.

I need more help

First off, do not worry if the benchmarks are failing. They are not tests. The intention is for them to be a tool for you to use during development.

If you would like a hand interpreting the results come chat with us in #serverless-agent in the internal DataDog slack or in #serverless in the public DataDog slack. We're happy to help!

Benchmark stats
goos: linux
goarch: amd64
pkg: github.com/DataDog/datadog-agent/pkg/serverless/daemon
cpu: AMD EPYC 7763 64-Core Processor                
                                      │ baseline/benchmark.log │        current/benchmark.log        │
                                      │         sec/op         │    sec/op     vs base               │
api-gateway-appsec.json                            87.12µ ± 4%   87.30µ ± 13%       ~ (p=0.579 n=10)
api-gateway-kong-appsec.json                       68.46µ ± 2%   68.87µ ±  3%       ~ (p=0.315 n=10)
api-gateway-kong.json                              66.60µ ± 1%   67.83µ ±  2%  +1.84% (p=0.005 n=10)
api-gateway-non-proxy-async.json                   106.4µ ± 2%   109.3µ ±  1%  +2.71% (p=0.003 n=10)
api-gateway-non-proxy.json                         106.8µ ± 1%   108.9µ ±  1%  +1.99% (p=0.002 n=10)
api-gateway-websocket-connect.json                 70.50µ ± 1%   72.03µ ±  2%  +2.16% (p=0.000 n=10)
api-gateway-websocket-default.json                 63.78µ ± 1%   64.90µ ±  2%  +1.76% (p=0.019 n=10)
api-gateway-websocket-disconnect.json              63.66µ ± 2%   64.99µ ±  1%  +2.09% (p=0.000 n=10)
api-gateway.json                                   117.3µ ± 2%   117.6µ ±  1%       ~ (p=0.315 n=10)
application-load-balancer.json                     64.70µ ± 1%   65.62µ ±  1%  +1.42% (p=0.001 n=10)
cloudfront.json                                    48.30µ ± 1%   49.59µ ±  2%  +2.67% (p=0.001 n=10)
cloudwatch-events.json                             38.71µ ± 3%   39.46µ ±  1%       ~ (p=0.063 n=10)
cloudwatch-logs.json                               67.78µ ± 1%   70.09µ ±  2%  +3.40% (p=0.000 n=10)
custom.json                                        31.40µ ± 2%   31.23µ ±  5%       ~ (p=1.000 n=10)
dynamodb.json                                      94.16µ ± 2%   98.09µ ±  1%  +4.17% (p=0.001 n=10)
empty.json                                         29.41µ ± 1%   30.65µ ±  2%  +4.20% (p=0.000 n=10)
eventbridge-custom.json                            41.96µ ± 2%   43.86µ ±  2%  +4.52% (p=0.000 n=10)
http-api.json                                      74.93µ ± 2%   76.79µ ±  1%  +2.48% (p=0.000 n=10)
kinesis-batch.json                                 71.38µ ± 2%   73.39µ ±  2%  +2.81% (p=0.000 n=10)
kinesis.json                                       54.95µ ± 3%   55.90µ ±  2%  +1.73% (p=0.004 n=10)
s3.json                                            59.48µ ± 1%   61.32µ ±  1%  +3.09% (p=0.000 n=10)
sns-batch.json                                     89.91µ ± 2%   92.34µ ±  1%  +2.70% (p=0.003 n=10)
sns.json                                           65.43µ ± 3%   65.83µ ±  1%       ~ (p=0.579 n=10)
snssqs.json                                        112.8µ ± 1%   115.4µ ±  1%  +2.27% (p=0.001 n=10)
snssqs_no_dd_context.json                          100.4µ ± 2%   102.3µ ±  2%  +1.94% (p=0.001 n=10)
sqs-aws-header.json                                55.72µ ± 1%   57.76µ ±  3%  +3.65% (p=0.002 n=10)
sqs-batch.json                                     94.15µ ± 2%   95.99µ ±  2%  +1.96% (p=0.007 n=10)
sqs.json                                           68.59µ ± 4%   70.24µ ±  2%  +2.40% (p=0.029 n=10)
sqs_no_dd_context.json                             63.24µ ± 3%   64.50µ ±  3%       ~ (p=0.089 n=10)
geomean                                            67.66µ        69.13µ        +2.17%

                                      │ baseline/benchmark.log │        current/benchmark.log        │
                                      │          B/op          │     B/op      vs base               │
api-gateway-appsec.json                           37.19Ki ± 0%   37.19Ki ± 0%       ~ (p=0.752 n=10)
api-gateway-kong-appsec.json                      26.79Ki ± 0%   26.79Ki ± 0%       ~ (p=0.839 n=10)
api-gateway-kong.json                             24.29Ki ± 0%   24.29Ki ± 0%       ~ (p=0.197 n=10)
api-gateway-non-proxy-async.json                  48.00Ki ± 0%   48.01Ki ± 0%       ~ (p=0.838 n=10)
api-gateway-non-proxy.json                        47.22Ki ± 0%   47.23Ki ± 0%       ~ (p=0.468 n=10)
api-gateway-websocket-connect.json                25.41Ki ± 0%   25.42Ki ± 0%       ~ (p=0.183 n=10)
api-gateway-websocket-default.json                21.32Ki ± 0%   21.33Ki ± 0%       ~ (p=0.753 n=10)
api-gateway-websocket-disconnect.json             21.10Ki ± 0%   21.11Ki ± 0%       ~ (p=0.223 n=10)
api-gateway.json                                  49.46Ki ± 0%   49.46Ki ± 0%       ~ (p=0.591 n=10)
application-load-balancer.json                    23.20Ki ± 0%   23.20Ki ± 0%       ~ (p=0.470 n=10)
cloudfront.json                                   17.60Ki ± 0%   17.60Ki ± 0%       ~ (p=0.696 n=10)
cloudwatch-events.json                            11.66Ki ± 0%   11.66Ki ± 0%       ~ (p=0.566 n=10)
cloudwatch-logs.json                              53.31Ki ± 0%   53.31Ki ± 0%       ~ (p=0.361 n=10)
custom.json                                       9.677Ki ± 0%   9.670Ki ± 0%       ~ (p=0.985 n=10)
dynamodb.json                                     40.64Ki ± 0%   40.66Ki ± 0%       ~ (p=0.190 n=10)
empty.json                                        9.227Ki ± 0%   9.240Ki ± 0%       ~ (p=0.072 n=10)
eventbridge-custom.json                           13.37Ki ± 0%   13.39Ki ± 0%       ~ (p=0.836 n=10)
http-api.json                                     23.74Ki ± 0%   23.72Ki ± 0%       ~ (p=0.289 n=10)
kinesis-batch.json                                26.99Ki ± 0%   27.00Ki ± 0%       ~ (p=0.955 n=10)
kinesis.json                                      17.77Ki ± 0%   17.77Ki ± 0%       ~ (p=0.739 n=10)
s3.json                                           20.26Ki ± 0%   20.34Ki ± 0%  +0.41% (p=0.002 n=10)
sns-batch.json                                    38.56Ki ± 0%   38.62Ki ± 0%  +0.15% (p=0.045 n=10)
sns.json                                          23.91Ki ± 0%   23.92Ki ± 0%       ~ (p=0.541 n=10)
snssqs.json                                       50.62Ki ± 0%   50.65Ki ± 0%       ~ (p=0.271 n=10)
snssqs_no_dd_context.json                         44.79Ki ± 0%   44.84Ki ± 0%       ~ (p=0.280 n=10)
sqs-aws-header.json                               18.87Ki ± 0%   18.90Ki ± 0%       ~ (p=0.643 n=10)
sqs-batch.json                                    41.58Ki ± 0%   41.60Ki ± 0%       ~ (p=0.247 n=10)
sqs.json                                          25.49Ki ± 0%   25.49Ki ± 0%       ~ (p=0.699 n=10)
sqs_no_dd_context.json                            20.63Ki ± 0%   20.66Ki ± 1%       ~ (p=0.699 n=10)
geomean                                           25.68Ki        25.70Ki       +0.05%

                                      │ baseline/benchmark.log │        current/benchmark.log        │
                                      │       allocs/op        │ allocs/op   vs base                 │
api-gateway-appsec.json                             629.0 ± 0%   629.5 ± 0%       ~ (p=1.000 n=10)
api-gateway-kong-appsec.json                        488.0 ± 0%   488.0 ± 0%       ~ (p=1.000 n=10) ¹
api-gateway-kong.json                               466.0 ± 0%   466.0 ± 0%       ~ (p=1.000 n=10) ¹
api-gateway-non-proxy-async.json                    725.5 ± 0%   726.0 ± 0%       ~ (p=1.000 n=10)
api-gateway-non-proxy.json                          716.0 ± 0%   716.0 ± 0%       ~ (p=1.000 n=10)
api-gateway-websocket-connect.json                  453.0 ± 0%   453.0 ± 0%       ~ (p=1.000 n=10)
api-gateway-websocket-default.json                  379.0 ± 0%   379.0 ± 0%       ~ (p=1.000 n=10)
api-gateway-websocket-disconnect.json               370.0 ± 0%   370.0 ± 0%       ~ (p=0.211 n=10)
api-gateway.json                                    790.0 ± 0%   790.5 ± 0%       ~ (p=0.720 n=10)
application-load-balancer.json                      353.0 ± 0%   353.0 ± 0%       ~ (p=1.000 n=10) ¹
cloudfront.json                                     284.0 ± 0%   284.0 ± 0%       ~ (p=1.000 n=10)
cloudwatch-events.json                              220.0 ± 0%   220.0 ± 0%       ~ (p=1.000 n=10)
cloudwatch-logs.json                                216.0 ± 0%   216.0 ± 0%       ~ (p=1.000 n=10)
custom.json                                         168.0 ± 0%   168.0 ± 1%       ~ (p=1.000 n=10)
dynamodb.json                                       589.0 ± 0%   589.0 ± 0%       ~ (p=1.000 n=10)
empty.json                                          159.5 ± 0%   160.0 ± 1%       ~ (p=0.350 n=10)
eventbridge-custom.json                             254.0 ± 0%   254.0 ± 0%       ~ (p=1.000 n=10)
http-api.json                                       433.0 ± 0%   432.5 ± 0%       ~ (p=0.720 n=10)
kinesis-batch.json                                  391.0 ± 0%   391.0 ± 0%       ~ (p=1.000 n=10)
kinesis.json                                        285.0 ± 0%   285.0 ± 0%       ~ (p=0.582 n=10)
s3.json                                             357.0 ± 0%   358.0 ± 0%  +0.28% (p=0.009 n=10)
sns-batch.json                                      455.0 ± 0%   456.0 ± 0%  +0.22% (p=0.026 n=10)
sns.json                                            323.0 ± 0%   323.0 ± 0%       ~ (p=1.000 n=10)
snssqs.json                                         446.0 ± 0%   446.0 ± 0%       ~ (p=0.921 n=10)
snssqs_no_dd_context.json                           399.0 ± 1%   400.0 ± 0%       ~ (p=0.251 n=10)
sqs-aws-header.json                                 275.0 ± 0%   275.0 ± 0%       ~ (p=0.608 n=10)
sqs-batch.json                                      503.5 ± 0%   504.0 ± 0%       ~ (p=0.172 n=10)
sqs.json                                            351.0 ± 0%   351.0 ± 0%       ~ (p=1.000 n=10)
sqs_no_dd_context.json                              324.0 ± 0%   324.5 ± 1%       ~ (p=0.652 n=10)
geomean                                             376.7        376.9       +0.05%
¹ all samples are equal

tasks/go_deps.py Show resolved Hide resolved
Without this, a request would continue running even after our Server
(which received a request from e.g. a tracer) has already timed out and,
because of this, would not propagate the response of the request anyway.
@albertvaka albertvaka force-pushed the albertvaka/evp-proxy-timeout branch from 56eb400 to 80e32ef Compare June 4, 2024 16:29
@pr-commenter

This comment has been minimized.

@pr-commenter

This comment has been minimized.

@pr-commenter
Copy link

pr-commenter bot commented Jun 4, 2024

Test changes on VM

Use this command from test-infra-definitions to manually test this PR changes on a VM:

inv create-vm --pipeline-id=35920216 --os-family=ubuntu

@ajgajg1134
Copy link
Contributor

Hello! Is it possible to add a small unit test verifying this change instead of needing to rely on manual testing using a separate python program? Thanks!

@albertvaka albertvaka force-pushed the albertvaka/evp-proxy-timeout branch from 360a5d7 to 89c8a3e Compare June 5, 2024 12:34
@pr-commenter

This comment has been minimized.

@albertvaka
Copy link
Contributor Author

@ajgajg1134 I added a test that actually waits 1 second to test the timeout. If you think that's not okay, I can change the code to add the github.com/benbjohnson/clock dependency to be able to mock the time passing without actually wasting 1 second.

@pr-commenter
Copy link

pr-commenter bot commented Jun 5, 2024

Benchmarks

Benchmark execution time: 2024-06-05 12:45:28

Comparing candidate commit 89c8a3e in PR branch albertvaka/evp-proxy-timeout with baseline commit 30ff86b in branch main.

Found 0 performance improvements and 0 performance regressions! Performance is the same for 2 metrics, 1 unstable metrics.

Copy link
Contributor

@ajgajg1134 ajgajg1134 left a comment

Choose a reason for hiding this comment

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

looks good from APM! Thanks for adding a test, I think the unit test covers this pretty well so feel free to add a qa/done label to this PR so no manual QA jira ticket is created

@albertvaka albertvaka added the qa/done QA done before merge and regressions are covered by tests label Jun 5, 2024
@pr-commenter
Copy link

pr-commenter bot commented Jun 5, 2024

Regression Detector

Regression Detector Results

Run ID: b962a103-3e92-4b29-ba90-46156e908517
Baseline: f4e0649
Comparison: 89c8a3e

Performance changes are noted in the perf column of each table:

  • ✅ = significantly better comparison variant performance
  • ❌ = significantly worse comparison variant performance
  • ➖ = no significant change in performance

No significant changes in experiment optimization goals

Confidence level: 90.00%
Effect size tolerance: |Δ mean %| ≥ 5.00%

There were no significant changes in experiment optimization goals at this confidence level and effect size tolerance.

Fine details of change detection per experiment

perf experiment goal Δ mean % Δ mean % CI
pycheck_1000_100byte_tags % cpu utilization +0.49 [-4.31, +5.29]
otel_to_otel_logs ingress throughput +0.17 [-0.20, +0.55]
tcp_dd_logs_filter_exclude ingress throughput +0.05 [+0.01, +0.09]
trace_agent_msgpack ingress throughput +0.00 [-0.00, +0.00]
uds_dogstatsd_to_api ingress throughput -0.00 [-0.20, +0.20]
trace_agent_json ingress throughput -0.01 [-0.03, +0.01]
idle memory utilization -0.38 [-0.42, -0.34]
basic_py_check % cpu utilization -0.46 [-3.34, +2.42]
tcp_syslog_to_blackhole ingress throughput -0.89 [-22.16, +20.38]
uds_dogstatsd_to_api_cpu % cpu utilization -1.07 [-4.01, +1.87]
file_tree memory utilization -1.51 [-1.60, -1.42]

Explanation

A regression test is an A/B test of target performance in a repeatable rig, where "performance" is measured as "comparison variant minus baseline variant" for an optimization goal (e.g., ingress throughput). Due to intrinsic variability in measuring that goal, we can only estimate its mean value for each experiment; we report uncertainty in that value as a 90.00% confidence interval denoted "Δ mean % CI".

For each experiment, we decide whether a change in performance is a "regression" -- a change worth investigating further -- if all of the following criteria are true:

  1. Its estimated |Δ mean %| ≥ 5.00%, indicating the change is big enough to merit a closer look.

  2. Its 90.00% confidence interval "Δ mean % CI" does not contain zero, indicating that if our statistical model is accurate, there is at least a 90.00% chance there is a difference in performance between baseline and comparison variants.

  3. Its configuration does not mark it "erratic".

@albertvaka
Copy link
Contributor Author

/merge

@dd-devflow
Copy link

dd-devflow bot commented Jun 10, 2024

🚂 MergeQueue: pull request added to the queue

The median merge time in main is 51m.

Use /merge -c to cancel this operation!

@albertvaka
Copy link
Contributor Author

albertvaka commented Jun 10, 2024

@knusbaum I don't have permissions to merge this myself, but it looks like I can still use the merge queue flow (?)

@dd-mergequeue dd-mergequeue bot merged commit 5194aa8 into main Jun 10, 2024
225 checks passed
@dd-mergequeue dd-mergequeue bot deleted the albertvaka/evp-proxy-timeout branch June 10, 2024 18:25
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
changelog/no-changelog qa/done QA done before merge and regressions are covered by tests team/agent-apm trace-agent
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants