Jump to:

23376 Posts in 18218 Topics by 2867 members

General Questions

SilverStripe Forums » General Questions » What does "all_execution" signify in the profiler?

General questions about getting started with SilverStripe that don't fit in any of the categories above.

Moderators: martimiz, Sean, biapar, Willr, Ingo, swaiba, simon_w

Page: 1
Go to End
Author Topic: 1217 Views
  • markguinn
    Avatar
    Community Member
    13 Posts

    What does "all_execution" signify in the profiler? Link to this post

    I'm doing some work optimizing one of our sites using the profiler (?debug_profile=1) and I've noticed that sometimes "all_execution" is the top entry, sometimes representing 50% or more of the execution time. I've looked at sapphire/main.php so I know technically what "all_execution" is representing, but I'm curious what's actually going on there. Does that mean that the database server is running slow? Does it mean that the controller is taking a long time? If your site is running slowly and all_execution is taking up all the time, where do you look first?

    Thanks,
    Mark

  • Pigeon
    Avatar
    Community Member
    243 Posts

    Re: What does "all_execution" signify in the profiler? Link to this post

    I'm not sure; but the name implies to me it is the total execution time to generate the page...

    Which might explain why it is 50% (as all the parts will add up to equal the total).

    Someone please correct me if I'm wrong.

  • markguinn
    Avatar
    Community Member
    13 Posts

    Re: What does "all_execution" signify in the profiler? Link to this post

    Thanks for the input, Pigeon. You're right that it encompasses most of the program execution time. The problem is that it's adding up to more than 50%, so there is some missing time in there. I'm just wondering what the missing time normally represents. Looking around on the forums, I've seen at least one other post where that was going on, so I know it's not only me.

    Mark

  • Pigeon
    Avatar
    Community Member
    243 Posts

    Re: What does "all_execution" signify in the profiler? Link to this post

    Odd, is it a significant amount of time? It could just be that the total timer runs for the entire execution where as the others don't start and stop instantainiously and so the to total time includes the initialisation of the other timers.

  • TotalNet
    Avatar
    Community Member
    181 Posts

    Re: What does "all_execution" signify in the profiler? Link to this post

    This has been bugging me so I've just done a little digging into how profiler actually works. If anyone's still interested.

    Profiler works by starting and stopping timers around code execution, quite simple really, however, the clever part is that you can have nested timers. When you start a timer within another, the parent timer is suspended.

    This is the case with all_execution, which is started in main.php, so essentially the time it reports is really unprofiled time ... i.e. code that does not use profile timers and is not contained within another timer.

    To get more detail you really need to dig into the code starting at Director::direct($url); and add timers - although I'm not sure how many levels you can "nest" timers I don't think there's a limit.

    Obviously this involves editing core files, however, if you find some code without a profile timer that has a significant chunk of execution time then I'm sure it would be appreciated by the wider community. I'll let you know if I turn up anything.

    Cheers,

    Rich

    EDIT: you can also use profile_trace to see the trace and find potential gaps between all_execution resuming and suspending e.g. ?debug_profile=1&profile_trace=1 at the end of your URL

    1217 Views
Page: 1
Go to Top

Want to know more about the company that brought you SilverStripe? Then check out SilverStripe.com

Comments on this website? Please give feedback.