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

Sandwitch Sort by "self". Method displayed twice #247

Closed
guettli opened this issue Dec 4, 2019 · 4 comments
Closed

Sandwitch Sort by "self". Method displayed twice #247

guettli opened this issue Dec 4, 2019 · 4 comments

Comments

@guettli
Copy link

guettli commented Dec 4, 2019

There is something strange.

The method "test_ids_from_import_done_exist" appears twice:

image

And the second:

image

Maybe this happens because once it is the lowest line in the stacktrace, and once there are sub-methods below this method.

Data was created by py-spy.

@jlfwong
Copy link
Owner

jlfwong commented Dec 4, 2019

If you include the profile, I can take a look. This is more likely to be a bug in the py-spy profiler speedscope output than it is to be a bug in speedscope itself

@benfred
Copy link

benfred commented Dec 8, 2019

I've managed to replicate this, and I've attached the profile output as well as script to generate it below.

I believe the duplicate entries are showing up in the sandwich view because of the line numbers being included in the frames, which aren't shown in the sandwich view but are shown in the time order/ left heavy views. This causes 1 duplicate entry per line in the sandwich view.

A script to generate is

# profile with
# py-spy record -o profile.json -f speedscope --idle --duration 10  -- python ./test.py
import time

def foo():
    time.sleep(0.2)
    time.sleep(0.1)

while True:
    foo()

And here is how it looks in the sandwich view, notice that there are two 'foo' entries included there, with the times roughly corresponding to how long we would expect each sleep line to take:

Screenshot from 2019-12-07 20-22-21

(profile output: speedscope.json.txt )

I'm happy to tweak the JSON format from py-spy if I'm doing something wrong here, but it looks to me that the issue is that the speedscope sandwich view isn't showing the line numbers causing a confusing experience.

semi-related issue here: benfred/py-spy#201

@jlfwong
Copy link
Owner

jlfwong commented Dec 9, 2019

Hi @benfred, thanks for making py-spy!

This is ambiguous, but the line numbers are intended to be line numbers of the function definition, not the line currently active in the stack. In this instance, the line number for foo should be the same for samples in which time.sleep(0.2) is at the top of the stack and in which time.sleep(0.1) is the top of the stack.

When importing from the speedscope file format, only stack frames which have the same frame index (

type SampledStack = number[]
) are aggregated together. This is important to e.g. allow two actually distinct functions with the same name in the same file to be treated separately.

@benfred
Copy link

benfred commented Dec 16, 2019

Thanks for the response!

I’ve added the ability for py-spy to leave out the line numbers from the speedscope output in the last release (by specifying the -F flag). This should mostly solve this problem @guettli.

I think I understand your point @jlfwong , the line numbers there are meant for disambiguating functions with the same name in the same filename, not for doing line based profiling. I still think that there is a case for including the line numbers in the sandwich view: it would make it consistent with the left heavy / time order views where they are displayed, and without the line numbers there can be entries that look the same (like same function name in same file case).

@jlfwong jlfwong closed this as completed Jul 27, 2020
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

No branches or pull requests

3 participants