Timeslices during continuous profiling isn't showing entire execution time

[corsairius]

Discussed in https://github.com/pyroscope-io/pyroscope/discussions/1298

^{Originally posted by corsairius July 21, 2022} A script runs for 12 minutes and not seeing any consistency in the elapsed time for the script's activities.

The Python script is executed within a vscode Python testing setup profiling parsing a sample script. When the timeslice is selected, the expected visualization would be expected to indicate total execution time, however, the total execution time slips to seconds instead of 12 minutes. It would be expected that continuous profiling would indicate an aggregate of time for the selected preset, or zero when idle.

     pyroscope.configure(  
        application_name = "Parser.app", # replace this with some name for your application  
        server_address   = "http://192.168.64.240:4040", # replace this with the address of your pyroscope server
        sample_rate         = 100, # default is 100  
        detect_subprocesses = True, # detect subprocesses started by the main process default is False  
        oncpu               = False, # report cpu time only; default is True  
        native              = False, # profile native extensions; default is False  
        gil_only            = False, # only include traces for threads that are holding on to the Global Interpreter Lock; default is True  
        log_level           = "info", # default is info, possible values: trace, debug, info, warn, error and critical 
     )

After Python Test (11.46 minutes):

Selecting the above time range does not show the correct total time (17.13 seconds):

Any help is appreciated.

Thanks! --Joe.

[petethepig]

Hi @corsairius

Thank you for reporting this!

With the parameters you've provided it seems like you should be seeing 12 minutes in pyroscope.

When the timeslice is selected, the expected visualization would be expected to indicate total execution time

How long is the time slice you've selected? Note that each yellow line corresponds to 10 seconds in real time. So if you're selecting 2 yellow lines, it's normal to see 17.13 seconds of CPU time during those 20 seconds of real time.

---

It would be helpful if you've provided:

• same screenshots but with the timeline component included
• more information about the expected behavior. E.g what are the numbers you're expecting to see in the first and second screenshots.

---

Another thing I'll mention is that currently there might be some profiling data loss at the very end of the process's lifetime. Pyroscope collects data in 10 seconds batches, and so if you have a process that starts at 12:00:00 and ends at 12:00:15, that last 5 second period of time will be lost because the profiling session is not properly finilized. We're working on a long term solution to this problem. For now you can add a 10 second sleep at the end of your script if you really need those last few seconds.

[Rperry2174]

also FYI (not sure if code is too sensitive to post here) but another option instead of screenshots is getting a shareable link via flamegraph.com

Up to you though if you feel comfortable sharing that vs sharing the screenshot :)

[corsairius]

I just ran the script, and then a selection of the timeline that is circled should, imho, show the same numbers.

The flamegraph appears different as well. What is the expected visualization after selecting the timeslices?

[Rperry2174]

closing as i believe this is functioning correctly and more an issue of cpu vs wall time. Let us know if you still run into this issue