What does a yellow bar on a temporal flamegraph chart represent?

[gh-andre]

This is a temporal flamegraph chart with that yellow bar. Its width depends on the time range zoom, so it appears to show some event over this time frame. I cannot find any references in the docs what the yellow bar shown here means. Thanks!

[gh-andre]

One place in the docs says that the high water mark will be highlighted, even though does not say how. If that's what it is, I would expect it to be placed at the highest heap usage, but on the chart below, the heap value at the beginning of the yellow bar is 135.7 MB and on the left side the heap value is 142.8 MB, so the yellow bark is not at the peak.

If it is indeed the highest allocation point, could it be because pymalloc is being tracked here and the heap value does not reflect the actual allocation being used by the Python code? In other words, does it mean that the higher heap usage on the left does not reflect actual active Python allocations (i.e. includes pending GC, latent references, etc) and is actually less than the total amount of actual active Python allocations in the high water mark frame?

If this interpretation is correct, is there a way to show the actual allocation amounts that are presented when I hover over call stack frames, which I'm assuming actual memory sizes the Python code is using at any given time.

[godlygeek]

One place in the docs says that the high water mark will be highlighted, even though does not say how.

Yep, that's exactly what it is: it's highlighting that the moment where the process reached its highest heap memory was in that time slice.

I would expect it to be placed at the highest heap usage, but on the chart below, the heap value at the beginning of the yellow bar is 135.7 MB and on the left side the heap value is 142.8 MB, so the yellow bar is not at the peak.

Ah, yes. That's a bit confusing, but it isn't wrong...

If it is indeed the highest allocation point, could it be because pymalloc is being tracked here and the heap value does not reflect the actual allocation being used by the Python code? In other words, does it mean that the higher heap usage on the left does not reflect actual active Python allocations (i.e. includes pending GC, latent references, etc) and is actually less than the total amount of actual active Python allocations in the high water mark frame?

Nope, it's not that, just that the line graph at the top has coarser granularity than the flame graph itself at the bottom. The docs say:

In this mode, the flame graph can show you not just one point in time, but instead the usage over time (with approximately 10 millisecond granularity by default).

What we see here is that, at the left side of the pale yellow bar, the heap memory is 135.7 MB, and at the right side of the pale yellow bar approximately 10ms later, the heap memory is also 135.7 MB (at least as far as I can tell without being able to see the tooltips), but Memray still insists that the heap high water mark was within that 10ms interval. That means that at some point during that 10ms interval, heap usage spiked up to above 142.8 MB, and then it dropped back down before the end of that 10ms interval. If you mouse over the top box labeled <root> in the flamegraph, the tooltip should tell you how many total bytes of heap memory were allocated at the point in time that it's showing to you, and it should report something greater than or equal to 142.8 MB.

The reason this winds up this way is that we don't know the exact timestamp of any given allocation, we just know the timestamp of the most recent "checkpoint" (for lack of a better word, but that's not exactly right). The records marking allocations and deallocations in our capture file aren't themselves associated with a timestamp, because it would slow us down too much to need to ask the OS for the current time every time an allocation or deallocation happens. Instead, those allocation and deallocation records are interleaved with another type of record, which is stamped out on a timer by a background thread, approximately every 10ms. So far any given allocation, we know a timestamp that it necessarily came after, and a timestamp that it necessarily came before, but not the exact time that it happened at. We know that the heap memory usage was reached somewhere in that yellow box, but we don't know when, and can't show it on the line chart in a way that wouldn't be misleading (I guess maybe we could put a synthetic point on the graph directly at the midpoint of the time slice, but that's still pretty misleading; it certainly implies that we know more about when two things happened in relation to each other than what we actually know).

[gh-andre]

Thank you for a very detailed answer. I see what you are saying about peak memory usage within the 10ms of the high water mark frame, but still cannot arrive at the actual memory usage. Let me explain what I see.

So both sides of the high water mark say 135.7 MB. The left side is at 457ms and the right is at 549ms. When I hover over root, it says 82.2 MiB, which even if I convert it to MB will only be 86.2 MB, so there's still quite a bit of heap allocation not accounted for between 135.7 MB and 86.2 MB. I must be missing something here.

Also, thank you for the detailed explanation about time stamps. I see the challenge here. I would probably do it the same way - key frames and offsets in between.

[godlygeek]

With regards to <root> allocations, will it track only the underlying malloc calls (on top of pymalloc) or it will also see mmap allocations?

mmap is included as well. Every allocator we track is - the list is currently

memray/src/memray/_memray/hooks.h

Lines 26 to 52 in 8d5267b

	#if defined(__APPLE__)
	# define MEMRAY_PLATFORM_HOOKED_FUNCTIONS
	#elif defined(__GLIBC__)
	# define MEMRAY_PLATFORM_HOOKED_FUNCTIONS \
	FOR_EACH_HOOKED_FUNCTION(memalign) \
	FOR_EACH_HOOKED_FUNCTION(prctl) \
	FOR_EACH_HOOKED_FUNCTION(pvalloc) \
	FOR_EACH_HOOKED_FUNCTION(mmap64)
	#else
	# define MEMRAY_PLATFORM_HOOKED_FUNCTIONS \
	FOR_EACH_HOOKED_FUNCTION(memalign) \
	FOR_EACH_HOOKED_FUNCTION(prctl)
	#endif
	#define MEMRAY_HOOKED_FUNCTIONS \
	FOR_EACH_HOOKED_FUNCTION(malloc) \
	FOR_EACH_HOOKED_FUNCTION(free) \
	FOR_EACH_HOOKED_FUNCTION(calloc) \
	FOR_EACH_HOOKED_FUNCTION(realloc) \
	FOR_EACH_HOOKED_FUNCTION(valloc) \
	FOR_EACH_HOOKED_FUNCTION(posix_memalign) \
	FOR_EACH_HOOKED_FUNCTION(aligned_alloc) \
	FOR_EACH_HOOKED_FUNCTION(mmap) \
	FOR_EACH_HOOKED_FUNCTION(munmap) \
	FOR_EACH_HOOKED_FUNCTION(dlopen) \
	FOR_EACH_HOOKED_FUNCTION(dlclose) \
	FOR_EACH_HOOKED_FUNCTION(PyGILState_Ensure) \

(There's a few non-allocation functions we hook as well, like PyGILState_Ensure and prctl, you can ignore those.)

We know that we're currently missing free_sized and free_aligned_sized, but that wouldn't account for what you're seeing; we'd be overcounting in both the line graph and the <root> node in the flame graph. I really can't think of a reason for them not to match other than a bug. Maybe we're discarding some particular allocation as uninteresting in one place and counting it in the other, or something like that, but I can't remember a case where we do that, and it would be very strange for us to consider so many MB of allocations "uninteresting"...

[gh-andre]

This is very useful. Thank you very much for all of your insights. It is much appreciated. I will post more once I can reproduce this behavior on a standalone example.

[gh-andre]

I spent a bunch of time trying to reproduce the amount in <root> being less than the number shown on the chart and I can only see in that bigger app that I cannot share and not in my smaller tests. I will keep an eye on it and if I manage to hunt it down to a smaller reproducible case, I will create an issue.

[jder]

I am having similar symptoms in my project:

• The temporal view's yellow highlight does not correspond to the curves in the graph. The explanation above that there's an spike between two keyframes from the graph seems reasonable but as I move the window around the timeline the yellow highlight seems consistently wrong. I guess it's possible that there's some consistent spiking (I guess large but very temporary allocations?) but there's different code running along different parts of the timeline so it seems unlikely to me.
• The total memory usage shown in the flamegraph is much lower than the numbers shown on the usage graph. For example, here I have zoomed in on an area with a memory usage consistently around 20GB and the total listed in the flamegraph is 917MB.

• The docs say that a flamegraph without --temporal should find the same peak usage as the temporal graph before changing the inspection window. When I produce a non-temporal graph, I see a different flamegraph which does match with the visible peak of usage. Here is the initial view of the temporal graph:

And the non-temporal one:

This kinda suggests to me that peak finding is somehow not working in temporal mode only?

I am checking to see if I can share the profile with you. In the meantime, if it helps, I'm using memray 1.17.1 on macOS 15.4.1 (arm64) with Python 3.11.9 as uv run python -m memray run -o output.bin --native my_module and then uv run python -m memray flamegraph [--temporal] --force output.bin and then opening the resulting graph in Chrome.

[godlygeek]

• The docs say that a flamegraph without --temporal should find the same peak usage as the temporal graph before changing the inspection window. When I produce a non-temporal graph, I see a different flamegraph

OK, then there's definitely a bug of some sort here. The two should absolutely match. I've opened #757 for it.

When I get a chance I'll play around with temporal reporting and see if I can stumble upon a reproducer. Whatever's going on here should actually be pretty easy to track down and fix. You've narrowed the scope of where the problem can be quite a lot, but a capture file that reproduces the problem would still be a big help.