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

[SVLS-4142] Create a cold start span only when a cold start has not already occurred #22202

Merged
merged 26 commits into from
Apr 23, 2024

Conversation

DylanLovesCoffee
Copy link
Contributor

@DylanLovesCoffee DylanLovesCoffee commented Jan 19, 2024

What does this PR do?

Checks whether a cold start request ID has been recorded (from a restored execution context) prior to creating a cold start span. Typically this should not be needed since we use sync.Once to process the span just once, but after a runtime is killed in the Lambda environment during the INVOKE phase, on the next invocation the ColdStartSpanCreator is reinitialized and the sync.Once counter is reset to a value of done: 0 rather than done: 1, resulting in another cold start span being created. This will always happen on an invocation that follows a killed runtime.

This is noticeable if a cold start invocation hits an out of memory or timeout error. The subsequent invocation will have a trace with another cold start span. The work being done to introduce the Impending Timeout span also makes this noticeable:

coldstartspan.mov

Motivation

An argument can be made that after the runtime is killed from a time out or out of memory error, the next invocation must re-initialize the Lambda environment again so it is a cold start. This specific scenario appears to be classified as a suppressed init: https://docs.aws.amazon.com/lambda/latest/dg/telemetry-schema-reference.html#InitPhase.

Additional Notes

Possible Drawbacks / Trade-offs

Describe how to test/QA your changes

Reviewer's Checklist

  • If known, an appropriate milestone has been selected; otherwise the Triage milestone is set.
  • Use the major_change label if your change either has a major impact on the code base, is impacting multiple teams or is changing important well-established internals of the Agent. This label will be use during QA to make sure each team pay extra attention to the changed behavior. For any customer facing change use a releasenote.
  • A release note has been added or the changelog/no-changelog label has been applied.
  • Changed code has automated tests for its functionality.
  • Adequate QA/testing plan information is provided. Except if the qa/skip-qa label, with required either qa/done or qa/no-code-change labels, are applied.
  • At least one team/.. label has been applied, indicating the team(s) that should QA this change.
  • If applicable, docs team has been notified or an issue has been opened on the documentation repo.
  • If applicable, the need-change/operator and need-change/helm labels have been applied.
  • If applicable, the k8s/<min-version> label, indicating the lowest Kubernetes version compatible with this feature.
  • If applicable, the config template has been updated.

@DylanLovesCoffee DylanLovesCoffee added kind/bug changelog/no-changelog [deprecated] qa/skip-qa - use other qa/ labels [DEPRECATED] Please use qa/done or qa/no-code-change to skip creating a QA card team/serverless qa/done QA done before merge and regressions are covered by tests labels Jan 19, 2024
@DylanLovesCoffee DylanLovesCoffee added this to the Triage milestone Jan 19, 2024
@DylanLovesCoffee DylanLovesCoffee requested a review from a team as a code owner January 19, 2024 21:03
@DylanLovesCoffee DylanLovesCoffee removed the [deprecated] qa/skip-qa - use other qa/ labels [DEPRECATED] Please use qa/done or qa/no-code-change to skip creating a QA card label Mar 4, 2024
Base automatically changed from dylan/timeout-trace to main April 12, 2024 20:03
Copy link
Contributor

Serverless Benchmark Results

BenchmarkStartEndInvocation comparison between 728165e and e07141d.

tl;dr
  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.

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                           92.85µ ± 10%   88.04µ ± 14%  -5.18% (p=0.015 n=10)
api-gateway-kong-appsec.json                      73.67µ ±  1%   67.78µ ±  2%  -8.00% (p=0.000 n=10)
api-gateway-kong.json                             71.66µ ±  2%   66.81µ ±  1%  -6.77% (p=0.000 n=10)
api-gateway-non-proxy-async.json                  112.5µ ±  3%   105.1µ ±  1%  -6.53% (p=0.000 n=10)
api-gateway-non-proxy.json                        108.9µ ±  1%   105.0µ ±  2%  -3.59% (p=0.001 n=10)
api-gateway-websocket-connect.json                72.33µ ±  2%   70.19µ ±  2%  -2.96% (p=0.000 n=10)
api-gateway-websocket-default.json                64.60µ ±  1%   62.60µ ±  1%  -3.09% (p=0.000 n=10)
api-gateway-websocket-disconnect.json             64.64µ ±  2%   62.34µ ±  2%  -3.56% (p=0.000 n=10)
api-gateway.json                                  119.8µ ±  1%   117.8µ ±  1%  -1.64% (p=0.000 n=10)
application-load-balancer.json                    65.42µ ±  1%   63.69µ ±  2%  -2.64% (p=0.000 n=10)
cloudfront.json                                   50.37µ ±  3%   48.38µ ±  3%  -3.94% (p=0.000 n=10)
cloudwatch-events.json                            39.20µ ±  2%   39.04µ ±  1%       ~ (p=0.971 n=10)
cloudwatch-logs.json                              68.91µ ±  2%   68.84µ ±  2%       ~ (p=0.912 n=10)
custom.json                                       32.05µ ±  2%   31.16µ ±  3%  -2.76% (p=0.001 n=10)
dynamodb.json                                     97.99µ ±  2%   96.98µ ±  1%  -1.03% (p=0.007 n=10)
empty.json                                        30.98µ ±  5%   30.21µ ±  3%  -2.48% (p=0.005 n=10)
eventbridge-custom.json                           44.56µ ±  1%   42.08µ ±  4%  -5.56% (p=0.000 n=10)
http-api.json                                     78.85µ ±  2%   74.96µ ±  1%  -4.94% (p=0.000 n=10)
kinesis-batch.json                                74.06µ ±  3%   73.51µ ±  2%       ~ (p=0.218 n=10)
kinesis.json                                      56.33µ ±  2%   55.66µ ±  2%       ~ (p=0.075 n=10)
s3.json                                           62.22µ ±  2%   60.29µ ±  2%  -3.11% (p=0.000 n=10)
sns-batch.json                                    95.73µ ±  2%   91.50µ ±  1%  -4.42% (p=0.000 n=10)
sns.json                                          68.45µ ±  2%   66.77µ ±  2%  -2.46% (p=0.009 n=10)
snssqs.json                                       119.8µ ±  2%   113.9µ ±  1%  -4.96% (p=0.000 n=10)
snssqs_no_dd_context.json                         106.5µ ±  1%   102.0µ ±  0%  -4.27% (p=0.000 n=10)
sqs-aws-header.json                               59.57µ ±  3%   57.53µ ±  3%  -3.43% (p=0.000 n=10)
sqs-batch.json                                   101.65µ ±  6%   95.25µ ±  3%  -6.30% (p=0.000 n=10)
sqs.json                                          74.26µ ±  2%   69.42µ ±  3%  -6.52% (p=0.000 n=10)
sqs_no_dd_context.json                            65.65µ ±  3%   62.55µ ±  3%  -4.71% (p=0.000 n=10)
geomean                                           70.66µ         68.03µ        -3.72%

                                      │ baseline/benchmark.log │        current/benchmark.log        │
                                      │          B/op          │     B/op      vs base               │
api-gateway-appsec.json                           37.13Ki ± 0%   37.13Ki ± 0%       ~ (p=0.643 n=10)
api-gateway-kong-appsec.json                      26.80Ki ± 0%   26.79Ki ± 0%       ~ (p=0.423 n=10)
api-gateway-kong.json                             24.29Ki ± 0%   24.29Ki ± 0%       ~ (p=0.100 n=10)
api-gateway-non-proxy-async.json                  47.95Ki ± 0%   47.94Ki ± 0%       ~ (p=0.239 n=10)
api-gateway-non-proxy.json                        47.14Ki ± 0%   47.15Ki ± 0%       ~ (p=0.926 n=10)
api-gateway-websocket-connect.json                25.37Ki ± 0%   25.37Ki ± 0%       ~ (p=0.362 n=10)
api-gateway-websocket-default.json                21.28Ki ± 0%   21.27Ki ± 0%       ~ (p=0.287 n=10)
api-gateway-websocket-disconnect.json             21.06Ki ± 0%   21.05Ki ± 0%       ~ (p=0.196 n=10)
api-gateway.json                                  49.46Ki ± 0%   49.46Ki ± 0%       ~ (p=0.644 n=10)
application-load-balancer.json                    22.24Ki ± 0%   22.23Ki ± 0%       ~ (p=0.671 n=10)
cloudfront.json                                   17.57Ki ± 0%   17.57Ki ± 0%       ~ (p=0.190 n=10)
cloudwatch-events.json                            11.61Ki ± 0%   11.62Ki ± 0%       ~ (p=0.137 n=10)
cloudwatch-logs.json                              53.29Ki ± 0%   53.29Ki ± 0%       ~ (p=0.565 n=10)
custom.json                                       9.651Ki ± 0%   9.646Ki ± 0%       ~ (p=0.239 n=10)
dynamodb.json                                     40.60Ki ± 0%   40.59Ki ± 0%       ~ (p=0.448 n=10)
empty.json                                        9.207Ki ± 0%   9.196Ki ± 0%       ~ (p=0.540 n=10)
eventbridge-custom.json                           13.33Ki ± 0%   13.33Ki ± 0%       ~ (p=0.987 n=10)
http-api.json                                     23.67Ki ± 0%   23.62Ki ± 0%       ~ (p=0.075 n=10)
kinesis-batch.json                                26.94Ki ± 0%   26.94Ki ± 0%       ~ (p=0.671 n=10)
kinesis.json                                      17.75Ki ± 0%   17.73Ki ± 0%       ~ (p=0.896 n=10)
s3.json                                           20.25Ki ± 0%   20.26Ki ± 0%       ~ (p=0.739 n=10)
sns-batch.json                                    38.58Ki ± 0%   38.56Ki ± 0%       ~ (p=0.404 n=10)
sns.json                                          23.94Ki ± 0%   23.92Ki ± 0%       ~ (p=0.700 n=10)
snssqs.json                                       50.61Ki ± 0%   50.55Ki ± 0%  -0.11% (p=0.011 n=10)
snssqs_no_dd_context.json                         44.80Ki ± 0%   44.73Ki ± 0%  -0.15% (p=0.011 n=10)
sqs-aws-header.json                               18.79Ki ± 0%   18.80Ki ± 0%       ~ (p=0.971 n=10)
sqs-batch.json                                    41.59Ki ± 0%   41.58Ki ± 0%       ~ (p=0.353 n=10)
sqs.json                                          25.56Ki ± 0%   25.47Ki ± 0%  -0.36% (p=0.043 n=10)
sqs_no_dd_context.json                            20.60Ki ± 1%   20.64Ki ± 0%       ~ (p=0.353 n=10)
geomean                                           25.62Ki        25.61Ki       -0.04%

                                      │ baseline/benchmark.log │        current/benchmark.log        │
                                      │       allocs/op        │ allocs/op   vs base                 │
api-gateway-appsec.json                             629.5 ± 0%   629.0 ± 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%   725.0 ± 0%       ~ (p=0.350 n=10)
api-gateway-non-proxy.json                          716.0 ± 0%   716.0 ± 0%       ~ (p=0.582 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               369.0 ± 0%   369.0 ± 0%       ~ (p=1.000 n=10)
api-gateway.json                                    790.0 ± 0%   790.0 ± 0%       ~ (p=1.000 n=10)
application-load-balancer.json                      351.5 ± 0%   351.0 ± 0%       ~ (p=1.000 n=10)
cloudfront.json                                     284.0 ± 0%   283.0 ± 0%       ~ (p=0.070 n=10)
cloudwatch-events.json                              220.0 ± 0%   220.0 ± 0%       ~ (p=1.000 n=10) ¹
cloudwatch-logs.json                                215.0 ± 0%   215.0 ± 0%       ~ (p=0.582 n=10)
custom.json                                         168.0 ± 0%   168.0 ± 0%       ~ (p=1.000 n=10) ¹
dynamodb.json                                       589.0 ± 0%   589.0 ± 0%       ~ (p=0.721 n=10)
empty.json                                          159.0 ± 1%   159.0 ± 0%       ~ (p=1.000 n=10)
eventbridge-custom.json                             253.5 ± 0%   254.0 ± 0%       ~ (p=1.000 n=10)
http-api.json                                       433.0 ± 0%   432.0 ± 0%       ~ (p=0.080 n=10)
kinesis-batch.json                                  390.0 ± 0%   390.0 ± 0%       ~ (p=1.000 n=10)
kinesis.json                                        285.0 ± 0%   285.0 ± 0%       ~ (p=0.854 n=10)
s3.json                                             357.0 ± 0%   357.5 ± 0%       ~ (p=0.722 n=10)
sns-batch.json                                      455.0 ± 0%   454.0 ± 0%       ~ (p=0.391 n=10)
sns.json                                            323.0 ± 0%   323.0 ± 0%       ~ (p=1.000 n=10)
snssqs.json                                         446.5 ± 0%   446.0 ± 0%       ~ (p=0.061 n=10)
snssqs_no_dd_context.json                           400.5 ± 0%   399.0 ± 0%  -0.37% (p=0.030 n=10)
sqs-aws-header.json                                 273.0 ± 1%   273.5 ± 0%       ~ (p=0.947 n=10)
sqs-batch.json                                      504.0 ± 1%   503.5 ± 0%       ~ (p=0.325 n=10)
sqs.json                                            352.0 ± 0%   350.5 ± 0%  -0.43% (p=0.027 n=10)
sqs_no_dd_context.json                              324.5 ± 1%   325.0 ± 0%       ~ (p=0.509 n=10)
geomean                                             376.5        376.3       -0.05%
¹ all samples are equal

@pr-commenter
Copy link

pr-commenter bot commented Apr 22, 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=32626796 --os-family=ubuntu

@pr-commenter
Copy link

pr-commenter bot commented Apr 22, 2024

Regression Detector

Regression Detector Results

Run ID: 8789a510-6119-455e-b219-065aa793b640
Baseline: 5ec593d
Comparison: 2f9e6fb

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.

Experiments ignored for regressions

Regressions in experiments with settings containing erratic: true are ignored.

perf experiment goal Δ mean % Δ mean % CI
file_to_blackhole % cpu utilization +22.95 [+17.36, +28.53]

Fine details of change detection per experiment

perf experiment goal Δ mean % Δ mean % CI
file_to_blackhole % cpu utilization +22.95 [+17.36, +28.53]
basic_py_check % cpu utilization +1.03 [-1.36, +3.41]
uds_dogstatsd_to_api_cpu % cpu utilization +0.85 [-2.03, +3.73]
pycheck_1000_100byte_tags % cpu utilization +0.43 [-3.85, +4.70]
process_agent_real_time_mode memory utilization +0.32 [+0.27, +0.36]
file_tree memory utilization +0.27 [+0.18, +0.37]
tcp_dd_logs_filter_exclude ingress throughput +0.01 [-0.04, +0.06]
uds_dogstatsd_to_api ingress throughput +0.01 [-0.20, +0.21]
otel_to_otel_logs ingress throughput -0.00 [-0.38, +0.37]
trace_agent_msgpack ingress throughput -0.00 [-0.01, +0.01]
trace_agent_json ingress throughput -0.00 [-0.02, +0.01]
process_agent_standard_check_with_stats memory utilization -0.24 [-0.30, -0.19]
idle memory utilization -0.43 [-0.48, -0.38]
process_agent_standard_check memory utilization -0.85 [-0.91, -0.78]
tcp_syslog_to_blackhole ingress throughput -7.89 [-28.46, +12.68]

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".

@DylanLovesCoffee
Copy link
Contributor Author

/merge

@dd-devflow
Copy link

dd-devflow bot commented Apr 23, 2024

🚂 MergeQueue

Pull request added to the queue.

This build is next! (estimated merge in less than 49m)

Use /merge -c to cancel this operation!

@dd-mergequeue dd-mergequeue bot merged commit 83daf1c into main Apr 23, 2024
208 checks passed
@dd-mergequeue dd-mergequeue bot deleted the dylan/cold-start-span-restarts branch April 23, 2024 13:35
@github-actions github-actions bot modified the milestones: Triage, 7.54.0 Apr 23, 2024
alexgallotta pushed a commit that referenced this pull request May 9, 2024
…lready occurred (#22202)

* create a Lambda span on timeouts

* don't create a cold start span when the runtime restarts during timeouts

* fix linting

* fix test

* lint: rename name variables

* lint again

* small fixes

* refactor timeout span logic

* add mutexes

* fix span completed check

* revert refactor

* remove cold start span changes

* use mutex over rwmutex

* test routes

* add comment + update tests

* test endExecutionSpan

* add serverless.go test

* add test /hello for route

* prevent additional cold start spans from being created after runtime is killed

* fix bad conflict merge

* fix test
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
changelog/no-changelog kind/bug qa/done QA done before merge and regressions are covered by tests team/serverless
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants