@rsc @RLH @aclements @randall77 @Sajmani @bcmills

I'm increasingly of the opinion that it's more important to have a mode that reports the current state of the heap than it is to have the "stable" mode that we have now (that is, I'm not necessarily opposed to having both, but the current state should be the default and if we only have one, it should be the current state).

Most often, people want to answer the question "what is consuming my process's memory"? The "stable" view does not answer that, but a "current" view would. This question comes in many related flavors, such as "why is my RSS x?" and "why was my process OOM-killed?" People try to answer this question using the "stable" heap profile and get confused and unhappy (rightfully so) when the answer doesn't make sense (and doesn't match MemStats) and they blame it on the Go memory manager.

The "stable" view is interesting and certainly well-defined, but I'm having trouble formulating exactly what question it answers, and that's a problem. It's something like "where is my retained memory going?", but that seems like clearly a secondary question to "where is my memory going?" ("Why is my memory being retained?" is a very useful question, but we don't have any tool that can answer that right now.)

The "stable" view can also be actively misleading. For example, if there are large allocations that quickly become garbage, they will almost never show up in the "stable" view, but they would be likely to show up in a "current" view. This makes the "current" view more useful for answering the question "why is my process garbage collecting as often as it is?" Strictly speaking, this does show up in the raw data exported by the runtime as large values of both allocated and freed memory at a site, but most analysis tools reveal only the difference between allocated and freed and I do not believe complicating the presentation of the data is the answer to this (even members of the Go team at Google I've spoken with who have dealt with this problem didn't realize this raw data was there).

The "stable" view is also currently slightly wrong, I think. I haven't checked this in detail, but I think it currently counts floating garbage; it would have to delay by yet one more GC cycle to eliminate this. This is only tangentially related to this issue, but it is related in that it seems clear to me we don't want to delay the data even more than we currently do, and that suggests that delaying the data by any significant amount is a mistake.

What about pprof --alloc_space/--alloc_objects? It seems like that addresses this point almost exactly, but is still more well-defined.

This question comes in many related flavors, such as "why is my RSS x?" and "why was my process OOM-killed?"

"Current" profile won't help to answer these questions (unless you capture the profile in kill handler, which is slightly separate topic). To answer these questions you need profile at the beginning of GC cycle (or "max" stable profile; for concurrent GC it probably should be samples between marking and sweeping). The maximum heap is what determines RSS. Consider that GC runs once per several minutes, if you just sample "current" heap, you almost never will see the maximum.

I suspect that "current' profile will lead even to more confusion, because you can observe profile closer to min, or to max, or somewhere in between and see radically different numbers. And even if you understand that you are sampling "current", it is difficult to understand where are you between min and max and how to interpret these numbers.

What about pprof --alloc_space/--alloc_objects? It seems like that addresses this point almost exactly, but is still more well-defined.

How can they help to understand RSS?
I see only how to use them for performance optimization: alloc_space helps to reduce frequency of GCs, alloc_objects helps to reduce malloc overhead.

As an example of how current memory profiles are confusing: I wrote a program that allocates 500 1M slices and retains them all. pprof reports that it is using 225M. If I call runtime.GC, the heap profile catches up and pprof reports on the full 500M.

The program uses 500M of memory, it has no garbage, and yet pprof reports a figure half its total memory consumption. Results are the same with --alloc_space/--inuse_space.

One thought: I think the most useful information that we do not currently provide would be heap contents at the last time memory was requested from the system. This directly addresses the question of what determined the current RSS, especially when the RSS is determined by a transient spike in memory usage.

I've been thinking about this more in response to an internal bug. I think there are several confusions around the heap profile, but underpinning many of them is the subtle but crucial difference between a heap profile and a memory profile. People are confused because they're trying to account for their process' RSS, but the memory reported by the OS and the memory reported by the heap profile are off by, well, about a factor of 2. If you don't understand how the Go memory manager works, it's natural to think that that memory must be going somewhere else, or that the heap profile is wrong.

I proposed in #15848 that the heap profile should also report totals for non-GC'd runtime allocation pools (stack memory, etc), mainly for debugging. But we could take that a step further and also report the amount of "unused heap" memory (there's probably a clearer term), so that the total reported by the heap profile actually matches the amount of memory the OS is reporting. I believe this information is already in the raw heap profile, it just isn't shown in any way. This wouldn't allay all confusion or solve all problems with the heap profile, but it would at least point people at why the allocation total doesn't match the process' RSS.

(For another common situation, figuring out why your process OOM'ed, I think switching to core files for the heap dump would put us on a path to being able to write a separate tool for answering this question.)

Do we know how pprof handles garbages in Java?

• Michael Matloob

On Mon, Jul 25, 2016 at 11:13 AM Hyang-Ah Hana Kim notifications@github.com
wrote:

Do we know how pprof handles garbages in Java?

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
#13463 (comment), or mute
the thread
https://github.com/notifications/unsubscribe-auth/AJSK3dVzD3NfecBqzpN_gHIz8jiketXuks5qZNKogaJpZM4Gt55r
.

I'm warming to Dmitry's original proposal, though I believe I think about it somewhat differently: rather than having several new modes (people already don't know about/are confused by the existing modes), the heap profiler should understand not just the "live" allocations as of the last GC, but also the allocations that became "dead", and it should show both simultaneously (in a visually distinguishable way). I'm also assuming the new profile information should represent the heap at the beginning of mark termination, not the beginning of GC (maybe that's really what Dmitry meant).

Unlike a "current heap profile", this "dead" heap profile is reasonably stable, since it captures the last heap peak, just like the existing profile captures the last heap trough. It's not as stable as the existing profile, since invoking runtime.GC() is idempotent against the existing profile, but not against the peak profile; however, it is stable in the steady state. I think it's also reasonably easy to explain.

If we can have pprof show a unified profile indicating both live and dead allocation samples as of the last GC, it would be significantly easier to profile transient garbage. I think this would be generally more useful than --alloc_* for two reasons: 1) it shows instantaneous garbage rather than cumulative garbage, which is more useful in multi-phase or long-running applications and in tracking down transient heap growth, and 2) it extends the current default in-use view, so people could get a lot more information from the default view without having to know about or dive in to the other modes.

I like the idea of showing the dead allocations as of the last mark termination. It fits in nicely with the existing "snapshot of heap usage" model but would also be useful for troubleshooting high allocation rates (not just large allocations), and it would clear up a lot of the "RSS vs. heap profile" confusion for folks who aren't used to thinking in terms of garbage collection.

One that I think would be very useful is live allocations as of the last
time memory was requested from the OS--i.e., what allocations caused the
actual process size to increase? This would aid in diagnosing growth caused
by transient spikes in allocations.

On Mon, Jul 25, 2016 at 12:16 PM, Bryan C. Mills notifications@github.com
wrote:

I like the idea of showing the dead allocations as of the last mark
termination. It fits in nicely with the existing "snapshot of heap usage"
model but would also be useful for troubleshooting high allocation rates
(not just large allocations), and it would clear up a lot of the "RSS vs.
heap profile" confusion for folks who aren't used to thinking in terms of
garbage collection.

—
You are receiving this because you commented.
Reply to this email directly, view it on GitHub
#13463 (comment), or mute
the thread
https://github.com/notifications/unsubscribe-auth/AADNQLJLM5RsjO01o9k86a4NXmPGBPZCks5qZQufgaJpZM4Gt55r
.

I think @neild is proposing snapshotting the whole heap profile as of process growth (and perhaps reporting all allocations, not just "live" ones?), not just sampling the allocation that caused process growth.

I believe that's technically feasible, though I worry about the performance cost of it, since there's some cost to taking that snapshot and when the process grows it tends to grow several times in quick succession. I also worry a bit about the cognitive cost of having another profiling mode, though perhaps it would make sense to expose it as a distinct class of profile, since the semantics are fairly different from the existing heap profile. Also, in the worst case of process growth, when you get an OOM, it's too late to get any useful profile out of the runtime, so I think the answer has to be a tool that can extract a profile out of a core file (which we're working towards).

How can we make forward progress here? @aclements @dvyukov

How can we make forward progress here? @aclements @dvyukov

I'm opposed to adding new modes to the heap profile, and would much rather enhance the existing modes to provide a differentiated profile of some form (I proposed one possibility, but there may be others). However, if we do want to have a differentiated profile, I believe the right way to do that is with labels, in which case this depends on #16093. That's fine, but it means this will have to sit for a while.

I'll take this out of the proposal process then and just track it as normal.

#16093 was accepted and included in go1.8.
Can some of the ideas discussed here be implemented in go1.9 cycle?

--
I'd still argue that 'current' view is more useful than 'stable' view even though the 'current' view is in between min/max. By capturing profiles multiple times, users may be lucky to capture the moment close to max, which is more useful in practice.

If the heap profile includes any allocations since the last GC as well. (@aclements mentioned reporting of 'dead' allocations above, but what I mean here are rather 'new' allocations. Some of them may be dead or some may be still alive).

With the new feature introduced by #16093, we can label the new allocations specially. pprof works as before, but with a special flag, it can report the sum of 'live' and 'new' which approximates 'current'.

The OOM killer we are currently dealing with captures heap profile before killing a process in a container. In that case, this information is useful in debugging the OOM situation.

--
Answering to my previous question... In Java, its heap dump or inspector is so powerful (it supports both 'after gc' and 'current' mode), users use heap dump instead of heap profile.

As a specific case: I've got a process with a HeapIdle of ~5GB and a HeapInUse of ~300MB. Memory profile shows about 100MB.

Clearly at some point in the past this program had at least 2.5GB of live data, which has since become garbage and been collected. I want to know what that data was.

How do I find this out, other than by time travelling or figuring out how to replicate the spike?

CL https://golang.org/cl/37335 mentions this issue.