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

[erts] Implement call_memory tracing #6351

Merged
merged 2 commits into from
Feb 8, 2023

Conversation

max-au
Copy link
Contributor

@max-au max-au commented Oct 7, 2022

Similar to call_time, erlang:trace_pattern(..., [call_memory]) accumulates memory allocations, allowing for basic heap profiling.

Inspired by @garazdawi's prototype discussed on Erlang Forums. This PR implements only the underlying mechanism. Heap profiler itself (hprof) is in works here: 62b1846

@github-actions
Copy link
Contributor

github-actions bot commented Oct 7, 2022

CT Test Results

       3 files     133 suites   44m 44s ⏱️
1 540 tests 1 489 ✔️ 51 💤 0
1 953 runs  1 883 ✔️ 70 💤 0

Results for commit 3a529f8.

♻️ This comment has been updated with latest results.

To speed up review, make sure that you have read Contributing to Erlang/OTP and that all checks pass.

See the TESTING and DEVELOPMENT HowTo guides for details about how to run test locally.

Artifacts

// Erlang/OTP Github Action Bot

@rickard-green rickard-green added the team:VM Assigned to OTP team VM label Oct 10, 2022
@sverker
Copy link
Contributor

sverker commented Dec 1, 2022

PR looks good. I pushed minor optimizations and some bug fixes in erlang:trace_info.

We probably will retarget the PR for master and OTP 26 as it's a new feature.

@max-au
Copy link
Contributor Author

max-au commented Dec 3, 2022

Sounds good! I can rebase it on top of master branch (although I would not mind getting support for it in OTP 25).

There is a (relatively long) discussion thread on the Erlang forums about this implementation. One undecided question was, how to account memory allocation for messages?

There are couple of things that I really don't like about my PR.

  1. There is a relatively slow call size_object (which has been moved to erts_adjust_memory_break. The problem with it, it runs even when tracing is not enabled. It can be slow for messages with deeply nested terms, and will introduce a CPU regression
  2. On one hand, it sort of makes sense to delay memory allocation accounting until the process calls receive and matches the message. On the other, the usual reason to run memory profiling is when some process heap gets too large. It can be large because of the message queue, but memory profiling will not show that.

So I'm wondering whether @garazdawi suggestion to simply skip message memory makes most sense, or, to account for it immediately.

@sverker
Copy link
Contributor

sverker commented Dec 5, 2022

  1. There is a relatively slow call size_object (which has been moved to erts_adjust_memory_break.

I fixed that in 8076592.

@sverker
Copy link
Contributor

sverker commented Dec 5, 2022

Pushed some more fixes for bugs found by our non-jit test runs. And some refactoring.

@sverker
Copy link
Contributor

sverker commented Dec 5, 2022

About received messages. I think they either should be included when matched (as it is now) or maybe be totally ignored.

Another thing to consider is off-heap binaries. Should they be ignored (as now), included or added as a separate accumulator.

@max-au
Copy link
Contributor Author

max-au commented Dec 6, 2022

I has the same questions, but haven't decided which is the proper answer. The thing is, in most cases we start looking into process heaps when we get large_heap messages from erlang:system_monitor. And it gets weird when memory tracing says "nope, all good, there is nothing in your heap". :-\

Hence I decided to open this PR and discuss it with the OTP team input.
One potential behaviour would be to make it configurable (e.g. take offheap/do not take offheap), count/do not count message space. But it will make implementation even more complex.

@max-au
Copy link
Contributor Author

max-au commented Dec 8, 2022

Looks great. Please allow me a few more days to test under some load, and with new hprof module.

@max-au
Copy link
Contributor Author

max-au commented Dec 8, 2022

Is it OK if I squash the commits? Or at least the fixups, so the PR will have 2 commits, with the second containing your changes.

@sverker
Copy link
Contributor

sverker commented Dec 8, 2022

Is it OK if I squash the commits? Or at least the fixups, so the PR will have 2 commits, with the second containing your changes.

Sure. I would recommend squashing everything into one commit except

  • maybe keep "Add constants for trace stack frame sizes" as a separate commit, as it's a pure refactoring.
  • skip "erts: Cleanup from bs_construct_SUITE:bs_add", as it conflicts with master and it's not needed anyway.

@max-au
Copy link
Contributor Author

max-au commented Dec 18, 2022

Testing looks good, I tried it with various production workloads, and it works as expected. Now the only decision to make is if it can be in maint (which I was hoping for), or change the base to master (patches actually apply neatly for both branches except for a minor conflict in etp Python script).

@sverker
Copy link
Contributor

sverker commented Dec 20, 2022

Sorry, we don't think this qualify for maint. We try to keep the risk down on maint by not changing core mechanics of the execution environment. For example, the change in stack frame size (BEAM_RETURN_CALL_ACC_TRACE_FRAME_SZ) has triggered some bug related to max_heap_size that I have not completely understood yet.

About messages. The call_memory trace is more a measure of how much GC pressure a function contributes, rather than how much memory it consumes. A function producing X amount of immediate garbage per call will yield the same trace stats as another producing X amount of long lived data per call. Therefore I start thinking messages should not be part of it at all. An enqueued message is not caused by the function that happens to execute at that time and to match a message does not contribute to GC pressure as it's already allocated.

@CLAassistant
Copy link

CLAassistant commented Dec 20, 2022

CLA assistant check
All committers have signed the CLA.

@max-au max-au changed the base branch from maint to master December 20, 2022 17:56
@max-au
Copy link
Contributor Author

max-au commented Dec 20, 2022

Moved to master branch.

Completely hiding messages from accounting is just deleting erts_adjust_message_break call from erts_save_message_in_proc, but I feel uneasy about it. I can think of using off-heap message queue data to quantify receive statements in the GC pressure calculations. Since there is almost no overhead to keep message accounting, I'd prefer that to extra call process_info(Pid, messages).

@max-au
Copy link
Contributor Author

max-au commented Jan 5, 2023

I realised that this PR requires a change in the preloaded file (erlang.beam), to add a spec for trace and trace_pattern functions. Otherwise Dialyzer complains about breaking the spec when I try to use new tracing flags.

Is there anything else needed for this PR to be merged?

@max-au
Copy link
Contributor Author

max-au commented Jan 27, 2023

@sverker is it possible to add this to OTP-26RC1? I'd love to bring it to our testing too.

@sverker
Copy link
Contributor

sverker commented Jan 31, 2023

@sverker is it possible to add this to OTP-26RC1? I'd love to bring it to our testing too.

Yes I will try to do that. This PR had some problem causing debug vm to crash in gc, something related to max_heap_size. I have to take a look at that again and find a solution.

@sverker sverker added feature testing currently being tested, tag is used by OTP internal CI labels Jan 31, 2023
@KennethL KennethL added this to the OTP-26.0-rc1 milestone Feb 2, 2023
@sverker
Copy link
Contributor

sverker commented Feb 3, 2023

Pushed a fixup that avoids the max_heap_size bug(s) that I will fix in a separate PR.

@max-au Are you ok if I squash my commits into your (with you as author). I see no reason with keeping development history with known bugs.

@max-au
Copy link
Contributor Author

max-au commented Feb 4, 2023

Please do! Thanks you!

@sverker
Copy link
Contributor

sverker commented Feb 7, 2023

Late change. We really don't like the {Pid,Count,MegaWords,Words} tuple and would like to build a possible bignum instead {Pid,Count,Words}. I will do that unless you have a really good reason not to.

@max-au
Copy link
Contributor Author

max-au commented Feb 7, 2023

There is no reason other than for uniformity (with call_time). If you think it's not necessary, please go ahead. Let me know if I can be of any help.
I will update hprof PR #6639 accordingly when this change lands.

@sverker
Copy link
Contributor

sverker commented Feb 7, 2023

Let me know if I can be of any help.

Well you could look at my commit and see if I missed something.
I will squash when we're done.

@max-au
Copy link
Contributor Author

max-au commented Feb 7, 2023

Confirming that the code still works fine on Linux (64 bit) under significant load. I updated #6639 to remove the unneeded mega-words.
Good to go!

max-au and others added 2 commits February 8, 2023 11:06
Similar to call_time, erlang:trace_pattern(..., [call_memory]) accumulates
memory allocations, allowing for basic heap profiling.
@sverker sverker merged commit c0cc1fe into erlang:master Feb 8, 2023
@sverker
Copy link
Contributor

sverker commented Feb 8, 2023

Merged to master (at last). Proposed release note:

New trace feature call_memory. Similar to call_time tracing, but instead of measure accumulated time in traced functions it measures accumulated heap space consumed by traced functions. It can be used to compare how much different functions are contributing to garbage collection being triggered.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
feature team:VM Assigned to OTP team VM testing currently being tested, tag is used by OTP internal CI
Projects
None yet
Development

Successfully merging this pull request may close these issues.

6 participants