Hmmm..... for some reason my above post didn't take... maybe it was too long, but here's the gist of it in a comment posting:
Since adding eaccelerator functionality, my site is doing better now, thanks to the help from gpk, khalid, and dominic. [You guys are great!]
However, I am still noticing, that occassionally, my site loads pages quite slowly. It looks like the pager_query function is not working exactly right, or has some kind of bottle neck.
For example the following query [noted from the devel module] took about 6697 ms to complete:
6697.93 1 pager_query SELECT COUNT(*) FROM accesslog WHERE uid = 598
Does anyone have any ideas about why pager_query is taking so long? Do I just need to schedule a truncation of accesslog with greater frequency? I think I'm only keeping the last 24hours of log information as it is...
Any thoughts or advice would be much appreciated.
I'm attaching an abbreviated devel query printout description below.
Executed 398 queries in 7217.38 milliseconds. Queries taking longer than 5 ms and queries executed more than once, are highlighted.Page execution time was 7685.76 ms. ms # where query 0.19 1 drupal_lookup_path SELECT COUNT(pid) FROM url_alias 0.79 1 drupal_lookup_path SELECT src FROM url_alias WHERE dst = 'user/598/track/navigation' 0.3 1 module_list SELECT name, filename, throttle, bootstrap FROM system WHERE type = 'module' AND status = 1 ORDER BY weight ASC, filename ASC 1.11 2 cache_get SELECT data, created, headers, expire FROM cache WHERE cid = 'locale:' 0.15 1 locale_supported_languages SELECT locale, name, formula, enabled FROM locales_meta ORDER BY isdefault DESC, enabled DESC, name ASC
<SNIP>
4.06 1 locale_refresh_cache SELECT s.source, t.translation, t.locale FROM locales_source s INNER JOIN locales_target t ON s.lid = t.lid WHERE t.locale = 'en-US' AND LENGTH(s.alias) < 75 0.11 1 locale SELECT s.lid, t.translation FROM locales_source s INNER JOIN locales_target t ON s.lid = t.lid WHERE s.alias = substring('Operations', 1, 255) AND t.locale = 'en-US' 6697.93 1 pager_query SELECT COUNT(*) FROM accesslog WHERE uid = 598 52.4 1 pager_query SELECT aid, timestamp, path, title FROM accesslog WHERE uid = 598 ORDER BY timestamp DESC LIMIT 0, 30
Then post the queries taking the most time (truncate them so they don't mess the page up when you post them.
--
Drupal development and customization: 2bits.com
Personal: Baheyeldin.com
--
Drupal performance tuning, development, customization and consulting: 2bits.com, Inc.
Personal blog: Baheyeldin.com.
sorry about the delay in following up on this... I've just been looking for a good example of this 'cause it doesn't happen too often... but anyways, I finally got one!... So... this example is good enough to probably give some ideas about it... and this time I sorted by time, rather than source :-) [thanks for the tip, Khalid!]
Executed 450 queries in 1307.36 milliseconds. Queries taking longer than 5 ms and queries executed more than once, are highlighted.Page execution time was 1746.18 ms.
ms # where query -------------------------- 806.95 1 pager_query SELECT count(DISTINCT(node.nid)) FROM node node LEFT JOIN votingapi_cache votingapi_cache ON node.nid = votingapi_cache.content_id AND votingapi_cache.content_type = 'node' LEFT JOIN node_comment_statistics node_comment_statistics ON node.nid = node_comment_statistics.nid INNER JOIN users users ON node.uid = users.uid WHERE (node.status = '1') AND (votingapi_cache.function = 'count' OR votingapi_cache.function IS NULL) AND (node.type IN ('audio','blog','book','event','forum','image','og','video')) AND (node.promote = '1') AND ((votingapi_cache.value_type = 'points') OR (votingapi_cache.value_type is NULL)) AND ((votingapi_cache.tag = 'vote') OR (votingapi_cache.tag is NULL)) AND ((votingapi_cache.function = 'count') OR (votingapi_cache.function is NULL))
251.57 1 pager_query SELECT DISTINCT(node.nid), node.sticky AS node_sticky, node_comment_statistics.last_comment_timestamp AS node_comment_statistics_last_comment_timestamp_last_comment_timestamp, node.type AS node_type, node.title AS node_title, node.changed AS node_changed, users.name AS users_name, users.uid AS users_uid, node_comment_statistics.comment_count AS node_comment_statistics_comment_count, node_comment_statistics.last_comment_timestamp AS node_comment_statistics_last_comment_timestamp, votingapi_cache.value AS votingapi_cache_value, votingapi_cache.value_type AS votingapi_cache_value_type, votingapi_cache.tag AS votingapi_cache_tag, votingapi_cache.function AS votingapi_cache_function, votingapi_cache.content_type AS votingapi_cache_content_type, votingapi_cache.content_id AS votingapi_cache_content_id FROM node node LEFT JOIN votingapi_cache votingapi_cache ON node.nid = votingapi_cache.content_id AND votingapi_cache.content_type = 'node' LEFT JOIN node_comment_statistics node_comment_statistics ON node.nid = node_comment_statistics.nid INNER JOIN users users ON node.uid = users.uid WHERE (node.status = '1') AND (votingapi_cache.function = 'count' OR votingapi_cache.function IS NULL) AND (node.type IN ('audio','blog','book','event','forum','image','og','video')) AND (node.promote = '1') AND ((votingapi_cache.value_type = 'points') OR (votingapi_cache.value_type is NULL)) AND ((votingapi_cache.tag = 'vote') OR (votingapi_cache.tag is NULL)) AND ((votingapi_cache.function = 'count') OR (votingapi_cache.function is NULL)) ORDER BY node_sticky DESC, node_comment_statistics_last_comment_timestamp_last_comment_timestamp DESC LIMIT 0, 25
156.95 1 locale_refresh_cache SELECT s.source, t.translation, t.locale FROM locales_source s INNER JOIN locales_target t ON s.lid = t.lid WHERE t.locale = 'en-US' AND LENGTH(s.alias) < 75
17.15 1 cache_set UPDATE cache SET data = 'a:6610:{s:6:\"Delete\";b:1;s:51:\"Are you sure you want to delete the language %name?\";b:1;s:34:\"[<a href=\"%link\">more help...</a>]\";b:1;s:18:\"Go to page %number\";b:1;s:15:\"Go to last page\";b:1;s:7:\"last »\";b:1;s:15:\"Go to next page\";b:1;s:8:\"next ›\";b:1;s:19:\"Go to previous page\";b:1;s:16:\"Go to first page\";b:1;s:12:\"‹ previous\";b:1;s:8:\"« first\";b:1;s:4:\"edit\";b:1;s:7:\"Locales\";b:1;s:6:\"String\";b:1;s:25:\"Only untranslated strings\";b:1;s:23:\"Only translated strings\";b:1;s:28:\"All strings in that language\";b:1;s:9:\"Search in\";b:1;s:28:\"English (provided by Drupal)\";b:1;s:13:\"All languages\";b:1;s:8:\"Language\";b:1;s:62:\"Leave blank to show all strings. The search is case sensitive.\";b:1;s:21:\"Strings to search for\";b:1;s:6:\"Export\";b:1;s:13:\"Language name\";b:1;s:6:\"Import\";b:1;s:53:\"Existing strings are kept, only new strings are added\";b:1;s:70:\"Strings in the uploaded file replace existing ones, new ones are <--snip-->
2.03 1 cache_get SELECT data, created, headers, expire FROM cache WHERE cid = 'views_tables:en-US' 1.8 1 cache_get SELECT data, created, headers, expire FROM cache WHERE cid = 'menu:2:en-US' 0.65 1 cache_get SELECT data, created, headers, expire FROM cache WHERE cid = 'views_style_plugins:en-US' 0.65 1 cache_get SELECT data, created, headers, expire FROM cache WHERE cid = 'filter:1:5251d2c41bcf432df6ac3240a16f730f' 0.62 1 cache_get SELECT data, created, headers, expire FROM cache WHERE cid = 'views_arguments:en-US' 0.56 1 user_load SELECT * FROM users u WHERE uid = 2 0.47 1 db_lock_table LOCK TABLES cache WRITE 0.46 1 statistics_exit INSERT INTO accesslog (title, path, url, hostname, uid, sid, timer, timestamp) values('all recent posts', 'tracker', 'http://www.ithou.org/tracker', '68.183.91.76', 2, '25105215c87ca91ad90bade0ccc6d56e', 1742, 1191975538) 0.41 3 cache_clear_all DELETE FROM cache WHERE cid = 'locale:' 0.37 3 cache_clear_all DELETE FROM cache WHERE cid = 'locale:' 0.32 15 locale SELECT s.lid, t.translation FROM locales_source s INNER JOIN locales_target t ON s.lid = t.lid WHERE s.alias = substring('%count days', 1, 255) AND t.locale = 'en-US' 0.31 1 drupal_lookup_path SELECT dst FROM url_alias WHERE src = 'node/2670' 0.31 1 drupal_lookup_path SELECT dst FROM url_alias WHERE src = 'node/2414' 0.27 1 _views_load_view SELECT v.* FROM view_view v WHERE v.name = 'tracker' 0.27 1 module_list SELECT name, filename, throttle, bootstrap FROM system WHERE type = 'module' AND status = 1 ORDER BY weight ASC, filename ASC 0.27 4 locale SELECT s.lid, t.translation FROM locales_source s INNER JOIN locales_target t ON s.lid = t.lid WHERE s.alias = substring('1 day', 1, 255) AND t.locale = 'en-US' 0.27 1 locale SELECT s.lid, t.translation FROM locales_source s INNER JOIN locales_target t ON s.lid = t.lid WHERE s.alias = substring('no votes', 1, 255) AND t.locale = 'en-US' 0.26 1 locale SELECT s.lid, t.translation FROM locales_source s INNER JOIN locales_target t ON s.lid = t.lid WHERE s.alias = substring('[!site] !type subscription update for !name : !subject', 1, 255) AND t.locale = ''
Same problem for me.
Seen on a live site, so I can provide any kind of examples... This is running drupal5, so maybe no one wants to spend any time trying to find a workaround or improvement...
example:
688.92 1 pager_query SELECT node.nid, votingapi_cache_vote_percent_average.value AS votingapi_cache_vote_percent_average_value, node.created AS node_created_created, field_video_op_videos.video_id AS field_video_op_videos_preview_image_link, node.title AS node_title, node.changed AS node_changed, node.created AS node_created, node_data_field_recorded.field_recorded_value AS node_data_field_recorded_field_recorded_value, field_video_op_videos.duration AS field_video_op_videos_duration, node_data_field_old_full_location.field_old_full_location_value AS node_data_field_old_full_location_field_old_full_location_value, users.name AS users_name, users.uid AS users_uid, node_data_field_subspecies.field_subspecies_value AS node_data_field_subspecies_field_subspecies_value, node_data_field_old_recorded.field_old_recorded_value AS node_data_field_old_recorded_field_old_recorded_value FROM node node LEFT JOIN content_field_species node_data_field_species ON node.vid = node_data_field_species.vid LEFT JOIN votingapi_cache votingapi_cache_vote_percent_average ON node.nid = votingapi_cache_vote_percent_average.content_id AND votingapi_cache_vote_percent_average.content_type = 'node' AND votingapi_cache_vote_percent_average.value_type = 'percent' AND votingapi_cache_vote_percent_average.tag = 'vote' AND votingapi_cache_vote_percent_average.function = 'average' LEFT JOIN content_type_video node_data_field_video ON node.vid = node_data_field_video.vid LEFT JOIN op_videos field_video_op_videos ON node_data_field_video.field_video_video_id = field_video_op_videos.video_id LEFT JOIN content_field_recorded node_data_field_recorded ON node.vid = node_data_field_recorded.vid LEFT JOIN content_type_video node_data_field_old_full_location ON node.vid = node_data_field_old_full_location.vid INNER JOIN users users ON node.uid = users.uid LEFT JOIN content_field_subspecies node_data_field_subspecies ON node.vid = node_data_field_subspecies.vid LEFT JOIN content_type_video node_data_field_old_recorded ON node.vid = node_data_field_old_recorded.vid WHERE (node.type IN ('video')) AND (node.status = '1') AND (node_data_field_species.field_species_nid = 7692) AND (node.nid NOT IN (7692)) ORDER BY votingapi_cache_vote_percent_average_value DESC, node_created_created DESC LIMIT 0, 5
Comments
Hmmm..... for some reason my
Hmmm..... for some reason my above post didn't take... maybe it was too long, but here's the gist of it in a comment posting:
Since adding eaccelerator functionality, my site is doing better now, thanks to the help from gpk, khalid, and dominic. [You guys are great!]
However, I am still noticing, that occassionally, my site loads pages quite slowly. It looks like the pager_query function is not working exactly right, or has some kind of bottle neck.
For example the following query [noted from the devel module] took about 6697 ms to complete:
6697.93 1 pager_query SELECT COUNT(*) FROM accesslog WHERE uid = 598Does anyone have any ideas about why pager_query is taking so long? Do I just need to schedule a truncation of accesslog with greater frequency? I think I'm only keeping the last 24hours of log information as it is...
Any thoughts or advice would be much appreciated.
I'm attaching an abbreviated devel query printout description below.
Executed 398 queries in 7217.38 milliseconds. Queries taking longer than 5 ms and queries executed more than once, are highlighted.Page execution time was 7685.76 ms.
ms # where query
0.19 1 drupal_lookup_path SELECT COUNT(pid) FROM url_alias
0.79 1 drupal_lookup_path SELECT src FROM url_alias WHERE dst = 'user/598/track/navigation'
0.3 1 module_list SELECT name, filename, throttle, bootstrap FROM system WHERE type = 'module' AND status = 1 ORDER BY weight ASC, filename ASC
1.11 2 cache_get SELECT data, created, headers, expire FROM cache WHERE cid = 'locale:'
0.15 1 locale_supported_languages SELECT locale, name, formula, enabled FROM locales_meta ORDER BY isdefault DESC, enabled DESC, name ASC
<SNIP>
4.06 1 locale_refresh_cache SELECT s.source, t.translation, t.locale FROM locales_source s INNER JOIN locales_target t ON s.lid = t.lid WHERE t.locale = 'en-US' AND LENGTH(s.alias) < 75
0.11 1 locale SELECT s.lid, t.translation FROM locales_source s INNER JOIN locales_target t ON s.lid = t.lid WHERE s.alias = substring('Operations', 1, 255) AND t.locale = 'en-US'
6697.93 1 pager_query SELECT COUNT(*) FROM accesslog WHERE uid = 598
52.4 1 pager_query SELECT aid, timestamp, path, title FROM accesslog WHERE uid = 598 ORDER BY timestamp DESC LIMIT 0, 30
<SNIP>
Albert
Esalen Alumni Group
I am experiencing the same
I am experiencing the same with pager_query
I have a big hierarchical taxonomy for a cck enabled node and pager_query uses a lot of joins which I suspect to be the suspect.
Has anyone solved this?
I saw a taxonomy_depth module but that is still in development.
Cheers
G
****Me and Drupal :)****
Clickbank IPN - Sell online or create a membership site with the largest affiliate network!
Review Critical - One of my sites
Sort by time
Sort the devel output by time, not by source.
Then post the queries taking the most time (truncate them so they don't mess the page up when you post them.
--
Drupal development and customization: 2bits.com
Personal: Baheyeldin.com
--
Drupal performance tuning, development, customization and consulting: 2bits.com, Inc.
Personal blog: Baheyeldin.com.
sorry about the delay in
sorry about the delay in following up on this... I've just been looking for a good example of this 'cause it doesn't happen too often... but anyways, I finally got one!... So... this example is good enough to probably give some ideas about it... and this time I sorted by time, rather than source :-) [thanks for the tip, Khalid!]
Executed 450 queries in 1307.36 milliseconds. Queries taking longer than 5 ms and queries executed more than once, are highlighted.Page execution time was 1746.18 ms.
ms # where query
--------------------------
806.95 1 pager_query SELECT count(DISTINCT(node.nid)) FROM node node LEFT JOIN votingapi_cache votingapi_cache ON node.nid = votingapi_cache.content_id AND votingapi_cache.content_type = 'node' LEFT JOIN node_comment_statistics node_comment_statistics ON node.nid = node_comment_statistics.nid INNER JOIN users users ON node.uid = users.uid WHERE (node.status = '1') AND (votingapi_cache.function = 'count' OR votingapi_cache.function IS NULL) AND (node.type IN ('audio','blog','book','event','forum','image','og','video')) AND (node.promote = '1') AND ((votingapi_cache.value_type = 'points') OR (votingapi_cache.value_type is NULL)) AND ((votingapi_cache.tag = 'vote') OR (votingapi_cache.tag is NULL)) AND ((votingapi_cache.function = 'count') OR (votingapi_cache.function is NULL))
251.57 1 pager_query SELECT DISTINCT(node.nid), node.sticky AS node_sticky, node_comment_statistics.last_comment_timestamp AS node_comment_statistics_last_comment_timestamp_last_comment_timestamp, node.type AS node_type, node.title AS node_title, node.changed AS node_changed, users.name AS users_name, users.uid AS users_uid, node_comment_statistics.comment_count AS node_comment_statistics_comment_count, node_comment_statistics.last_comment_timestamp AS node_comment_statistics_last_comment_timestamp, votingapi_cache.value AS votingapi_cache_value, votingapi_cache.value_type AS votingapi_cache_value_type, votingapi_cache.tag AS votingapi_cache_tag, votingapi_cache.function AS votingapi_cache_function, votingapi_cache.content_type AS votingapi_cache_content_type, votingapi_cache.content_id AS votingapi_cache_content_id FROM node node LEFT JOIN votingapi_cache votingapi_cache ON node.nid = votingapi_cache.content_id AND votingapi_cache.content_type = 'node' LEFT JOIN node_comment_statistics node_comment_statistics ON node.nid = node_comment_statistics.nid INNER JOIN users users ON node.uid = users.uid WHERE (node.status = '1') AND (votingapi_cache.function = 'count' OR votingapi_cache.function IS NULL) AND (node.type IN ('audio','blog','book','event','forum','image','og','video')) AND (node.promote = '1') AND ((votingapi_cache.value_type = 'points') OR (votingapi_cache.value_type is NULL)) AND ((votingapi_cache.tag = 'vote') OR (votingapi_cache.tag is NULL)) AND ((votingapi_cache.function = 'count') OR (votingapi_cache.function is NULL)) ORDER BY node_sticky DESC, node_comment_statistics_last_comment_timestamp_last_comment_timestamp DESC LIMIT 0, 25
156.95 1 locale_refresh_cache SELECT s.source, t.translation, t.locale FROM locales_source s INNER JOIN locales_target t ON s.lid = t.lid WHERE t.locale = 'en-US' AND LENGTH(s.alias) < 75
17.15 1 cache_set UPDATE cache SET data = 'a:6610:{s:6:\"Delete\";b:1;s:51:\"Are you sure you want to delete the language %name?\";b:1;s:34:\"[<a href=\"%link\">more help...</a>]\";b:1;s:18:\"Go to page %number\";b:1;s:15:\"Go to last page\";b:1;s:7:\"last »\";b:1;s:15:\"Go to next page\";b:1;s:8:\"next ›\";b:1;s:19:\"Go to previous page\";b:1;s:16:\"Go to first page\";b:1;s:12:\"‹ previous\";b:1;s:8:\"« first\";b:1;s:4:\"edit\";b:1;s:7:\"Locales\";b:1;s:6:\"String\";b:1;s:25:\"Only untranslated strings\";b:1;s:23:\"Only translated strings\";b:1;s:28:\"All strings in that language\";b:1;s:9:\"Search in\";b:1;s:28:\"English (provided by Drupal)\";b:1;s:13:\"All languages\";b:1;s:8:\"Language\";b:1;s:62:\"Leave blank to show all strings. The search is case sensitive.\";b:1;s:21:\"Strings to search for\";b:1;s:6:\"Export\";b:1;s:13:\"Language name\";b:1;s:6:\"Import\";b:1;s:53:\"Existing strings are kept, only new strings are added\";b:1;s:70:\"Strings in the uploaded file replace existing ones, new ones are
<--snip-->
2.03 1 cache_get SELECT data, created, headers, expire FROM cache WHERE cid = 'views_tables:en-US'
1.8 1 cache_get SELECT data, created, headers, expire FROM cache WHERE cid = 'menu:2:en-US'
0.65 1 cache_get SELECT data, created, headers, expire FROM cache WHERE cid = 'views_style_plugins:en-US'
0.65 1 cache_get SELECT data, created, headers, expire FROM cache WHERE cid = 'filter:1:5251d2c41bcf432df6ac3240a16f730f'
0.62 1 cache_get SELECT data, created, headers, expire FROM cache WHERE cid = 'views_arguments:en-US'
0.56 1 user_load SELECT * FROM users u WHERE uid = 2
0.47 1 db_lock_table LOCK TABLES cache WRITE
0.46 1 statistics_exit INSERT INTO accesslog (title, path, url, hostname, uid, sid, timer, timestamp) values('all recent posts', 'tracker', 'http://www.ithou.org/tracker', '68.183.91.76', 2, '25105215c87ca91ad90bade0ccc6d56e', 1742, 1191975538)
0.41 3 cache_clear_all DELETE FROM cache WHERE cid = 'locale:'
0.37 3 cache_clear_all DELETE FROM cache WHERE cid = 'locale:'
0.32 15 locale SELECT s.lid, t.translation FROM locales_source s INNER JOIN locales_target t ON s.lid = t.lid WHERE s.alias = substring('%count days', 1, 255) AND t.locale = 'en-US'
0.31 1 drupal_lookup_path SELECT dst FROM url_alias WHERE src = 'node/2670'
0.31 1 drupal_lookup_path SELECT dst FROM url_alias WHERE src = 'node/2414'
0.27 1 _views_load_view SELECT v.* FROM view_view v WHERE v.name = 'tracker'
0.27 1 module_list SELECT name, filename, throttle, bootstrap FROM system WHERE type = 'module' AND status = 1 ORDER BY weight ASC, filename ASC
0.27 4 locale SELECT s.lid, t.translation FROM locales_source s INNER JOIN locales_target t ON s.lid = t.lid WHERE s.alias = substring('1 day', 1, 255) AND t.locale = 'en-US'
0.27 1 locale SELECT s.lid, t.translation FROM locales_source s INNER JOIN locales_target t ON s.lid = t.lid WHERE s.alias = substring('no votes', 1, 255) AND t.locale = 'en-US'
0.26 1 locale SELECT s.lid, t.translation FROM locales_source s INNER JOIN locales_target t ON s.lid = t.lid WHERE s.alias = substring('[!site] !type subscription update for !name : !subject', 1, 255) AND t.locale = ''
Albert
Esalen Alumni Group
Explains?
Can you please run explains on the queries that take the most time?
--
Drupal development and customization: 2bits.com
Personal: Baheyeldin.com
--
Drupal performance tuning, development, customization and consulting: 2bits.com, Inc.
Personal blog: Baheyeldin.com.
Same problem for me. Seen on
Same problem for me.
Seen on a live site, so I can provide any kind of examples... This is running drupal5, so maybe no one wants to spend any time trying to find a workaround or improvement...
example:
And the explain of this query is:
It's taking too many seconds to load the page.
http://ibc.lynxeds.com/species/striped-wren-babbler-kenopia-striata?only...
Any help?
Thanks!