Incorrect stacking of events that are close in time

[occivink]

Hi,

I have the following trace that gets rendered incorrectly in speedscope

[
{ "name": "A", "ph": "X", "ts":      1732107141551429.079, "dur": 34670882.955, "pid": 1033891, "tid": 140390667650624, "args": {}},
{ "name": "B", "ph": "X", "ts":      1732107142997066.682, "dur":   476375.838, "pid": 1033891, "tid": 140390667650624, "args": {}},
{ "name": "C", "ph": "X", "ts":      1732107143473442.569, "dur":   300492.826, "pid": 1033891, "tid": 140390667650624, "args": {}}
]

The event B ends at 1732107143473442.520, and event C starts at 1732107143473442.569 (49ns later), so C should be on the same stack, but just after B.

However, this is how it gets visualized in speedscope:

And in perfetto.dev:

My hunch is that this could be due to a double precision issue.

[jespersh]

is this why mine looks like this?

[jlfwong]

@occivink Yeah, I think your suspicions are correct:

I'm not super stoked at the idea of used arbitrary precision floating point for all of the parsing for trace file import, since I'm assuming that would be a non-trivial perf hit for massive files. I wonder how Perfetto deals with this

@jespersh I think what you're looking at is probably unrelated -- the display in that profile doesn't look like a bug to me. Can you say more about what's unexpected there?

[jespersh]

@jlfwong I'd think that the brown AdMain.Program.Main() shouldn't be chopped into pieces as the program never leaves the Main() method

[occivink]

I'm not super stoked at the idea of used arbitrary precision floating point for all of the parsing for trace file import

I don't know much about the internals of speedscope, but what about changing the stacking logic when event A ends at the same time as event B starts? Right now speedscope considers that B is a child of start, would it be an issue to consider it a sibling instead?

[alecazam]

I think devs should expect at most double precision out of a browser timestamp. Those ts values are super long. The caller can subtract the base time, and Catapult has a mode that you can set that starting offset. We just zero all our timestamps before writing out the file, and then the ts precision issues are not an problem.

Since Catapult doesn't have an explicit level defined, Perfetto has to derive the level by sorting the timestamps. This also means that all deeper scopes must be entirely inside the parent scope.