GHOP Issue #4: Profiling of D6, viewing the standard page after installation, create a story and view the Admin index

Link to GHOP: http://code.google.com/p/google-highly-open-participation-drupal/issues/...

The Text:
For GHOP Drupal-Issue 4 I did a profiling of D6. Because the Computer I used for profiling is *very* slow I maybe spot to problems other people don't see/doesn't exist for others. Because this Computer runs XP with 512MB RAM, especially SQL-Queries are slow, so if you're looking into the raw data, don't be surprised.

1. Analysis of a fresh installed D6-HEAD start page after installing (runned cron 1time manually, please note that it IS NOT saved into db)
Overall stats:
It tooks about 2s to build the complete page (yes, the computer is slow :P)
2400ms (98%) went into index.php and functions called by it
the rest went into sess_write and sess_close, nothing to mention here
The complete drupal_bootstrap-Call took 1500ms aka ~60%. It called 9 times _drupal_bootstrap. Analysis of the calls will follow. Most of the rest time is spent into the theme-function, 941ms aka ~40%, analysis will follow.

Analysis of drupal_bootstrap:
Here is 1 call to _drupal_bootstrap mentionabel:
the one which calls drupal_bootstrap_full:
Here is the function _drupal_bootstrap_full to mention, here you can focus on, it's consuming 18% time to execute it's own code and 36% execution time to execute it's code+calls to other funcs. The most part of the additionally 18% goes to the modules_load_all aka drupal_load calls. Here you could try to find a timeoptimized version for, but the code is rather short, not too much you're able to optimize :(

Analysis of theme:
The theme-function including it's calls need 1000ms aka ~40% of the page generation time. As time-consuming functions I propose _init_theme, it needs 230ms for it's own code, maybe here you can step in. Additionally, have look at template_preprocess_page, it consumes with all related calls 550ms, nut it's calling a *huge* amount of functions, it will be hard to find there much code to optimize, without ripping out Features in the template engine (this is a best guess depending on the callstack:P)

Additional advice:
you should imho think of a query-cache, but I talked in IRC with killes and he disliked the idea, and maybe there are reasons for not putting one into D6 till now. You also need *25* calls to the query-function (for me mysqli_query), this are just too much for building one page. OK, sure i'v tested all without caching, but anyway this are too much calls

2. Submitting a new Story-Form
Creating a story consumes 4700ms time
Here we have a complete different places where the time goes.
I talked already about _drupal_bootstraps, now we have more time spent here, 1400ms. But don't worry, i'd guess that you'll not see so much of it on a webhost-server, the vHDD in this computer is *that* slow, it spends 500ms in mysqli_query for the session, 500 in drupal_bootstrap_full (see above) + the rest and you're at 1400m theme needs 1200ms now, but nothing really new, look at 1

The rest of the time, ~1900ms goes into menu_execute_active_handler+calls. Tracking down this time I noticed that the most of it isn't PHP but (for me) slow SQL-Queries
3. Adminindex
I'll just post the additional infos.
it needs 11000ms to be built, 1600ms goes into drupal_bootstrap, 1600 into theme, and the rest (~8000ms) into menu_execute_active_handler, aka
system_requirements and update_requirements: to my understanding, it needs just calling after you've checked for new releases or you've installed/updated a module, not every time you watch the admin panel. For the status, just cache the data if you change them and display the cached data. This would reduce the IO alot. And for the requirements: just check them if they don't meet your requirements. For the time, here we've 6200ms
Other tasks aren't that bad, so i didn't found anything more shocking (like the unexplainable system_requirements :P)

For Questions contact me in #drupal or #drupal-ghop, nick Corni or drop a mail(cDOTr1ATgmxDOTde)

The Profiler Data:
I used WinCacheGrind to analyse them
The Admin Index:
http://www.file-upload.net/download-534419/adminindex.html
The Create-Story:
http://www.file-upload.net/download-534421/profilecreatestory.html
The Watch-1st-page
http://www.file-upload.net/download-534425/profiledatapageview.html
These files are there saved for 1 Year, if someone wants to host them in another location, just do so :)
I Hope you'll be looking into the admin page, that's a huge mess :)