Skip to content

Add speedscope export timestamp fallback#899

Open
pablogsal wants to merge 1 commit into
bloomberg:mainfrom
pablogsal:speedscope-timestamps-fallback
Open

Add speedscope export timestamp fallback#899
pablogsal wants to merge 1 commit into
bloomberg:mainfrom
pablogsal:speedscope-timestamps-fallback

Conversation

@pablogsal

Copy link
Copy Markdown
Collaborator

Build the speedscope export around sampled stacks and make the ordering
source explicit instead of relying on the reader's iteration order.

When a capture has exact allocation timestamps, record them in the
non-aggregated file format, expose them through the reader metadata, and
sort each aggregated speedscope sample by the earliest allocation time
that contributed to it. This keeps the sampled profile aligned with the
real execution order without changing the existing high-water-mark and
leak aggregation logic.

When exact timestamps are not available, switch the speedscope path to
temporal allocation records and recover a stable approximation from the
memory snapshots we already store. Leak exports keep only intervals that
survive to the end of the run and order them by the first snapshot where
they appear. High-water-mark exports evaluate intervals at the peak
snapshot and order them by the first snapshot that contributes to that
peak.

Keep this behavior speedscope-specific and reject --aggregate with
--allocation-timestamps, because aggregated captures discard the event
ordering that the export depends on. The patch also bumps the file
format/header metadata and adds command, reader/writer, and reporter
tests for both the exact-timestamp and fallback paths.

Issue number of the reported bug or feature request: #

Describe your changes
A clear and concise description of the changes you have made.

Testing performed
Describe the testing you have performed to ensure that the bug has been addressed, or that the new feature works as planned.

Additional context
Add any other context about your contribution here.

@pablogsal
pablogsal force-pushed the speedscope-timestamps-fallback branch from 2118cc9 to 1daa4a2 Compare April 5, 2026 16:11
@pablogsal

pablogsal commented Apr 5, 2026

Copy link
Copy Markdown
Collaborator Author

@pablogsal
pablogsal force-pushed the speedscope-timestamps-fallback branch from 1daa4a2 to 31e477b Compare April 5, 2026 19:10
@codecov-commenter

codecov-commenter commented Apr 5, 2026

Copy link
Copy Markdown

Codecov Report

❌ Patch coverage is 98.33333% with 3 lines in your changes missing coverage. Please review.
✅ Project coverage is 92.29%. Comparing base (776fe15) to head (d3692c5).

Files with missing lines Patch % Lines
src/memray/reporters/transform.py 95.00% 3 Missing ⚠️
Additional details and impacted files
@@            Coverage Diff             @@
##             main     #899      +/-   ##
==========================================
+ Coverage   92.22%   92.29%   +0.06%     
==========================================
  Files          99       99              
  Lines       12556    12705     +149     
  Branches      432      442      +10     
==========================================
+ Hits        11580    11726     +146     
- Misses        976      979       +3     
Flag Coverage Δ
cpp 92.29% <98.33%> (+0.06%) ⬆️
python_and_cython 92.29% <98.33%> (+0.06%) ⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Harness.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.
  • 📦 JS Bundle Analysis: Save yourself from yourself by tracking and limiting bundle sizes in JS merges.

@godlygeek godlygeek left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm still looking through this one. I've reviewed the changes to add the allocation timestamp to every allocation record, I haven't yet really reviewed the new report. I've got a few comments on the code from the first commit.

But mostly, I'm a bit confused by why we need the per-allocation timestamp. What is it that this gives us beyond what we can already get from our temporal format? Is it just to get finer granularity rather than sticking us with the default 10ms granularity?

Comment thread src/memray/_memray/record_writer.cpp Outdated
Comment thread src/memray/_memray/record_writer.cpp Outdated
Comment thread tests/integration/test_api.py Outdated
Comment thread src/memray/_memray/tracking_api.h Outdated
const bool d_allocation_timestamps;
linker::SymbolPatcher d_patcher;
std::unique_ptr<BackgroundThread> d_background_thread;
const std::chrono::steady_clock::time_point d_monotonic_start{std::chrono::steady_clock::now()};

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is there any way that we can synchronize this to refer to the exact same moment in time as the start_time in the metadata? I think the answer is "no", but if we could it would be very nice. As it is, we can sort of say what wall clock time an event happened at, but not exactly - even setting aside clock adjustments due to NTP or whatever, or DST transitions, we'll always be off by some fixed number of microseconds due to the delta between when we get the wall clock timestamp and when we get the monotonic clock timestamp.

Like I said, I don't think there's anything we can do about that, but if there was it'd be cool...

Comment thread src/memray/_memray/record_writer.cpp Outdated
Comment thread src/memray/_memray/record_writer.cpp Outdated
@godlygeek

godlygeek commented Jul 15, 2026

Copy link
Copy Markdown
Contributor

Hm. An interesting observation, with my current favorite stress test:

memray run --trace-python-allocators --allocation-timestamps --no-compress -fo output.bin -m test test_set

82.50% of all records have a delta of 0 microseconds from the previous
17.36% of all records have a delta of 1 microsecond from the previous
0.14% of all records have a delta more than 1 microsecond from the previous

The uncompressed capture file is 184,012,800 bytes and contains 42,419,372 allocation records, and deltas of 0 or 1 are varint encoded as a single byte per allocation record, so 19% of the space in the uncompressed capture file (~35 megabytes) is spent encoding "the time hasn't changed since the last record", and an additional 4% of the capture file (~7 megabytes) is spent encoding "the time changed by 1us since the last record".

That seems very inefficient, and makes me think we want a different encoding for timestamps. I'm thinking about creating a new CLOCK_ADVANCED record type with a single flag bit. If the flag is 0 it means the clock advanced by 1us, otherwise a varint is emitted saying how many microseconds time advanced by. That means it will take 0 bytes to represent that the time is the same as the previous record and 1 byte to represent that the time has advanced by 1us.

@godlygeek
godlygeek force-pushed the speedscope-timestamps-fallback branch 3 times, most recently from 0fe392c to 8e9452e Compare July 20, 2026 22:39
@godlygeek

Copy link
Copy Markdown
Contributor

@pablogsal I'm still not understanding why we need to add the fine grained timestamps for the speedscope report. It seems like the only thing they're used for is to tell when the first time we saw an allocation with a given stack was, and then the superposition of stacks in the speedscope flamegraph winds up ordered left to right by the first time we saw an allocation at each of those stacks. Right?

But... we don't need timestamps for that! The capture file is written in allocation order, so we know whether we saw an allocation with stack X before an allocation with stack Y without needing to know exactly when those allocations occurred. We could get the exact same behavior just replacing the timestamp with a sequence number.

I feel like either I'm badly misreading something or you implemented a really overengineered way to explicitly record a piece of information that we already had implicitly.

Starting with your original commit 31e477b (just to make sure I haven't screwed anything up while working on it), I applied this patch:

diff --git a/src/memray/_memray/tracking_api.cpp b/src/memray/_memray/tracking_api.cpp
index 3dc1692..9b581bf 100644
--- a/src/memray/_memray/tracking_api.cpp
+++ b/src/memray/_memray/tracking_api.cpp
@@ -1495,6 +1495,7 @@ Tracker::getTracker()
 uint64_t
 Tracker::currentTimestampUs() const
 {
+    std::this_thread::sleep_for(std::chrono::microseconds(1));
     return std::chrono::duration_cast<std::chrono::microseconds>(
                    std::chrono::steady_clock::now() - d_monotonic_start)
             .count();

That makes it so that we still record the fine grained timestamps, but also guarantees that every allocation will have a unique timestamp, so that the order is deterministic (we never have two allocations rounded to the same timestamp because of our quantum).

Then, I ran:

memray run -fo output.bin --allocation-timestamps --trace-python-allocators -m test test_set

to generate a report with tons of data, and with allocation timestamps in the report.

I generated a speedscope report with:

memray transform speedscope -f -o memray-speedscope-output.speedscope.json.uniq_micros output.bin

Then I applied this patch, which completely ignores the timestamps encoded in the capture file in favor of just using a sequence number:

diff --git a/src/memray/_memray/record_reader.cpp b/src/memray/_memray/record_reader.cpp
index 64eecd4..b29aa2a 100644
--- a/src/memray/_memray/record_reader.cpp
+++ b/src/memray/_memray/record_reader.cpp
@@ -356,7 +356,7 @@ RecordReader::processAllocationRecord(const AllocationRecord& record)
         d_latest_allocation.native_segment_generation = 0;
     }
     d_latest_allocation.n_allocations = 1;
-    d_latest_allocation.timestamp_us = record.timestamp_us;
+    d_latest_allocation.timestamp_us++;
     return true;
 }

and then I regenerated that report again:

memray transform speedscope -f -o memray-speedscope-output.speedscope.json.uniq_seqnum output.bin

and... the two files are byte-for-byte identical.

The only difference the timestamp makes over a sequence number is screwing up the order, by making it arbitrary which order two allocations seen in the same microsecond show up in!

Am I missing something?

Teach the transform reporter to emit sampled speedscope profiles for bytes and allocation counts, preserving root-to-leaf stack order and aggregating identical stacks.

Preserve the capture order with sequence numbers assigned while building snapshots. This keeps the export deterministic without changing the capture format or recording allocation timestamps.

Signed-off-by: Pablo Galindo Salgado <pablogsal@gmail.com>
@pablogsal
pablogsal force-pushed the speedscope-timestamps-fallback branch from 8e9452e to d3692c5 Compare July 21, 2026 08:20
@pablogsal

Copy link
Copy Markdown
Collaborator Author

Yep, you’re totally right 😅 My fault. I’m used to profiling formats that rely on timestamps, so I went straight down that path. I’ve removed all the timestamp machinery and the temporal fallback. Snapshot aggregation now keeps a local sequence number and uses it to preserve ordering. I also rebased everything into one clean commit. Thanks for catching it!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants