Running on the same machine, i have installed both 5.10 and 6.4. When I visit admin/build/modules on 6.4, it takes 20+ seconds to load.

Here is the dump of 6.4 using Devel module when visit admin/build/modules:

Executed 1478 queries in 24852.78 milliseconds. Queries taking longer than 5 ms and queries executed more than once, are highlighted.
ms # where query
265.38 1 _menu_router_build INSERT INTO menu_router (path, load_functions,
168.68 1 _menu_router_build INSERT INTO menu_router (path, load_functions,
158.62 3 _menu_update_parental_status UPDATE menu_links SET has_children = 0 WHERE m
113.33 2 module_rebuild_cache UPDATE system SET info = 'a:10:{s:4:\"name\";s
104.47 1 cache_set INSERT INTO cache_views (cid, data, created, e
103.41 8 _menu_update_parental_status UPDATE menu_links SET has_children = 1 WHERE m
92.95 1 menu_link_save UPDATE menu_links SET menu_name = 'navigation'
91.83 2 cache_clear_all DELETE FROM cache_menu WHERE cid LIKE 'links:n
88.14 1 menu_link_save UPDATE menu_links SET menu_name = 'navigation'
80.31 1 menu_link_save UPDATE menu_links SET menu_name = 'navigation'
79.44 1 _menu_router_build INSERT INTO menu_router (path, load_functions,
77.43 8 _menu_update_parental_status SELECT mlid FROM menu_links WHERE menu_name =
76.86 1 _menu_router_build DELETE FROM menu_router
76.17 1 _menu_router_build INSERT INTO menu_router (path, load_functions,
73.7 1 _menu_router_build INSERT INTO menu_router (path, load_functions,
70.67 1 _menu_router_build INSERT INTO menu_router (path, load_functions,

Here is the dump for 5.10:
Executed 44 queries in 1238.72 milliseconds. Queries taking longer than 5 ms and queries executed more than once, are highlighted.
ms # where query
59.37 1 sess_write UPDATE users SET access = 1222058857 WHERE uid = 1
54.7 1 sess_write UPDATE sessions SET uid = 1, cache = 0,
47.95 1 module_rebuild_cache UPDATE system SET description = 'Logs and records system events.',
42.49 1 module_rebuild_cache UPDATE system SET description = 'Aggregates syndicated content (
40.04 1 module_rebuild_cache UPDATE system SET description = 'Lets you register your site with a ce
39.81 1 module_rebuild_cache UPDATE system SET description = 'Allows the user to change

Support from Acquia helps fund testing for Drupal Acquia logo

Comments

newbuntu’s picture

FileSize
126.13 KB

I have attached the dump data for 6.4. I can upload 5.10 data if needed.

I want to change this to a bug report, and change the title to "Excessive db queries and delay on admin/build/modules"

sun’s picture

newbuntu’s picture

I just downloaded 6.5 and installed it on a different machine, exactly the same behavior. Modules takes forever to load. Thousands of db queries are invoked by simply clicking on the module list. I think this is a serious problem!

On both my machines the installer also took several times longer to run than drupal 5 installer. I believe it's the same issue.

Both machines are pretty beefy XP boxes. Drupal 5 runs great on both.

One has apache 2.2.4, php 5.2.3, mysql 5.0.45. The other one has apache 2.2.9, php 5.2.6, mysql 5.1.26.

Anybody has clues?

newbuntu’s picture

I have a hunch what's going on. I'd like hear some feedback from the experts.

It appears to me that whenever I click on module list, drupal is rebuilding everything, that's why there are so many db queries. The question is whether this is supposed behavior?

I notice that if I change my module menu, or cck fields or permission or form_alter code, it won't take effect until I click on module list.

newbuntu’s picture

Priority: Normal » Critical

I'd like to raise this issue to critical. It becomes unbearable that I have to set execution time limit to 120 sec, it still may time out when I hit modules in admin.

I can tell it's rebuilding something huge (my hunch it's the entire internal tables). Because if the execution doesn't finish, then many of the system menu would disappear. I would think this is a very serious issue.

I would assume many people experience this problem. Is it possible, some expert can take a look at the log file, throw some light on this problem?

Is this how drupal 6 supposed to work? or this is a bug?

thanks a lot!

dset’s picture

Version: 6.4 » 6.5
Component: base system » admin.module

I have exactly the same problem with my system.

OS: WinXP SP3
PHP: 5.2.6
Apache: 2.2.9
MySQL: 4.1.22

Drupal: 6.5

Administer > Site building > Modules access times:

Clean install (all default core modules enabled but 'Update status'):
approx. 2.94 s.

Views 6.x-2.0-rc5 added (not enabled - just copied into sites/all/modules/):
approx. 4.20 s.

CCK 6.x-2.0-rc10 added (not enabled - just copied into sites/all/modules/):
approx. 5.30 s.

FCKeditor 6.x-1.3-rc1, FCKeditor ver. 2.6.3 added (not enabled - just copied into sites/all/modules/):
approx. 9.45 s.

and so on and so forth... access time increases everytime I add a new module.

Any help would be greatly appreciated!
Thanks!

skritek00’s picture

I have exactly the same problem
OS: Debian etch
PHP: 5.2.6
Apache: 2.2.9
MySQL: 5.0.32

With the modules above enabled. Veeeeery Slow with more than 15 users on the site.

Drupal: 6.5

Heine’s picture

This is intentional, see http://drupal.org/node/193366

2ndChanceTech’s picture

I also was having some serious problems with the module/list page loading on 6.5
It eventually got so bad that I got "out of memory" errors, and my host told me that drupal was attempting a 64mb+ cache dump to the database and that it was excessive. of course we all get the "by design" answer. Personally if it can't run on 64mb max limit, then maybe there's a design flaw?

anyways
I fixed this issue by using cacherouter and using file based caching. worked right away!

hope that helps someone

gpk’s picture

2ndChanceTech’s picture

A little bit more on this... With the cache router enabled, it messes with the cache_menu.

so I dug a little deeper and discovered that the biggest problem is in 'cache' bin. So I made my default routing to the database as per normal, and set 'cache' bin to file. This cleared up my problem on the modules/list page, and allows my menu and such to work properly. However, I noticed a couple lingering issues, and will submit some bug reports to cacherouter, hopefully they can be resolved.

You may want to figure out exactly which cache dump is causing the problem and route only that one to file. Hopefully this isn't concidered hijacking the thread, I believe this is a viable solution for those of us on shared hosts having problems with the DB abuse caused by rebuilding all the cache in one shot.

PixelClever’s picture

I have been having this problem since Drupal 6 has been released. I am only having this issue on my local testing server (wamp) so I suspect that the problem is related to a unix specific reference in the code. I have 3-4 Drupal 6 installations in progress at any given time so I know that this is not a installation specific issue. This is a bug and in as such I am setting it to bug report rather than support request.

I checked the queries for the page and the numbers are ridiculous:
Executed 7087 queries in 134726.87 milliseconds. Page execution time was 160051.17 ms.

The majority of the long queries are called through _menu_router_build.

gpk’s picture

Title: brand new install 6.4, admin/build/modules takes 20 more times than 5.10? » brand new install 6.6, admin/build/modules takes 160051.17 milliseconds
Version: 6.5 » 6.6
Category: support » bug

Your average query duration is about 20ms, which is on the high side. So part of the probem is that MySQL is running very slowly for you. I would expect exactly the same number of queries for a given site irrespective of whether it is running on Windows or *nix. But yes 7,000 queries is a tad extravagant!!!! I take it you have quite a few modules enabled?

PixelClever’s picture

No, I don't have very many modules installed at all (I have 8 I am using right now).
Averages are not really relevant in this case, Take a look at the first 5 queries (in miliseconds) :
660.67 _menu_router_build
579.91 _menu_router_build
530.8 _menu_router_build
443.78 _menu_router_build
401 _menu_router_build

The majority of the queries came from _menu_router_build that ran over and over with huge query times. Please read the other bug reports from the other users. This is happening on fresh installs with only the core modules in place. I have been using Drupal 6 since it came out, and in effect I am forced to develop on a remote server if I want to avoid waiting two to three minutes for the modules page to load. (When I say two to three minutes I say that because once other modules are put in place the query times only get longer.)

gpk’s picture

Can you post the list of active modules (core + contrib)? I get the following behaviour with a pretty hefty list of modules (see below). (Timings not particularly useful for comparison - this is on a shared hosting account.)

Executed 3604 queries in 1678.3 milliseconds... Page execution time was 5670.58 ms.

...
Memory used at: devel_init()=1.04 MB, devel_shutdown()=35.64 MB.

Most _menu_router_build queries are well under 1ms.

Even with quite a lot of modules I'm not getting nearly as many queries.

I've not run this particular site on my 5 yr old laptop (OK, it does have a fair bit of RAM), but other 6.x sites work fine.

Active modules/version:
Acquia agent 1.0.2-ISR
Acquia site information 1.0.2-ISR
Administration Menu 6.x-1.1
Advanced help 6.x-1.1
Block 6.6
Blog 6.6
Book 6.6
Calendar 6.x-2.0-rc4
Calendar iCal 6.x-2.0-rc4
Calendar Popup 6.x-2.0-rc4
Color 6.6
Comment 6.6
Content 6.x-2.0-rc10
Database logging 6.6
Date 6.x-2.0-rc4
Date API 6.x-2.0-rc4
Date Popup 6.x-2.0-rc4
Date Timezone 6.x-2.0-rc4
Devel 6.x-1.12
Fieldgroup 6.x-2.0-rc10
FileField 6.x-3.x-dev
Filter 6.6
Help 6.6
Image 6.x-1.0-alpha3
Image Attach 6.x-1.0-alpha3
Image Gallery 6.x-1.0-alpha3
ImageAPI 6.x-1.0
ImageAPI GD2 6.x-1.0
ImageField 6.x-3.x-dev
Markdown filter 6.x-1.1
Menu 6.6
Node 6.6
Organic groups 6.x-1.0-rc6
Organic groups actions 6.x-1.0-rc6
Organic groups Views integration 6.x-1.0-rc6
Path 6.6
Pathauto 6.x-1.1
Sitenotes 6.x-1.2
Statistics 6.6
System 6.6
Taxonomy 6.6
Text 6.x-2.0-rc10
Token 6.x-1.11
Trigger 6.6
Update status 6.6
User 6.6
Views 6.x-2.1
Views UI 6.x-2.1

pokadan’s picture

I have the issue too. Wamp server, winXP.

PixelClever’s picture

I also run sites with massive amounts of modules on shared hosting with no problems. The problem doesn't occur on shared hosting. It happens on local machines, test servers (In my case Wamp, but there are people having the problem on other os's too). It could be that this is something as simple as a php plugin that most host have activated but we don't have activated on our local machines. In any case this is not a question of individual modules installed. As I stated in an earlier post this happens on fresh installs. As in you install drupal with no modules and you go to the modules page to add something and bam you're waiting a minute and a half for the page to load. And it only happens with Drupal 6.

gpk’s picture

@17: I don't have the sort of problem you are having, running 6.6 on stock XAMPP install on Win XP SP3/P4 2.4GHz (5 yrs old)/1GB RAM. Time to load modules page is about 10s (see below). This is why I think *part* (but not all) of the problem is the config of your local setup. Unfortunately I don't have any experience of WAMP in particular or server tuning in general, but the first thought when seeing your query times was that MySQL may be paging due to insufficient RAM.

Page execution time was 10006.45 ms. Executed 1481 queries in 2080.26 milliseconds.
Memory usage: Memory used at: devel_init()=1.63 MB, devel_shutdown()=16.77 MB.

Enabled modules:
Blog, Book, Color, Comment, Database logging, Help, Menu, Path, Statistics, Taxonomy, Trigger, Update status, plus (of course!) the Core - required modules and Devel.

Even running the heavier module load as at #15 locally I typically get something like this:
Page execution time was 17543.83 ms. Executed 3604 queries in 5153.71 milliseconds.
Memory usage: Memory used at: devel_init()=1.64 MB, devel_shutdown()=40.02 MB.

Of course this does mean that submitting the modules page takes 35-40 seconds since there are 2 page requests (a POST followed by a GET).

PixelClever’s picture

Hmmm... That's interesting. Perhaps I should install Xampp and see if it runs better. I have resisted doing that because with the exception of this problem my test server is set up just how I like it with debugging and all. If Wamp is the problem though then it probably just means there is a configuration default that is different. It would be nice to figure out what that difference is so that it could be documented.

2ndChanceTech’s picture

Wamp is not the issue. This issue happens on local environments, shared hosting and VPS. I've seen it on all 3, the forums are littered with posts of this exact same problem, all about this length, all blaming something different, HOWEVER in ALL of them, you realize it's a cache/mysql problem, and you need to narrow whatever fixes your looking for to that area.

Cache Router:
and Menu_Cache are the things to search for that will lead you to a solution.

And if you haven't found a solution to amp up your caching options, then, expect more issues.

To solve this, like I said I disabled Menu_Cache and enabled eaccelerator caching for the entire site. Site blazes, module page still a little slow, but I have over 120 Modules now installed and running just fine. No Time outs, no errors, etc.

newbuntu’s picture

I truly hope this problem can be fixed soon!

I configured my php time out to 3 minutes locally, it timed out again today. What was worse, it corrupted everything. I spent hours try to repair to no avail. Now I am spending agonizing hours to re-install everything from scratch. To add to the insult, I know what I am installing: it's exactly the same thing.

If I know how to fix it, I'll do it, and I will share it. I am sorry I just don't know enough. I can only pray the problem gets fixed somehow...

Sigh...

newbuntu’s picture

GREAT!!! After a few months of agony, I finally found my problem. I hope my solution works for you too.

The problem was that my mysql was configured to use "innodb" engine as default. I switched to "myisam". That's it!

Here is how: find your my.ini in your mysql folder, (BACK IT UP before you change it), replace the engine configuration with this line:

default-storage-engine=myisam

If you want to go further, you can also change this line as well, (I didn't see it made much difference with this line)

key_buffer_size=512M

Restart mysql, then re-install drupal 6.x. (If you don't want to re-install, you'll need to convert your tables to 'myisam', you'll need to search online to find out how to do that. Shouldn't be difficult.)

I see my 5.x tables all selected "myisam". I suspect the previous installer had something in it that forced tables to use "myiasm", but I can't find any evidence though.

In any event, I can finally go back do my work now...

nevets’s picture

Following up on ubuntu's comment here is a script that will change all the tables over to myisam.

WARNING: Backup your database before trying this in case something goes wrong.

Before you start: Enable the PHP filter module

Create a new page (Create Content > Page)
Give it a title.
Add the following as the body

<?php
$sql  =  "SHOW  TABLES";
$results  = db_query($sql);
while ( $data = db_fetch_object($results) ) {
$table  =  $data->Tables_in_sb66;  //  You  need to change the sb66 to reflect the name of your database
print  $table  . '<br />';
db_query("ALTER TABLE $table ENGINE = MYISAM");
}
?>

Set the input format to "PHP code"

Save the page - This will update the engine type

Now edit the page and delete (so it is not there to run again).

Visit the modules admin page, should show much quicker.

zilla’s picture

not so sure everybody should kick over to myisam on the fly like this! there are a few modules i've seen in the past that don't play as well...could you provide a more technical review of this (performance gains etc)?

nevets’s picture

A short test of a Drupal 6 install with a fair number of modules, times are for the module administrative page.

Before change

Queries QueryTime Page Load Time
3522 16284.44 ms 20240.00 ms
3522 16498.51 ms 19640.58 ms
3522 16827.17 ms 21421.32 ms

After change

Queries QueryTime Page Load Time
3496 1308.35 ms 4215.98 ms
3514 1308.03 ms 5128.20 ms
3514 1298.63 ms 5139.64 ms

With change page loads in about a quarter of the time.

catch’s picture

Title: brand new install 6.6, admin/build/modules takes 160051.17 milliseconds » admin/build/modules very slow on some configurations
Version: 6.6 » 7.x-dev

Moving to 7.x since bugs get fixed there first then backported.

gpk’s picture

On shared server, after converting to InnoDB I typically get results between
Page execution time was 7477.62 ms. Executed 3604 queries in 3715.54 milliseconds.
Page execution time was 5372.14 ms. Executed 3604 queries in 1442.4 milliseconds.

Where previously with MyISAM had typically
Page execution time was 5670.58 ms. Executed 3604 queries in 1678.3 milliseconds.

This suggests that the problem with InnoDB experienced above by some people is not necessarily the use of InnoDB so much as its configuration (though from what little I know, it's true MyISAM would probably be faster for most tables). Note 1. drupal.org originally used MyISAM, then a few tables were converted over to InnoDB to improve performance a while back (tables which frequently get written to). MyISAM is generally quicker for reads. 2. The Drupal installer doesn't define the table type, it lets MySQL use whichever engine is the default.

[update] Just to clarify what I'm saying - the workaround posted above by nevets may well be very useful for some people, but I don't think this is the way forward for Drupal as a whole. There are 2 issues here:
1. some users have poor performance (especially on the query-heavy admin/build/modules) because of MySQL setup/config. Given this is not an isolated issue, the question here is - can Drupal do anything to help?
2. even on a server that is running well, admin/build/modules requires an very large number of queries. On a local install this can get rather trying. So - is there is scope for optimisation (e.g. for starters: the duplicate queries).

zilla’s picture

Component: admin.module » base system

hmm, a simple idea: could there be an admin option to cache the modules list page and then manually update when updatign modules (update.php) such that an admin can rapidly load a module list OR an admin page? i'm talking about just main screens for module listings and admin home page - all others would be dynamic for module specific configuration....

gpk’s picture

@28: as I think noted above it looks as though the main cause of the high volume of queries is the rebuilding of some caches. Per #8, this was introduced in #193366: execute various rebuilds when modules are submitted to fix a bug. In that issue it was assessed that the impact on the site overall was tolerable.

Your suggestion is interesting but TBH I can't see an option to make cached "copies" of admin + admin/build/modules available making it into core. Would be confusing for novice users and would need some explanation e.g. "sorry folks we can't get this bit to work properly". ;)

catch’s picture

zilla - the expense here isn't the modules themselves, it's that the admin/build/modules page is a convenient (and often necessary) place to rebuild most of Drupal's caches.

Anonymous’s picture

working on this patch, #325665: Cache registry lookups, i noticed that there is a lot of fat in admin/*. some of that will get cleared away when that patch lands, and we might be able to backport some of this to 6. maybe.

PixelClever’s picture

@#22
I tried the switch to myisam, but the difference wasn't large enough on my server to consider it a fix. At any rate I don't think that manually changing the db type is the solution. Innodb should be able to run this page at a reasonable speed if the queries are well set up and the server configuration is correct. For me the issue can't be innodb because I run the same site on a local server with the very slow page load, while the same database installed on a off site server loads quickly. My guess is that Drupal 6 queries are counting on a certain server configuration in order to work. Since so much work has been put into database compatibility I would say Drupal code should be adjusted so that it works on all configurations as Drupal 5 did.

arhak’s picture

subscribing

Netzarim’s picture

I am having this issue as well... I have not tried to change to myisam, I changed some of the tables to innodb specifically to get a performance increase because of the large number of queries to load every page. There are so many redundant queries that I am seriously concerned that it will never load in under 5 seconds.. A sample time is below:

502.95 1 counter_block SELECT count(*) as total FROM (SELECT counter_ip FROM counter GROUP BY counter_ip) c
302.21 1 _session_restore_session_set DELETE FROM session_restore WHERE uid = 1
301.23 1 _menu_router_build INSERT INTO menu_router (path, load_functions, to_arg_functions, access_callback, access_arguments, page_callback, page_arguments, fit, number_parts, tab_parent, tab_root, title, title_callback, title_arguments, type, block_callback, description, position, weight, file) VALUES ('admin/content/node-type/video/edit', '', '', 'user_access', 'a:1:{i:0;s:24:\"administer content types\";}', 'drupal_get_form', 'a:2:{i:0;s:14:\"node_type_form\";i:1;O:8:\"stdClass\":14:{s:4:\"type\";s:5:\"video\";s:4:\"name\";s:5:\"Video\";s:6:\"module\";s:4:\"node\";s:11:\"description\";s:0:\"\";s:4:\"help\";s:0:\"\";s:9:\"has_title\";s:1:\"1\";s:11:\"title_label\";s:5:\"Title\";s:8:\"has_body\";s:1:\"1\";s:10:\"body_label\";s:4:\"Body\";s:14:\"min_word_count\";s:1:\"0\";s:6:\"custom\";s:1:\"1\";s:8:\"modified\";s:1:\"1\";s:6:\"locked\";s:1:\"0\";s:9:\"orig_type\";s:0:\"\";}}', 31, 5, 'admin/content/node-type/video', 'admin/content/node-type/video', 'Edit', 't', '', 136, '', '', '', 0, 'modules/node/content_types.inc')
293.87 1 _menu_router_build INSERT INTO menu_router (path, load_functions, to_arg_functions, access_callback, access_arguments, page_callback, page_arguments, fit, number_parts, tab_parent, tab_root, title, title_callback, title_arguments, type, block_callback, description, position, weight, file) VALUES ('admin/content/node-type/image/access', '', '', 'content_access_admin_settings_access', 'a:0:{}', 'drupal_get_form', 'a:2:{i:0;s:29:\"content_access_admin_settings\";i:1;s:5:\"image\";}', 31, 5, 'admin/content/node-type/image', 'admin/content/node-type/image', 'Access control', 't', '', 128, '', 'Configure content access control.', '', 1, 'sites/all/modules/content_access/content_access.admin.inc')
291.57 1 _menu_router_build INSERT INTO menu_router (path, load_functions, to_arg_functions, access_callback, access_arguments, page_callback, page_arguments, fit, number_parts, tab_parent, tab_root, title, title_callback, title_arguments, type, block_callback, description, position, weight, file) VALUES ('admin/build/block/list/amity_island', '', '', '_block_themes_access', 'a:1:{i:0;O:8:\"stdClass\":12:{s:8:\"filename\";s:47:\"sites/all/themes/amity_island/amity_island.info\";s:4:\"name\";s:12:\"amity_island\";s:4:\"type\";s:5:\"theme\";s:6:\"status\";s:1:\"0\";s:8:\"throttle\";s:1:\"0\";s:9:\"bootstrap\";s:1:\"0\";s:14:\"schema_version\";s:2:\"-1\";s:6:\"weight\";s:1:\"0\";s:4:\"info\";a:13:{s:4:\"name\";s:27:\"Amity Island for Drupal 6.x\";s:11:\"description\";s:39:\"Free Theme by ThemeShark.com (default).\";s:7:\"version\";s:7:\"6.x-1.0\";s:4:\"core\";s:3:\"6.x\";s:6:\"engine\";s:11:\"phptemplate\";s:11:\"stylesheets\";a:2:{s:3:\"all\";a:1:{s:9:\"style.css\";s:39:\"sites/all/themes/amity_island/style.css\";}s:5:\"print\";a:1:{s:9:\"print.css\";s:39:\"sites/all/themes/amity_island/print.css\";}}s:7:\"regions\";a:15:{s:4:\"left\";s:12:\"Left sidebar\";s:5:\"right\";s:13:\"Right sidebar\";s:7:\"content\";s:7:\"Content\";s:6:\"header\";s:6:\"Header\";s:10:\"contenttop\";s:11:\"Content Top\";s:13:\"contentbottom\";s:14:\"Content Bottom\";s:6:\"footer\";s:6:\"Footer\";s:7:\"primary\";s:13:\"Primary Links\";s:9:\"secondary\";s:15:\"Secondary Links\";s:5:\"user1\";s:6:\"User 1\";s:5:\"user2\";s:6:\"User 2\";s:5:\"user3\";s:6:\"User 3\";s:5:\"user4\";s:6:\"User 4\";s:5:\"user5\";s:6:\"User 5\";s:5:\"user6\";s:6:\"User 6\";}s:8:\"features\";a:8:{i:0;s:4:\"logo\";i:1;s:4:\"name\";i:2;s:6:\"slogan\";i:3;s:17:\"node_user_picture\";i:4;s:20:\"comment_user_picture\";i:5;s:6:\"search\";i:6;s:7:\"favicon\";i:7;s:13:\"primary_links\";}s:7:\"project\";s:12:\"amity_island\";s:9:\"datestamp\";s:10:\"1219334702\";s:7:\"scripts\";a:1:{s:9:\"script.js\";s:39:\"sites/all/themes/amity_island/script.js\";}s:10:\"screenshot\";s:44:\"sites/all/themes/amity_island/screenshot.png\";s:3:\"php\";s:5:\"4.3.5\";}s:5:\"owner\";s:45:\"themes/engines/phptemplate/phptemplate.engine\";s:11:\"stylesheets\";a:2:{s:3:\"all\";a:1:{s:9:\"style.css\";s:39:\"sites/all/themes/amity_island/style.css\";}s:5:\"print\";a:1:{s:9:\"print.css\";s:39:\"sites/all/themes/amity_island/print.css\";}}s:6:\"engine\";s:11:\"phptemplate\";}}', 'block_admin_display', 'a:1:{i:0;s:12:\"amity_island\";}', 31, 5, 'admin/build/block/list', 'admin/build/block', 'Amity Island for Drupal 6.x', 't', '', 136, '', '', '', -10, 'modules/block/block.admin.inc')
255.73 1 cache_set INSERT INTO cache_form (cid, data, created, expire, headers, serialized) VALUES ('form_form-2ce031e5d23a754f467d3d0c12430b25', 'a:21:{s:4:\"#nid\";s:2:\"44\";s:6:\"submit\";a:3:{s:5:\"#type\";s:6:\"submit\";s:6:\"#value\";s:16:\"Cancel your vote\";s:7:\"#submit\";a:1:{i:0;s:11:\"poll_cancel\";}}s:6:\"#cache\";b:1;s:11:\"#parameters\";a:3:{i:0;s:16:\"poll_cancel_form\";i:1;a:3:{s:7:\"storage\";N;s:9:\"submitted\";b:0;s:4:\"post\";a:0:{}}i:2;s:2:\"44\";}s:9:\"#build_id\";s:37:\"form-2ce031e5d23a754f467d3d0c12430b25\";s:5:\"#type\";s:4:\"form\";s:11:\"#programmed\";b:0;s:13:\"form_build_id\";a:4:{s:5:\"#type\";s:6:\"hidden\";s:6:\"#value\";s:37:\"form-2ce031e5d23a754f467d3d0c12430b25\";s:3:\"#id\";s:37:\"form-2ce031e5d23a754f467d3d0c12430b25\";s:5:\"#name\";s:13:\"form_build_id\";}s:6:\"#token\";s:16:\"poll_cancel_form\";s:10:\"form_token\";a:3:{s:3:\"#id\";s:34:\"edit-poll-cancel-form-form-token-1\";s:5:\"#type\";s:5:\"token\";s:14:\"#default_value\";s:32:\"fd380bcf96bb36994c83d45a337d8de0\";}s:7:\"form_id\";a:3:{s:5:\"#type\";s:6:\"hidden\";s:6:\"#value\";s:16:\"poll_cancel_form\";s:3:\"#id\";s:23:\"edit-poll-cancel-form-1\";}s:3:\"#id\";s:18:\"poll-cancel-form-1\";s:12:\"#description\";N;s:11:\"#attributes\";a:0:{}s:9:\"#required\";b:0;s:5:\"#tree\";b:0;s:8:\"#parents\";a:0:{}s:7:\"#method\";s:4:\"post\";s:7:\"#action\";s:23:\"/en/admin/build/modules\";s:12:\"#after_build\";a:1:{i:0;s:22:\"fckeditor_process_form\";}s:12:\"#cache_token\";s:32:\"f8265065ece37bc492774e967c2cf68a\";}', 1227641663, 1227663263, '', 1)
244.52 1 quotes_block UPDATE quotes_blocks SET vid=132, cron_last=1227641666 WHERE bid=1
238.59 1 _menu_router_build INSERT INTO menu_router (path, load_functions, to_arg_functions, access_callback, access_arguments, page_callback, page_arguments, fit, number_parts, tab_parent, tab_root, title, title_callback, title_arguments, type, block_callback, description, position, weight, file) VALUES ('admin/rules/rule_sets/%/list', 'a:1:{i:3;a:1:{s:15:\"rules_item_load\";a:1:{i:0;i:2;}}}', '', 'user_access', 'a:1:{i:0;s:16:\"administer rules\";}', 'drupal_get_form', 'a:2:{i:0;s:30:\"rules_admin_form_edit_rule_set\";i:1;i:3;}', 29, 5, 'admin/rules/rule_sets/%', 'admin/rules/rule_sets/%', 'Overview', 't', '', 136, '', '', '', -5, 'sites/all/modules/rules/rules/rules.admin_sets.inc')
238.09 1 _menu_router_build INSERT INTO menu_router (path, load_functions, to_arg_functions, access_callback, access_arguments, page_callback, page_arguments, fit, number_parts, tab_parent, tab_root, title, title_callback, title_arguments, type, block_callback, description, position, weight, file) VALUES ('admin/content/node-type/recipe/edit', '', '', 'user_access', 'a:1:{i:0;s:24:\"administer content types\";}', 'drupal_get_form', 'a:2:{i:0;s:14:\"node_type_form\";i:1;O:8:\"stdClass\":14:{s:4:\"type\";s:6:\"recipe\";s:4:\"name\";s:6:\"Recipe\";s:6:\"module\";s:6:\"recipe\";s:11:\"description\";s:51:\"Share your favorite recipes with your fellow cooks.\";s:4:\"help\";s:0:\"\";s:9:\"has_title\";s:1:\"1\";s:11:\"title_label\";s:5:\"Title\";s:8:\"has_body\";s:1:\"1\";s:10:\"body_label\";s:4:\"Body\";s:14:\"min_word_count\";s:1:\"0\";s:6:\"custom\";s:1:\"0\";s:8:\"modified\";s:1:\"1\";s:6:\"locked\";s:1:\"1\";s:9:\"orig_type\";s:6:\"recipe\";}}', 31, 5, 'admin/content/node-type/recipe', 'admin/content/node-type/recipe', 'Edit', 't', '', 136, '', '', '', 0, 'modules/node/content_types.inc')
237.42 1 _menu_router_build INSERT INTO menu_router (path, load_functions, to_arg_functions, access_callback, access_arguments, page_callback, page_arguments, fit, number_parts, tab_parent, tab_root, title, title_callback, title_arguments, type, block_callback, description, position, weight, file) VALUES ('admin/user/captcha/captcha/settings', '', '', 'user_access', 'a:1:{i:0;s:27:\"administer CAPTCHA settings\";}', 'drupal_get_form', 'a:1:{i:0;s:22:\"captcha_admin_settings\";}', 31, 5, 'admin/user/captcha/captcha', 'admin/user/captcha', 'General settings', 't', '', 136, '', '', '', 0, 'sites/all/modules/captcha/captcha.admin.inc')
231.35 1 _menu_router_build INSERT INTO menu_router (path, load_functions, to_arg_functions, access_callback, access_arguments, page_callback, page_arguments, fit, number_parts, tab_parent, tab_root, title, title_callback, title_arguments, type, block_callback, description, position, weight, file) VALUES ('admin/content/node-type/image/edit', '', '', 'user_access', 'a:1:{i:0;s:24:\"administer content types\";}', 'drupal_get_form', 'a:2:{i:0;s:14:\"node_type_form\";i:1;O:8:\"stdClass\":15:{s:4:\"name\";s:5:\"Image\";s:6:\"module\";s:5:\"image\";s:11:\"description\";s:83:\"An image (with thumbnail). This is ideal for publishing photographs or screenshots.\";s:4:\"type\";s:5:\"image\";s:9:\"has_title\";b:1;s:11:\"title_label\";s:5:\"Title\";s:8:\"has_body\";b:1;s:10:\"body_label\";s:4:\"Body\";s:4:\"help\";s:0:\"\";s:14:\"min_word_count\";i:0;s:6:\"custom\";b:0;s:8:\"modified\";b:0;s:6:\"locked\";b:1;s:9:\"orig_type\";s:5:\"image\";s:6:\"is_new\";b:1;}}', 31, 5, 'admin/content/node-type/image', 'admin/content/node-type/image', 'Edit', 't', '', 136, '', '', '', 0, 'modules/node/content_types.inc')
230.8 1 _menu_router_build INSERT INTO menu_router (path, load_functions, to_arg_functions, access_callback, access_arguments, page_callback, page_arguments, fit, number_parts, tab_parent, tab_root, title, title_callback, title_arguments, type, block_callback, description, position, weight, file) VALUES ('userpoints', '', '', 'user_access', 'a:1:{i:0;s:15:\"view userpoints\";}', 'userpoints_list_users', 'a:0:{}', 1, 1, '', 'userpoints', 'Users by !points', 't', 'a:4:{s:7:\"!Points\";s:6:\"Points\";s:7:\"!points\";s:6:\"points\";s:6:\"!point\";s:5:\"point\";s:14:\"!Uncategorized\";s:13:\"Uncategorized\";}', 6, '', '', '', 0, '')
228.35 7 cache_clear_all DELETE FROM cache WHERE cid = 'variables'
197.29 1 _menu_router_build INSERT INTO menu_router (path, load_functions, to_arg_functions, access_callback, access_arguments, page_callback, page_arguments, fit, number_parts, tab_parent, tab_root, title, title_callback, title_arguments, type, block_callback, description, position, weight, file) VALUES ('admin/content/node-type/story/edit', '', '', 'user_access', 'a:1:{i:0;s:24:\"administer content types\";}', 'drupal_get_form', 'a:2:{i:0;s:14:\"node_type_form\";i:1;O:8:\"stdClass\":14:{s:4:\"type\";s:5:\"story\";s:4:\"name\";s:5:\"Story\";s:6:\"module\";s:4:\"node\";s:11:\"description\";s:219:\"Stories are articles in their simplest form: they have a title, a teaser and a body, but can be extended by other modules. The teaser is part of the body too. Stories may be used as a personal blog or for news articles.\";s:4:\"help\";s:0:\"\";s:9:\"has_title\";s:1:\"1\";s:11:\"title_label\";s:5:\"Title\";s:8:\"has_body\";s:1:\"1\";s:10:\"body_label\";s:4:\"Body\";s:14:\"min_word_count\";s:1:\"0\";s:6:\"custom\";s:1:\"1\";s:8:\"modified\";s:1:\"1\";s:6:\"locked\";s:1:\"0\";s:9:\"orig_type\";s:5:\"story\";}}', 31, 5, 'admin/content/node-type/story', 'admin/content/node-type/story', 'Edit', 't', '', 136, '', '', '', 0, 'modules/node/content_types.inc')

my-family’s picture

Version: 7.x-dev » 6.6

I have exactly the same problem... and all my tables are on MYISAM.
Devel results (admin/builds/modules):
Executed 3973 queries in 53096.99 milliseconds. Page execution time was 56500.27 ms.

2ndChanceTech’s picture

First that's an obscene amount of queries, I have over 160 modules installed, 10+ views per page, and don't have that many queries. Meaning one of your modules may be a culprit. Also it's been determined before that this has NOTHING to do with MYISAM, this has SO FAR been exclusive to people on shared hosts (I don't see anyone in any of these threads complaining, not on one). Also those queries are extremely slow, which means it's your mysql database that isn't responding fast enough. It's not drupal you may want to check into things like mysql cache, buffers, max simultaneous connections, and may also want to look into mysql indexing as well to increase the speed of queries. 4000 Queries is a lot, but it should execute in under 5ms each. Meaning 20,000 ms maximum just due to your queries (that's still terrible).

One other thing to check is try loading a default theme and see if that makes any changes. I had a friend move to a vps, and it sped things up but he still had the excessive query issue (5600). Even though the page loaded in about 11 seconds it was unexecptable.

He changed his custom theme to a default one and his time went to 7 seconds, queries down to 2700 Still not perfect, but concidering on the shared host it was 19 seconds, I'd say that is a EXTREME improvement. Keep in mind that included no php accelerators (available on everything but shared host), no mysql optimization, or any other tweaks. Check 2bits.com for articles on drupal optimization

PixelClever’s picture

@Kryptik, Please read the threads more carefully, this is happening for many people on non shared hosting set ups. For me, for example this is happening for me only on my local test server. On my shared hosting it works fine. It has nothing to do with modules or themes. As stated in the earlier threads this is happening on a fresh install (meaning in my case no third party modules, and Garland theme only) and I am getting these same ridiculous queries.

PixelClever’s picture

Version: 6.6 » 7.x-dev

@my-family, There was a reason this thread was moved to 7x. All changes in core are made in head and then backported, if you want the programmers that handle this level of problem to notice it then it needs to stay there.

alexanderpas’s picture

please note that the myISAM doesn't support transactions.

jegianop’s picture

Hi All,
I hope that I am posting this in the correct place.
I am a relative newbie to CMS. I wanted to switch to Drupal for an internal CMS at work due to the additional features included in Drupal over Joomla.
However (IMHO) I wonder how 6.6 was released when an issue such as these slow admin pages exist. I can see that the developers may want to move ahead on a new release, but since there seems to be a number of people having issues with the admin module, I cannot see as to why the priority has not been placed on fixing 6.6 first.
I only started looking at the admin module/pages today and was unimpressed with the performance, actually very disappointed. I am running Drupal on a standalone host for testing with basically no users.
My choice of a CMS may still be up in the air. Or I may try an older version of Drupal.

arhak’s picture

@jegianop - if you find this issue is blocking your way (meaning you don't know/want to figure it out) then I would recommend you Drupal 5.x
Next time, please: go to the forums for such a support question rather than dirtying an existing issue

PetrL’s picture

I also have a problem with that. On my hosting is exec_time set on 30 seconds. For me helped to switch off module administration menu. Btw. It took me while to find out how to switch off the module when I can not go to module page of drupal. I did it trough (phpMyAdmin) database table "system" and changed field "status" to value 0. I am not sure if it is correct, but ti was only way I have found out.

blueskiwi’s picture

I too have this frustrating problem on my local (win xp) dev pc

From my experience it is not about how many modules you have enabled, but how many modules you have downloaded to your 'modules' folder.

eg I did a default install... loaded fine. Copied my modules folder across from another site. The modules page is slow to load, even before I've enabled the new modules.

Any sign of a fix?
Why so many queries just to display the page?
How can I tweak my MySQL config to speed it up?

gpk’s picture

>The modules page is slow to load, even before I've enabled the new modules.
This suggests that your PC may have insufficient RAM. The modules are not loaded until they are enabled, though their .info files *are* parsed and that info is stored in the DB.

I'd say the minimum PC spec for running Drupal 6 under XP would be something like Pentium 4 with 768MB RAM.

The number of queries should not change drastically simply by moving unenabled modules around. If it does then perhaps you could post back with some stats.

PixelClever’s picture

I have 2 gigs of Ram and 2.6 gigahertz of cpu. This has nothing to do with processor speed. I edit music while watching video with this machine with no problem.

goodbye’s picture

Status: Closed (won't fix) » Active

deleted!

Damien Tournoud’s picture

Component: base system » admin.module
Status: Active » Closed (duplicate)
goodbye’s picture

Status: Active » Closed (won't fix)

deleted!

2ndChanceTech’s picture

Version: 7.x-dev » 6.8
Status: Closed (duplicate) » Closed (won't fix)

Although I'm sure this will be argued with, but I'm sure it has to do with server configuration, not necessarily on the hardware side.

Example:

Hostgator -> Shared hosting, I experienced this problem, and sometimes the page woud even time out (3minutes)
Eapps VPS -> Doesn't Happen
Pentium 4, 1GB Ram Laptop running Wamp -> Experienced this problem
Dual Pentium 3Ghz, 4GB Ram Desktop running Xampp -> No issues with this problem

Due to this, I believe it may surely be something to do with server configuration, but I have no idea where to start looking, as the only thing I've ever been able to do to correct it is move to a different server.

Do remember for those wondering about all the queries, that if a module is in the folder, even disabled it's .info is still loaded by the system. How fast is the modules page with absolutely no modules other then core ones installed? Perhaps there is a module playing culprit here? Another thing is perhaps the menu cache is not getting cleared and reloaded appropriately causing it to stall out? There's other threads dealing with that issue, that often result in the same problem.

goodbye’s picture

Status: Closed (duplicate) » Closed (won't fix)

deleted!

goodbye’s picture

Status: Closed (won't fix) » Closed (fixed)

deleted!

PixelClever’s picture

2ndChanceTech’s picture

Status: Closed (won't fix) » Closed (duplicate)

and you say I don't read well? I haven't touched the status of this thread or any other so don't include me in your ramblings. Also I was simply inputting what resolved the issue in my case if in fact the issues were completely related. Sorry for submitting an opinion in a thread on an open forum in attempts to help. All I can say at this point is, enjoy waiting for a fix, dealing with your issue which obviously got your panties in a bunch. And I'll do the opposite.

thePanz’s picture

Status: Closed (fixed) » Closed (duplicate)

I'm testing #302638: No-op and slow queries during menu rebuild in my D6.8 installation -dev and production server. My issue is related to MemoryLimit setted to 32MB in my hosting (with no possibility to change it)

Hope to have good news soon...

ShutterFreak’s picture

Although I don't have Devel stats at hand I can tell you that on the same server the Drupal 5 environments' admin pages run considerably faster than on Drupal 6. I don't understand why on an almost-idle 2-CPU server with 4GB of RAM the admin/build/modules needs several seconds to run, and many admin/** items are significantly slower than non-admin entries on a Drupal 6 site.

On another shared hosting site that hosts my personal Drupal powered website I can no longer configure the Drupal modules so maybe I'll have to downgrade to Drupal 5.

shaunak’s picture

Converting the storage engine from InnoDB to MyISAM helped speed up my install.

I found this for storage engine conversion:
http://forums.mysql.com/read.php?21,26193,190902#msg-190902

EgbertB’s picture

Don't know is this sheds light on the problem:
For me the issue was caused by, or set in motion by, OG content type admin

One of the sites we are building was showing between 10 seconds and one minute pageloads, making development virtually impossible.
There were an infinite lot of _menu_router_build queries.
admin/build/modules sometimes timed out

I first thought that the problem was connected to this thread: http://drupal.org/node/302638#comment-1198213 And still got the feeling it is.
But the patch did not work. (did not test this thoroughly though, could be I made some mistake in the process.)

SOLUTION
What worked was disabling OG content type admin. This of course is not the solution I crave for, as I need this module.....

TESTDATA: Drupal 6.10 and 6.9 (I tested the creation of a standard page node, cause testing the modules pages took too much of my precious time)
- With OG content type admin enabled
Executed 3099 queries in 5397.62 milliseconds. [...] Page execution time was 9814.64 ms.
- Without OG content type admin
Executed 180 queries in 1181.34 milliseconds. [...] Page execution time was 2479.04 ms.

Damien Tournoud’s picture

@EgbertB: nothing surprising, og_content_type_admin does this silly thing:

/**
 * Implementation of hook_init().
 */
function og_content_type_admin_init() {
  menu_router_build(TRUE);
  node_types_rebuild();	
}

Please open an issue against og_content_type_admin.

EgbertB’s picture

Version: 7.x-dev » 6.8

Check will do so.

See issue on this: http://drupal.org/node/330135

acrollet’s picture

Version: 7.x-dev » 6.9

Hello all,

we've been experiencing this problem as well, and I have finally had a chance to dig into the matter in a serious way this week. I found at least two separate major issues which will slow the load time for this page, which I will address in two separate posts for clarity's sake.

It is important to enable the devel module and turn on 'Collect query info' and 'Display page timer' to figure out what is taking up the majority of the time. If most of your time is taken up with database queries, (we were seeing 4k+ queries, taking 20-30 seconds) it might be worth your while to investigate MySQL's sync_binlog setting. (If you have binary logging enabled, which some distributions do by default.) Changing this setting from sync_binlog=1 to sync_binlog=0 dropped us from 20-30 seconds per pageload to a consistent ~1.5s. DISCLAIMER: carefully read and understand what this setting affects before changing it! We decided that the additional speed was worth a slight risk of data loss or inconsistency, but your needs might be different. (in case of a server crash) Alternatively, you may not even need the binary log at all.

edited to add: If UPDATE and INSERT statements are very slow, (>50ms) but your SELECT statements are fast, there's a good chance that this is the issue you have. If all queries are slow, you probably have another issue entirely - slow network between web & db server, slow disk on db server, db server out of memory and swapping - the possibilities are endless.

Second post coming soon.

acrollet’s picture

Version: 6.8 » 7.x-dev

Now for the follow-up - if your DB performance is good, but you're still having slow load times, there are three possible causes that I have found.

First, if your DocumentRoot is on NFS, (or some other slow filesystem) your performance will suffer, because it takes quite a number of trips to disk to build the modules page. C'est la vie.

Second, if you have the CVS deploy module installed, it will drastically increase the amount of disk access needed. (sextupled the calls to lstat64() in my very unscientific testing) More info available in this CVS deploy issue. nb: if you do not have open_basedir enabled, tweaking the realpath_cache_size parameter *may* help with this.

Third, if you have open_basedir configured, it too will increase your disk access. (nearly quintupled calls to lstat64())

If you have a combination of all three, God help your poor soul! (only slightly kidding) In our case, we need all three, so we're stuck. We're looking at how to get away from open_basedir, (especially since it is deprecated in php 6) but that's obviously not something that happens overnight. It's at least very nice to know what's going on, even if we can't do a whole lot about it at the moment. So, I'm hoping that this information will serve to guide the Drupal maintainers in taking any possible steps to alleviate this problem, especially since most of them probably work in local development environments with local disk, and don't feel the effects of it on a day-to-day basis. (Hence the version change to 7.x-dev.)

I hope this helps some people.

mbria’s picture

Version: 6.9 » 7.x-dev

Same issue on HostMonster.

I disabled every additional module, but admin/modules page still took arround 15 seconds.
When I enable some modules it goes to 30s (with 3400 queries) for page creation.

Creating, editing and deleting nodes are quite usable: 0.9 seconds and 144 queries.

Thanks for all your efforts done with this issue.

browlands’s picture

Version: 6.8 » 7.x-dev

On a laptop apache2triad WAMP localserver, the following changes helped enormously ... meaning i could get modules installed no fuss and quickly whereas the default settings that came in the package were causing slow and timed-out problems as discussed in various posts above.

In c:\apache2triad\php\bin\basic.ini and c:\windows\php.ini change the following settings: -

max_execution_time = 150
max_input_time = 300
memory_limit = 128M

Go to control panel, administrative tools, component services and restart the various apache2triad services.

As always take backups before performing administrative tasks to core.

I note D7 is addressing module install issues, in particular excessive querying and hopefully some of the technology used there will be back-ported to D6.

cqdbvvfy’s picture

Status: Closed (duplicate) » Needs review

try disabling the update module. if you can't even get to the admin menu, you can do so through SQL. you can find the modules in the 'system' table. just set status to 0. i posted something similar but people didn't even reply. but at least i got to fix it for myself...

catch’s picture

Status: Needs review » Closed (duplicate)

This is still a duplicate, as marked in #48.

acrollet’s picture

Status: Closed (duplicate) » Needs review

I disagree that this is a duplicate - slow and/or redundant DB queries are the issue for some people, but not all. For instance, this load of the modules page from one of our installations a few seconds ago:

Page execution time was 64131.48 ms. Executed 5720 queries in 3246.49 milliseconds

Please see my comment #62 for more info.

catch’s picture

Status: Needs review » Active

In that case there's still no patch. So back to active.

stormsweeper’s picture

If I had my druthers, all that cache clearing wouldn't happen on just the listing page, just when actually submitting the form. As it is, submitting the form actually causes all those to run twice as the delegation to system_modules_confirm_form() happens after that point:

function system_modules($form_state = array()) {
  drupal_rebuild_theme_registry();
  node_types_rebuild();
  menu_rebuild();
  cache_clear_all('schema', 'cache');
  // Get current list of modules.
  $files = module_rebuild_cache();

  uasort($files, 'system_sort_modules_by_info_name');

  if (!empty($form_state['storage'])) {
    return system_modules_confirm_form($files, $form_state['storage']);
  }

That delegation should really be the first thing to happen in the function, I think, before those three rebuild functions.

For my own sanity, I have moved those three rebuild functions to the submit handler, which makes viewing this page reasonably faster (it's still a huge form). Patch against DRUPAL-6 attached.

moshe weitzman’s picture

@stormsweeper - you are going to have to address with the reasons why those cache clears went in, and why they are not needed. i suggest you do that in #193366: execute various rebuilds when modules are submitted.

yes, this is an acknowledged issue and it is very annoying.

Netzarim’s picture

This patch has allowed me to access the modules page that I previously had to access by server node verses url. This should make things a lot easier.

webchick’s picture

Component: admin.module » system.module
Status: Active » Needs review
moshe weitzman’s picture

Status: Needs review » Closed (duplicate)
merpsit’s picture

Version: 7.x-dev » 6.x-dev

Disabling the update module totally fixed it for me. I was dealing with "basically never" getting to see my admin pages unless I turned off modules in phpmyadmin. This was happening with Date and Calendar, along with Wysiwyg API. There might have been a few more that would trigger the admin loading page freeze.

I just went back into phpmyadmin and set the Status of update in the system table to 0. Lightning fast loads, in comparison. Less than 2 seconds.

I'm glad this fix turned out to be very simple. I didn't want to dig any deeper into the server config.

Thanks blackice89.

merpsit’s picture

Update: This worked on 2 different installs. One at 6.x-dev and one at 6.12.

Give it a shot. Turn off the Update module.

Hope this helps.

gpk’s picture

@74/75: I think you probably tripped over #243253: Update status module can cause white screen if the check for updates takes too long which has similar symptoms, only slightly worse!

GuillaumeDuveau’s picture

FileSize
2.17 KB

Hello,

I'm having the same issue of /admin/* being slow especially /admin/build/modules, but only on my production server.
The production server is a cluster of 10 machines. 1 takes the incoming connections (and is backed-up by another machine) and distributes them across the other machines. MySQL server is on another machine.

I've tried these simple "tricks" :
- disabling update status doesn't change anything on the cluster
- no OG content type admin module is installed

Here are some elements that clearly show a problem with MySQL on the cluster, but it's not on specific queries. I guess a vanilla install of Drupal + Devel would give the same results... If somebody has any idea it would be of great help !

DEVEL
=====

cluster test 1
--------------
Executed 7921 queries in 9155.12 milliseconds. Queries taking longer than 5 ms and queries executed more than once, are highlighted. Page execution time was 47515.12 ms.
Memory used at: devel_init()=1.85 MB, devel_shutdown()=71.81 MB.

queries > 100ms
1111ms module_list SELECT name, filename, throttle FROM system WHERE type = 'module' AND status = 1 ORDER BY weight ASC, filename ASC
there's another module_list query which runs OK, normal it's a trivial query !!!
1.03ms module_list SELECT name, filename, throttle FROM system WHERE type = 'module' AND status = 1 AND bootstrap = 1 ORDER BY weight ASC, filename ASC
200.36ms _menu_router_build
122.07ms _menu_update_parental_status
105.74ms _menu_navigation_links_rebuild
101.84ms _menu_router_build

localhost
---------
Executed 7899 queries in 2070.13 milliseconds. Queries taking longer than 5 ms and queries executed more than once, are highlighted. Page execution time was 5983.53 ms.
Memory used at: devel_init()=2.1 MB, devel_shutdown()=78.54 MB.

longest query
87ms _menu_navigation_links_rebuild

let's look at the problematic queries on the cluster
0.16ms module_list SELECT name, filename, throttle FROM system WHERE type = 'module' AND status = 1 ORDER BY weight ASC, filename ASC
huge difference !!!
other module_list query which runs OK on the cluster
0.1ms module_list SELECT name, filename, throttle FROM system WHERE type = 'module' AND status = 1 AND bootstrap = 1 ORDER BY weight ASC, filename ASC
0.34ms _menu_router_build (same query as the 200.36ms on the cluster)

cluster test 2
--------------
Executed 7935 queries in 8417.75 milliseconds. Queries taking longer than 5 ms and queries executed more than once, are highlighted. Page execution time was 59705.34 ms.
Memory used at: devel_init()=1.85 MB, devel_shutdown()=71.64 MB.

queries > 100ms = different from test 1 !
540.43ms locale
290.47ms _menu_navigation_links_rebuild
110.92ms _menu_navigation_links_rebuild

MYSQL
=====

Differences in /admin/reports/status/sql
--------------------------------------------------
cluster :
Com_select 30
Qcache_queries_in_cache 0
Qcache_hits 0
Qcache_inserts 0

localhost :

Com_select 10
Qcache_queries_in_cache 143
Qcache_hits 104
Qcache_inserts 262

OK so I don't have any MySQL cache active on the cluster, but it changes nothing, see below.

Configurations
------------------
query cache size
cluster 0
localhost 16 777 216
> I tried to set query_cache_size at 0 on localhost, but I keep having good performance :
Executed 7911 queries in 2561.63 milliseconds. Queries taking longer than 5 ms and queries executed more than once, are highlighted. Page execution time was 6559.91 ms.

sync_binlog=0 on both, queries slow not depending on the type : SELECT, UPDATE, INSERT

other differences not very significant : in mysql-variables-diff.txt

storage engine = MyISAM for both

PHP
===
max_execution_time
both 30

max_input_time
both 60

memory_limit
both 128M

gpk’s picture

@77: The first couple of things I notice:

- 8,000 queries is a huge number. I guess it is a big site (as implied by your config details). If this is on all admin/* pages then it seems a bit excessive - can you confirm?; I can imagine you might have this many queries though on admin/build/modules if you have lots of Views, CCK, OG etc.

- >Executed 7921 queries in 9155.12 milliseconds. Queries taking longer than 5 ms and queries executed more than once, are highlighted. Page execution time was 47515.12 ms.
Memory used at: devel_init()=1.85 MB, devel_shutdown()=71.81 MB.
OK so 80% of the execution time is in PHP, not in the database. You need to start optimizing PHP first. Do the servers have sufficient RAM or are they swapping (i.e. in iowait while the disk thrashes)?
Also 70MB is a huge RAM requirement for a single page request. Would make sense if you are manipulating images, but otherwise it suggests that something is eating up huge amounts .. same might be causing the slowness. I think there is a module or patch that lets you investigate each module's RAM consumption. Try looking on the 2bits.com website.

HTH,

acrollet’s picture

@77 - I agree with all that was said in comment 78, here are a few more things to look at:

As far as mysql performance goes, it's not your biggest problem by any means, but those queries *are* running pretty slowly - I assume that you have gigabit ethernet or better between your php nodes and your mysql server? Have you checked that the link is in fact running at full bandwidth? How heavily loaded is your database server? If you run a test site on your production php nodes pointed at an unloaded mysql server, do the query times improve?

As far as php - definitely find out if you have sufficient memory, also investigate installing APC or another opcode cache. I assume that you're sharing disk between your nodes with NFS - unfortunately, that's probably the source of at least some of your problems. CVS deploy + nfs can be a real performance killer on the modules page in our experience.

hope some of this helps.

GuillaumeDuveau’s picture

Thanks a lot gpk and acrollet !

It's a shared hosting cluster, hence the config. I'm just an user, so I'll ask some of your questions to my admins. Connectivity between PHP nodes and the MySQL server, and the MySQL server load, will be especially investigated. I'll try to see which module eats the RAM, too, but I don't think the server is swapping anyway.

It's not a big site at all : around 64 modules, 30 views, 10 CCK fields types, 15 content types, 500 nodes, 500 users

8k queries is just on the modules pages :
/admin/build 149 queries
/admin/settings/devel 188 queries
/admin/build/views 389 queries
most complex public page (a panel) : 669 queries
typical node : around 200 queries

8k queries in 9k ms, page execution time 50k ms : of course a PHP opcode cache could help, but on my Centrino laptop as localhost, without any PHP cache as well, the execution time is 10 times less. So I was more thinking that the PHP execution time could be big because PHP has to wait a lot between sending the MySQL query and getting the results. Executed 7935 queries in 8417.75 milliseconds -> does this calculation by Devel take into account the total time, seen from PHP, between the first query sent and the last query result, or is it just the sum of the queries durations seen from MySQL ?

gpk’s picture

OK since you say this a shared host an opcode cache could help generally to reduce the server load by pre-compiling Drupal and other scripts. 64 modules is a fairly high number (though actually I have 60 on a site I'm working on!) but even so the PHP compile time would probably be under a second of actual processing time ... but if server load is high then everything just multiplies up... So what is the server load generally (run the shell command "uptime" if you have permissions to do so, or your account control panel may have an option to do same)?

IIRC the time reported by devel.module is the sum over all queries of the elapsed time since the query was issued by PHP until the result was received back from MySQL. However the overall page execution time is also just an elapsed time, not the time your process was running in core, hence if you are only getting 1/10 share, say, of a CPU because of high server load then that could easily account for the times you are seeing.

GuillaumeDuveau’s picture

Thanks again gpk, I'll try to get APC installed.

newbuntu’s picture

It sounds like there is a solution coming up http://drupal.org/node/512962

jasonabc’s picture

also noticing dreadful performance when trying to save a View (over 3,000 queries, takes over two minutes to complete the save) and creating product classes (UberCart). Takes nearly two minutes to create a class?! According to Devel - seems menu_rebuild is the culprit here also. Anyone else experiencing this on View save or Class creation?

v.eckert’s picture

Hi,

@guix,
you propably want to add
skip-name-resolve
to your MySQL-configuration-file and restart MySQL. Otherwise every SQL-statement generates a DNS-query.
If I read your diff right, you log _all_ your queries made to your production server. This usually is a huge performance killer. Personally, I just keep the log-bin and log-slow-queries activated.

HTH, Volker

GuillaumeDuveau’s picture

Thanks a lot v.eckert, I'll try your suggestions !!!

domidc’s picture

subscribing

domidc’s picture

subscribing

sinasalek’s picture

subscribing

mikekelly’s picture

Subscribing

jboeger’s picture

Subscribing. Hoping something shows up here to kickstart my rackspace cloud site from creepy crawly.

Exploratus’s picture

subscribe

jhm’s picture

I noticed that the UPDATE statement in module_rebuild_cache always replaces the entire row, including the primary key, even though that is not necessary in most cases.

I added an additional test just for kicks comparing $file->old_filename with $file->filename, and when it is the same I don't update the filename column. Not beautiful but objectively faster

    // Update the contents of the system table:
    if (isset($file->status) || (isset($file->old_filename) && $file->old_filename != $file->filename)) {
      if(isset($file->old_filename) && $file->old_filename != $file->filename) {
          db_query("UPDATE {system} SET info = '%s', name = '%s', filename = '%s', bootstrap = %d WHERE filename = '%s'"
              , serialize($files[$filename]->info)
              , $file->name
              , $file->filename
              , $bootstrap
              , $file->old_filename
          );
      } else {
          db_query("UPDATE {system} SET info = '%s', name = '%s', bootstrap = %d WHERE filename = '%s'"
              , serialize($files[$filename]->info)
              , $file->name
              , $bootstrap
              , $file->filename
          );
      }
    }
    else {
      // This is a new module.
      $files[$filename]->status = 0;
      $files[$filename]->throttle = 0;
      db_query("INSERT INTO {system} (name, info, type, filename, status, throttle, bootstrap) VALUES ('%s', '%s', '%s', '%s', %d, %d, %d)", $file->name, serialize($files[$filename]->info), 'module', $file->filename, 0, 0, $bootstrap);
    }

PS: I use MyISAM tables on Mac Pro 10.6.4 with PHP5.2.13 MySQL 5.1.40 and D6.17

jhm’s picture

To really solve this I had to patch system.module:system_get_files_database and add the old serialized info as info_old to the result (I also switched update_status from daily to weekly)

function system_get_files_database(&$files, $type) {
  // Extract current files from database.
  $result = db_query("SELECT filename, name, type, status, throttle, schema_version, info AS info_old FROM {system} WHERE type = '%s'", $type);
  while ($file = db_fetch_object($result)) {
    if (isset($files[$file->name]) && is_object($files[$file->name])) {
      $file->old_filename = $file->filename;
      foreach ($file as $key => $value) {
        if (!isset($files[$file->name]) || !isset($files[$file->name]->$key)) {
          $files[$file->name]->$key = $value;
        }
      }
    }
  }
}

and in module.inc:module_rebuild_cache I now compare the two values before updating the system table, which is what takes all the time.

This is a snippet from within module_rebuild_cache

    // Update the contents of the system table:
    $serialize = serialize($files[$filename]->info);
    if (isset($file->status) || (isset($file->old_filename) && $file->old_filename != $file->filename)) {
      // info_old set in system.module:system_get_files_database
      if($file->old_filename != $file->filename || $file->info_old != $serialize)
      {
          drupal_set_message($file->name);
          db_query("UPDATE {system} SET info = '%s', name = '%s', filename = '%s', bootstrap = %d WHERE filename = '%s'"
              , $serialize
              , $file->name
              , $file->filename
              , $bootstrap
              , $file->old_filename
          );
      }
    }
    else {
      // This is a new module.
      $files[$filename]->status = 0;
      $files[$filename]->throttle = 0;
      db_query("INSERT INTO {system} (name, info, type, filename, status, throttle, bootstrap) VALUES ('%s', '%s', '%s', '%s', %d, %d, %d)"
          , $file->name
          , $serialize
          , 'module'
          , $file->filename
          , 0, 0, $bootstrap);
    }

this pretty much solved this problem for me. If someone else confirms this I am ready to provide a patch.

niteshade’s picture

subscribing

david3000’s picture

Thanks so much newbuntu!! this is it! myisam!! greetings