Skip to content

perf(profiling): speed up stack walking by using function run_time_cache - #1949

Merged
realFlowControl merged 15 commits into
masterfrom
levi/run-time-cache
Mar 22, 2023
Merged

perf(profiling): speed up stack walking by using function run_time_cache#1949
realFlowControl merged 15 commits into
masterfrom
levi/run-time-cache

Conversation

@morrisonlevi

@morrisonlevi morrisonlevi commented Mar 1, 2023

Copy link
Copy Markdown
Collaborator

Description

This is for PHP 8 only. It uses two slots in the function run_time_cache to store:

  • The function name, which looks something like "module|Namespace\\ClassName::method".
  • The file name.

These two strings are interned and live between requests. This allows us to share them as Cow<'static, str> with the ddprof_time thread (fewer copies).

This is not ZTS safe. The profiler doesn't support ZTS yet anyway, I'm just pointing this out informationally.

This is not using PHP's own interning. It uses a OwnedStringTable which allocates the string data in an arena, and deduplicates using a HashMap. It also holds references to the strings in a contiguous Vec; this property is not particularly useful for this PR, but it probably will be in the future with some libdatadog work. This string_table module has cherry-picked bits from that libdatadog work-in-process.

Also fixes the initial Vec size in the ddprof_time thread when converting a SampleMessage into a Sample for libdatadog. I noticed this while reviewing profiles that it was spending a good amount of time allocating.

Readiness checklist

  • Changelog has been added to the release document.
  • Tests added for this feature/bug.

Reviewer checklist

  • Appropriate labels assigned.
  • Milestone is set.

@morrisonlevi morrisonlevi added the profiling Relates to the Continuous Profiler label Mar 1, 2023
@morrisonlevi morrisonlevi added this to the future milestone Mar 1, 2023
@morrisonlevi

Copy link
Copy Markdown
Collaborator Author

Numbers time! Using the Datadog native profiler, I analyzed memory and CPU characteristics. Here's the short version:

  • When just wall-time and cpu-time are enabled, CPU and latency are about the same, but down slightly. The number of allocations and bytes allocated are also down.
  • When wall-time, cpu-time, and allocation profiling are enabled, then it's a clear win. CPU time spent stack walking is down ~55%, and allocated bytes are down ~35%.

In all cases, the total memory in use goes up a bit as the OwnedStringTable lives essentially forever in thread-local storage.

Some screenshots:

CPU time before/after. This is with allocation profiling enabled.

app datadoghq com_profiling_AYaeLMt7AABn13XN6ikcfQAA_query=service%3Asymfony-demo%20-runtime%3Azendengine event=AQAAAYaeLMoEJtXgqQAAAABBWWFlTE10N0FBQm4xM1hONmlrY2ZRQUE group_by=line my_code=disabled op_filter=show_from%28function%3A%22datad

app datadoghq com_profiling_AYaeLMZ8AABBkYx4H153YwAA_query=service%3Asymfony-demo%20-runtime%3Azendengine event=AQAAAYaeLMUJB0wRTgAAAABBWWFlTE1aOEFBQkJrWXg0SDE1M1l3QUE group_by=line my_code=disabled op_filter=show_from%28function%3A%22datad

Bytes allocated before/after. Again, with allocation profiling enabled.

app datadoghq com_profiling_AYaeE3pmAABn13XN6iIVegAA_query=runtime%3Anative%20service%3Asymfony-demo event=AQAAAYaeE3mCH9LgqQAAAABBWWFlRTNwbUFBQm4xM1hONmlJVmVnQUE group_by=line my_code=disabled op_filter=show_from%28function%3A%22datado (1)

app datadoghq com_profiling_AYaeE3fvAACx9iETN3_ewgAA_query=runtime%3Anative%20service%3Asymfony-demo event=AQAAAYaeE3dHRc9nFgAAAABBWWFlRTNmdkFBQ3g5aUVUTjNfZXdnQUE group_by=line my_code=disabled op_filter=show_from%28function%3A%22datado (1)

@morrisonlevi
morrisonlevi marked this pull request as ready for review March 1, 2023 21:29
@morrisonlevi
morrisonlevi requested review from a team as code owners March 1, 2023 21:29
@morrisonlevi morrisonlevi modified the milestones: future, 0.85.0 Mar 1, 2023
@morrisonlevi morrisonlevi added the Overhead Relates to latency, CPU, or memory overhead label Mar 2, 2023
Comment thread profiling/src/string_table/bump_owned.rs
Comment thread profiling/src/profiling/stalk_walking.rs
Comment thread profiling/src/profiling/stalk_walking.rs
Comment thread profiling/src/php_ffi.c
Comment thread profiling/src/php_ffi.c
@morrisonlevi morrisonlevi changed the title perf(profiling): speed up stalk walking by using function run_time_cache perf(profiling): speed up stack walking by using function run_time_cache Mar 2, 2023
Comment thread profiling/src/string_table/owned.rs
Comment thread profiling/src/string_table/borrowed.rs
Comment thread profiling/src/string_table/borrowed.rs
Comment thread profiling/src/string_table/owned.rs
Comment thread profiling/src/string_table/bump_owned.rs
@bwoebi bwoebi modified the milestones: 0.85.0, 0.86.0 Mar 9, 2023
@realFlowControl
realFlowControl merged commit 6c541e4 into master Mar 22, 2023
@realFlowControl
realFlowControl deleted the levi/run-time-cache branch March 22, 2023 11:40
@Anilm3 Anilm3 mentioned this pull request Mar 22, 2023
morrisonlevi added a commit that referenced this pull request Mar 29, 2023
…_time_cache (#1949)"

This reverts commit 6c541e4.

Changes made by this commit are showing up in backtraces in crash dumps:
#1993
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Overhead Relates to latency, CPU, or memory overhead profiling Relates to the Continuous Profiler

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants