ddtrace/tracer: reduce lock contention for spans #1775

felixge · 2023-03-03T12:15:18Z

What does this PR do?

Optimizes the concurrent generation of random span IDs using sync.Pool. The old code used a naive mutex approach that seems to have been copied from the stdlib without proper attribution.

go version: 1.20

goos: linux
goarch: amd64
pkg: gopkg.in/DataDog/dd-trace-go.v1/ddtrace/tracer
cpu: Intel(R) Xeon(R) Platinum 8375C CPU @ 2.90GHz
                     │ before.txt  │              after.txt              │
                     │   sec/op    │   sec/op     vs base                │
ConcurrentTracing-32   706.7µ ± 4%   583.7µ ± 5%  -17.40% (p=0.000 n=10)

Before:

After:

Motivation

#1774 causes a small regression in performance, so I took a quick look to see what's going on and noticed the high lock contention on span generation.

Describe how to test/QA your changes

Reviewer's Checklist

If known, an appropriate milestone has been selected; otherwise the Triage milestone is set.
Changed code has unit tests for its functionality.
If this interacts with the agent in a new way, a system test has been added.

goos: darwin goarch: arm64 pkg: gopkg.in/DataDog/dd-trace-go.v1/ddtrace/tracer │ before.txt │ after.txt │ │ sec/op │ sec/op vs base │ ConcurrentTracing-10 823.9µ ± 2% 589.5µ ± 6% -28.44% (p=0.000 n=10)

pr-commenter · 2023-03-03T12:18:15Z

Benchmarks

Benchmark execution time: 2024-05-28 13:51:43

Comparing candidate commit 46f8df3 in PR branch felix.geisendoerfer/reduce-span-contention with baseline commit 464e078 in branch main.

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

felixge · 2023-03-03T12:30:38Z

scenario:BenchmarkConcurrentTracing-24

🟩 execution_time [-0.091ms; -0.079ms] or [-8.872%; -7.706%]

This is less than what I'm reporting in the issue description. I think the reason is that the machine I used has 32 logical cores and our benchmark uses 24. Lock contention gets worse with a higher number of cores.

felixge · 2023-03-03T16:51:10Z

Will debug the test failure.

felixge · 2023-03-03T20:22:16Z

Tests are green ✅ - Ready for review.

ajgajg1134

Looks good! Cool to see sync.Pool being used, I don't think I've ever seen it used before

felixge · 2023-03-04T14:48:46Z

Looks good! Cool to see sync.Pool being used, I don't think I've ever seen it used before

Yeah, it's probably best to stay away from it in most cases 😅, but I think the reduced lock contention here makes it worth it.

Since this is pretty mission critical, I'm also adding @nsrip-dd as a reviewer. We need to ensure that this change doesn't increase the chance of spandID collisions or other problems.

nsrip-dd

This lead me down quite a rabbit hole 😄 The biggest difficulty in reviewing this is that I don't know what the expectations are for the quality of trace/span ID generation. Over what time period do they need to be unique? Over the life of a single process? Across all traffic from an individual customer for some time? Across all customers?

The math/rand RNG truncates its seeds to 32 bits. My biggest concern with this change is that it will increase the likelihood that dd-trace-go apps produce trace/span IDs with the same seed close together. Rather than seeding once at the start of the process, it could be seeded arbitrarily many times over the lifetime of a process (e.g. if the RNG gets garbage collected while it's in the pool).

Maybe we need to investigate using an RNG with a bigger seed space? I did a little poking around and something from the PCG family seems like it might be good. Each seed selects a different, uncorrelated random sequence, and a second value can be used to start at a random spot within the sequence. The Rust authors have some good writing on RNGs as well. But... this is a little out of my depth.

nsrip-dd · 2023-03-06T13:52:03Z

ddtrace/tracer/rand.go

+	// This is pretty much optimal for avoiding contention.
+	r := randPool.Get().(*rand.Rand)
+	// NOTE: TestTextMapPropagator fails if we return r.Uint64() here. Seems like
+	// span ids are expected to be 64 bit with the first bit being 0?


I'm pretty sure span IDs can be full-size 64 bit unsigned integers. The problem is that tests in textmap_test.go are asserting the formatted span IDs match strconv.Itoa(int(childSpanID)) (noticed the signed, platform-dependent-sized integer), when they should match strconv.FormatUint(childSpanID, 10). I recall that tests actually also fail on 32-bit archs when they shouldn't. So really, the tests should be fixed.

Actually these tests might be related to past problem processing full 64 bits IDs in languages like Node.JS and Java (IIRC)

Not sure if this limitation is still valid.

nsrip-dd · 2023-03-06T15:44:16Z

ddtrace/tracer/rand.go

+			}
+			// seedSeq makes sure we don't create two generators with the same seed
+			// by accident.
+			return rand.New(rand.NewSource(seed + atomic.AddInt64(&seedSeq, 1)))


Small thing, but I think seedSeq is only needed if we have to fall back to the timestamp. The resolution of the timestamp might be such that two random sources created close together get the seed. In that case, and assuming time.Now is monotonic, seedSeq would indeed prevent the same seed being used multiple times in the same process. Across process, all bets are off when using timestamps as a seed, with or without seedSeq.

But if we can successfully use the cryptograph RNG source, I don't think the seed needs to be changed. We should already have as low of a chance of collision as we could hope to get.

time.Now is monotonic, seedSeq would indeed prevent the same seed being used multiple times in the same process. Across process, all bets are off when using timestamps as a seed, with or without seedSeq.

As I understand Pool uses thread local underneath - this is niice! Definitely how this rand should be implemented! :)

Since the initialization cost will be amortized, you could add process id and a hash of a hostname, to ensure the seed is more unique.

Also to avoid a chance of collisions more I would recommend more transformative operations than Add. e.g. multiply or shift would ensure that seeds created in sequence will definitely not collide. However value Overflow will need to be handled to ensure bits are not lost.

For the same reason its best to not modify the crypto acquired seed - it should already be good enough 🤞

But if we can successfully use the cryptograph RNG source, I don't think the seed needs to be changed. We should already have as low of a chance of collision as we could hope to get.

ajgajg1134 · 2023-03-07T16:24:06Z

The math/rand RNG truncates its seeds to 32 bits. My biggest concern with this change is that it will increase the likelihood that dd-trace-go apps produce trace/span IDs with the same seed close together. Rather than seeding once at the start of the process, it could be seeded arbitrarily many times over the lifetime of a process (e.g. if the RNG gets garbage collected while it's in the pool).

This truncated 32 bit seed is something we've already run into as an issue and to reduce the likelihood of collisions we added this here: https://github.com/DataDog/dd-trace-go/blob/main/ddtrace/tracer/tracer.go#L520
If this further increases our likelihood of a seed collision that might cause problems? But I think that the XOR with span start time should hopefully protect us in the small change two tracers get the same seed, it's unlikely they would also be at the same point in their generator AND start a span at the same time (hopefully?)

katiehockman · 2023-11-28T20:54:16Z

@felixge is this something you feel is ready to merge? Is there anything my team can help with to get it over the finish line?

felixge · 2023-11-28T21:45:00Z

@katiehockman maybe 😅. Any reason this is on your radar right now? I could try to make some time tomorrow to re-read the latest comments and see if this is ready from my PoV.

katiehockman · 2023-11-28T21:46:32Z

@felixge no particular reason. I'm just trying to clean up the backlog. If we aren't sure about this PR and want to just close it, and re-open it later if/when we feel it's ready, that's another option. Or can mark it with the do-not-merge/WIP label, and that'll remove it from our review filters.

darccio · 2024-05-28T13:30:49Z

@felixge I wonder if #2689 supersedes this PR once 1.22 becomes our oldest supported version.

ddtrace/tracer: reduce lock contention for spans

fbca8cb

goos: darwin goarch: arm64 pkg: gopkg.in/DataDog/dd-trace-go.v1/ddtrace/tracer │ before.txt │ after.txt │ │ sec/op │ sec/op vs base │ ConcurrentTracing-10 823.9µ ± 2% 589.5µ ± 6% -28.44% (p=0.000 n=10)

felixge added this to the v1.49.0 milestone Mar 3, 2023

felixge marked this pull request as ready for review March 3, 2023 12:29

felixge requested a review from a team March 3, 2023 12:29

felixge added 2 commits March 3, 2023 20:22

fix test failure

5b539c5

be more paranoid about collisions

e25e8fd

felixge force-pushed the felix.geisendoerfer/reduce-span-contention branch from 9f63e5a to e25e8fd Compare March 3, 2023 19:48

document how the optimization works

2bc284b

ajgajg1134 approved these changes Mar 3, 2023

View reviewed changes

felixge requested a review from nsrip-dd March 4, 2023 14:09

nsrip-dd reviewed Mar 7, 2023

View reviewed changes

felixge added 2 commits June 27, 2023 15:52

Merge branch 'main' into felix.geisendoerfer/reduce-span-contention

72b5eaf

Merge branch 'main' into felix.geisendoerfer/reduce-span-contention

a40f4b9

katiehockman added the stale Stuck for more than 1 month label Jan 29, 2024

Merge branch 'main' into felix.geisendoerfer/reduce-span-contention

46f8df3

darccio requested a review from a team as a code owner May 28, 2024 13:27

darccio added do-not-merge/WIP and removed stale Stuck for more than 1 month labels Oct 1, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

ddtrace/tracer: reduce lock contention for spans #1775

ddtrace/tracer: reduce lock contention for spans #1775

felixge commented Mar 3, 2023 •

edited

Loading

pr-commenter bot commented Mar 3, 2023 •

edited

Loading

felixge commented Mar 3, 2023

scenario:BenchmarkConcurrentTracing-24

felixge commented Mar 3, 2023

felixge commented Mar 3, 2023

ajgajg1134 left a comment

felixge commented Mar 4, 2023

nsrip-dd left a comment

nsrip-dd Mar 6, 2023

pawelchcki Apr 18, 2023

nsrip-dd Mar 6, 2023

pawelchcki Apr 18, 2023

ajgajg1134 commented Mar 7, 2023

katiehockman commented Nov 28, 2023

felixge commented Nov 28, 2023

katiehockman commented Nov 28, 2023

darccio commented May 28, 2024

ddtrace/tracer: reduce lock contention for spans #1775

Are you sure you want to change the base?

ddtrace/tracer: reduce lock contention for spans #1775

Conversation

felixge commented Mar 3, 2023 • edited Loading

What does this PR do?

Motivation

Describe how to test/QA your changes

Reviewer's Checklist

pr-commenter bot commented Mar 3, 2023 • edited Loading

Benchmarks

felixge commented Mar 3, 2023

scenario:BenchmarkConcurrentTracing-24

felixge commented Mar 3, 2023

felixge commented Mar 3, 2023

ajgajg1134 left a comment

Choose a reason for hiding this comment

felixge commented Mar 4, 2023

nsrip-dd left a comment

Choose a reason for hiding this comment

nsrip-dd Mar 6, 2023

Choose a reason for hiding this comment

pawelchcki Apr 18, 2023

Choose a reason for hiding this comment

nsrip-dd Mar 6, 2023

Choose a reason for hiding this comment

pawelchcki Apr 18, 2023

Choose a reason for hiding this comment

ajgajg1134 commented Mar 7, 2023

katiehockman commented Nov 28, 2023

felixge commented Nov 28, 2023

katiehockman commented Nov 28, 2023

darccio commented May 28, 2024

felixge commented Mar 3, 2023 •

edited

Loading

pr-commenter bot commented Mar 3, 2023 •

edited

Loading