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

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.

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

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.

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