-
Notifications
You must be signed in to change notification settings - Fork 463
feat(profiling): add threading.RLock support to the Lock profiler (re-entrant lock) #14823
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
base: main
Are you sure you want to change the base?
Conversation
|
944b340
to
c17cd90
Compare
Bootstrap import analysisComparison of import times between this PR and base. SummaryThe average import time from this PR is: 238 ± 2 ms. The average import time from base is: 240 ± 2 ms. The import time difference between this PR and base is: -2.5 ± 0.09 ms. Import time breakdownThe following import paths have shrunk:
|
Performance SLOsComparing candidate vlad/lock-profiler-add-rlock (45abc7f) with baseline main (b766bf5) 🟡 Near SLO Breach (5 suites)🟡 djangosimple - 30/30✅ appsecTime: ✅ 20.473ms (SLO: <22.300ms -8.2%) vs baseline: +0.2% Memory: ✅ 65.477MB (SLO: <67.000MB -2.3%) vs baseline: +5.0% ✅ exception-replay-enabledTime: ✅ 1.344ms (SLO: <1.450ms -7.3%) vs baseline: +0.3% Memory: ✅ 64.643MB (SLO: <67.000MB -3.5%) vs baseline: +5.1% ✅ iastTime: ✅ 20.421ms (SLO: <22.250ms -8.2%) vs baseline: -0.3% Memory: ✅ 65.495MB (SLO: <67.000MB -2.2%) vs baseline: +5.0% ✅ profilerTime: ✅ 15.543ms (SLO: <16.550ms -6.1%) vs baseline: +1.9% Memory: ✅ 53.949MB (SLO: <54.500MB 🟡 -1.0%) vs baseline: +5.2% ✅ resource-renamingTime: ✅ 20.528ms (SLO: <21.750ms -5.6%) vs baseline: ~same Memory: ✅ 65.464MB (SLO: <67.000MB -2.3%) vs baseline: +4.9% ✅ span-code-originTime: ✅ 26.146ms (SLO: <28.200ms -7.3%) vs baseline: ~same Memory: ✅ 67.472MB (SLO: <69.500MB -2.9%) vs baseline: +4.6% ✅ tracerTime: ✅ 20.433ms (SLO: <21.750ms -6.1%) vs baseline: -0.2% Memory: ✅ 65.434MB (SLO: <67.000MB -2.3%) vs baseline: +4.8% ✅ tracer-and-profilerTime: ✅ 22.552ms (SLO: <23.500ms -4.0%) vs baseline: +2.3% Memory: ✅ 66.917MB (SLO: <67.500MB 🟡 -0.9%) vs baseline: +5.3% ✅ tracer-dont-create-db-spansTime: ✅ 19.332ms (SLO: <21.500ms 📉 -10.1%) vs baseline: ~same Memory: ✅ 65.514MB (SLO: <66.000MB 🟡 -0.7%) vs baseline: +4.8% ✅ tracer-minimalTime: ✅ 16.590ms (SLO: <17.500ms -5.2%) vs baseline: -0.3% Memory: ✅ 65.391MB (SLO: <66.000MB 🟡 -0.9%) vs baseline: +4.8% ✅ tracer-nativeTime: ✅ 20.486ms (SLO: <21.750ms -5.8%) vs baseline: +0.2% Memory: ✅ 71.376MB (SLO: <72.500MB 🟡 -1.6%) vs baseline: +4.9% ✅ tracer-no-cachesTime: ✅ 18.412ms (SLO: <19.650ms -6.3%) vs baseline: -0.2% Memory: ✅ 65.432MB (SLO: <67.000MB -2.3%) vs baseline: +4.8% ✅ tracer-no-databasesTime: ✅ 18.742ms (SLO: <20.100ms -6.8%) vs baseline: ~same Memory: ✅ 65.403MB (SLO: <67.000MB -2.4%) vs baseline: +4.8% ✅ tracer-no-middlewareTime: ✅ 20.134ms (SLO: <21.500ms -6.4%) vs baseline: -0.2% Memory: ✅ 65.382MB (SLO: <67.000MB -2.4%) vs baseline: +4.8% ✅ tracer-no-templatesTime: ✅ 20.239ms (SLO: <22.000ms -8.0%) vs baseline: -0.1% Memory: ✅ 65.450MB (SLO: <67.000MB -2.3%) vs baseline: +4.8% 🟡 errortrackingdjangosimple - 6/6✅ errortracking-enabled-allTime: ✅ 17.998ms (SLO: <19.850ms -9.3%) vs baseline: -0.5% Memory: ✅ 65.215MB (SLO: <66.500MB 🟡 -1.9%) vs baseline: +4.8% ✅ errortracking-enabled-userTime: ✅ 18.048ms (SLO: <19.400ms -7.0%) vs baseline: ~same Memory: ✅ 65.156MB (SLO: <66.500MB -2.0%) vs baseline: +4.7% ✅ tracer-enabledTime: ✅ 18.085ms (SLO: <19.450ms -7.0%) vs baseline: +0.3% Memory: ✅ 65.215MB (SLO: <66.500MB 🟡 -1.9%) vs baseline: +4.9% 🟡 flasksimple - 18/18✅ appsec-getTime: ✅ 4.580ms (SLO: <4.750ms -3.6%) vs baseline: ~same Memory: ✅ 61.991MB (SLO: <65.000MB -4.6%) vs baseline: +4.8% ✅ appsec-postTime: ✅ 6.571ms (SLO: <6.750ms -2.7%) vs baseline: -0.2% Memory: ✅ 61.912MB (SLO: <65.000MB -4.8%) vs baseline: +4.7% ✅ appsec-telemetryTime: ✅ 4.573ms (SLO: <4.750ms -3.7%) vs baseline: -0.1% Memory: ✅ 61.971MB (SLO: <65.000MB -4.7%) vs baseline: +4.8% ✅ debuggerTime: ✅ 1.866ms (SLO: <2.000ms -6.7%) vs baseline: +0.7% Memory: ✅ 45.456MB (SLO: <47.000MB -3.3%) vs baseline: +4.9% ✅ iast-getTime: ✅ 1.881ms (SLO: <2.000ms -6.0%) vs baseline: +0.7% Memory: ✅ 42.369MB (SLO: <49.000MB 📉 -13.5%) vs baseline: +4.8% ✅ profilerTime: ✅ 1.914ms (SLO: <2.100ms -8.8%) vs baseline: ~same Memory: ✅ 46.498MB (SLO: <47.000MB 🟡 -1.1%) vs baseline: +4.8% ✅ resource-renamingTime: ✅ 3.381ms (SLO: <3.650ms -7.4%) vs baseline: -0.2% Memory: ✅ 52.239MB (SLO: <53.500MB -2.4%) vs baseline: +4.9% ✅ tracerTime: ✅ 3.378ms (SLO: <3.650ms -7.4%) vs baseline: +0.4% Memory: ✅ 52.219MB (SLO: <53.500MB -2.4%) vs baseline: +4.7% ✅ tracer-nativeTime: ✅ 3.368ms (SLO: <3.650ms -7.7%) vs baseline: -0.3% Memory: ✅ 58.283MB (SLO: <60.000MB -2.9%) vs baseline: +4.9% 🟡 otelspan - 22/22✅ add-eventTime: ✅ 42.641ms (SLO: <47.150ms -9.6%) vs baseline: +1.1% Memory: ✅ 44.425MB (SLO: <47.000MB -5.5%) vs baseline: +4.7% ✅ add-metricsTime: ✅ 317.350ms (SLO: <344.800ms -8.0%) vs baseline: +0.4% Memory: ✅ 594.649MB (SLO: <600.000MB 🟡 -0.9%) vs baseline: +4.8% ✅ add-tagsTime: ✅ 288.177ms (SLO: <314.000ms -8.2%) vs baseline: +0.3% Memory: ✅ 596.701MB (SLO: <600.000MB 🟡 -0.5%) vs baseline: +4.9% ✅ get-contextTime: ✅ 80.844ms (SLO: <92.350ms 📉 -12.5%) vs baseline: +0.4% Memory: ✅ 39.946MB (SLO: <46.500MB 📉 -14.1%) vs baseline: +4.9% ✅ is-recordingTime: ✅ 38.855ms (SLO: <44.500ms 📉 -12.7%) vs baseline: -0.1% Memory: ✅ 43.911MB (SLO: <47.500MB -7.6%) vs baseline: +4.7% ✅ record-exceptionTime: ✅ 58.560ms (SLO: <67.650ms 📉 -13.4%) vs baseline: -0.5% Memory: ✅ 40.253MB (SLO: <47.000MB 📉 -14.4%) vs baseline: +4.7% ✅ set-statusTime: ✅ 44.711ms (SLO: <50.400ms 📉 -11.3%) vs baseline: -0.7% Memory: ✅ 43.944MB (SLO: <47.000MB -6.5%) vs baseline: +4.8% ✅ startTime: ✅ 38.268ms (SLO: <43.450ms 📉 -11.9%) vs baseline: +0.3% Memory: ✅ 43.909MB (SLO: <47.000MB -6.6%) vs baseline: +4.7% ✅ start-finishTime: ✅ 82.834ms (SLO: <88.000ms -5.9%) vs baseline: ~same Memory: ✅ 34.524MB (SLO: <46.500MB 📉 -25.8%) vs baseline: +4.7% ✅ start-finish-telemetryTime: ✅ 85.674ms (SLO: <89.000ms -3.7%) vs baseline: +1.2% Memory: ✅ 34.564MB (SLO: <46.500MB 📉 -25.7%) vs baseline: +4.9% ✅ update-nameTime: ✅ 40.237ms (SLO: <45.150ms 📉 -10.9%) vs baseline: +0.3% Memory: ✅ 44.152MB (SLO: <47.000MB -6.1%) vs baseline: +4.7% 🟡 span - 26/26✅ add-eventTime: ✅ 20.659ms (SLO: <22.500ms -8.2%) vs baseline: -0.2% Memory: ✅ 50.348MB (SLO: <53.000MB -5.0%) vs baseline: +4.8% ✅ add-metricsTime: ✅ 90.265ms (SLO: <93.500ms -3.5%) vs baseline: -1.3% Memory: ✅ 660.931MB (SLO: <961.000MB 📉 -31.2%) vs baseline: +4.8% ✅ add-tagsTime: ✅ 148.722ms (SLO: <155.000ms -4.1%) vs baseline: +0.6% Memory: ✅ 661.417MB (SLO: <962.500MB 📉 -31.3%) vs baseline: +4.8% ✅ get-contextTime: ✅ 19.339ms (SLO: <20.500ms -5.7%) vs baseline: +0.1% Memory: ✅ 49.137MB (SLO: <53.000MB -7.3%) vs baseline: +4.8% ✅ is-recordingTime: ✅ 19.633ms (SLO: <20.500ms -4.2%) vs baseline: -0.3% Memory: ✅ 49.229MB (SLO: <53.000MB -7.1%) vs baseline: +5.0% ✅ record-exceptionTime: ✅ 38.546ms (SLO: <40.000ms -3.6%) vs baseline: +0.2% Memory: ✅ 42.755MB (SLO: <53.000MB 📉 -19.3%) vs baseline: +4.7% ✅ set-statusTime: ✅ 21.298ms (SLO: <22.000ms -3.2%) vs baseline: +0.1% Memory: ✅ 49.182MB (SLO: <53.000MB -7.2%) vs baseline: +5.0% ✅ startTime: ✅ 19.238ms (SLO: <20.500ms -6.2%) vs baseline: +0.6% Memory: ✅ 49.256MB (SLO: <53.000MB -7.1%) vs baseline: +5.1% ✅ start-finishTime: ✅ 51.484ms (SLO: <52.500ms 🟡 -1.9%) vs baseline: -0.2% Memory: ✅ 32.145MB (SLO: <34.000MB -5.5%) vs baseline: +4.7% ✅ start-finish-telemetryTime: ✅ 53.039ms (SLO: <54.500ms -2.7%) vs baseline: +0.6% Memory: ✅ 32.126MB (SLO: <34.000MB -5.5%) vs baseline: +4.9% ✅ start-finish-traceid128Time: ✅ 55.812ms (SLO: <56.000ms 🟡 -0.3%) vs baseline: +1.8% Memory: ✅ 32.145MB (SLO: <34.000MB -5.5%) vs baseline: +4.9% ✅ start-traceid128Time: ✅ 19.974ms (SLO: <22.500ms 📉 -11.2%) vs baseline: +2.7% Memory: ✅ 49.105MB (SLO: <53.000MB -7.3%) vs baseline: +4.9% ✅ update-nameTime: ✅ 20.493ms (SLO: <22.000ms -6.8%) vs baseline: +2.0% Memory: ✅ 49.787MB (SLO: <53.000MB -6.1%) vs baseline: +5.0%
|
195b3c8
to
22f1608
Compare
cbe5cdd
to
a7fb6e2
Compare
0520a6b
to
4c62a2c
Compare
79da982
to
3f50634
Compare
3f50634
to
7e7549f
Compare
435e9ec
to
5faff64
Compare
…lector tests fail
…belong with threading)
5faff64
to
259091d
Compare
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.
One worry i had in mind when doing something similar to this was the fact that some threading classes (Condition, Event) internally use Lock(). Fortunately, RLock
doesn't use it and use _allocate_lock()
to create its internal lock instance.
For Condition
and Event
, how do you plan to implement the profiler?
Co-authored-by: Taegyun Kim <[email protected]>
Co-authored-by: Taegyun Kim <[email protected]>
Can you share an example of something concerning about this fact? In my view, this is actually a desired effect: complex primitives that use Lock in their implementation, such as Condition and Event, should correctly attribute time spent creating / calling both complex and simple primitives (e.g. by including the calls
I'm still fleshing this out, but given the above statement, I plan to modify Example:
Option 1
, where Option 1 In fact, this approach should work for all of the complex primitives that are implemented with either Notes
Types implementing |
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.
The PR looks mostly good.
One thing to check
- How these samples/events would show up on the timeline viz
https://www.datadoghq.com/blog/continuous-profiler-timeline-view/
PROF-12721
Description
This PR adds profiling support for a new kind of synchronization mechanism: Reentrant Lock. A RLock is a lock that can be acquired by the same thread multiple times without blocking on itself. From the documentation:
This feature was identified as one of the most - low-hanging-fruits, since
RLock
s are being used extensively in Python world.Changes
ThreadingRLockCollector
class inthreading.py
profiler.py
test_threading.py
module has been updated to reuse existing tests for bothLock
andRLock
primitives (via new inheritance)test_global_locks
test rewritten extensively to support the unit test code reuse betweenLock
andRLock
(effectively duplicating the existing extensiveLock
unit tests forRLock
... without the code duplication)Testing
Risks
none
Additional Notes