Support Forum

Advanced Search
Forum Scope


Match



Forum Options



Minimum search word length is 3 characters - maximum search word length is 84 characters
general-topic
RSS creates long and slow query errors
Avatar
kvr28
Member
Free Members
sp_UserOfflineSmall Offline
Oct 29, 2014 - 7:12 am

Hey guys, was looking at my server error log (not the forum error log) and noticed that the rss is generating long and slow querys, here is examples of the errors, is this a concern? 

[Wed Oct 29 10:44:06 2014] [error] [client xx.xxx.xx.xx] [WPE Monitoring] Stopwatch php.pod-2294.function.mysql_query.duration exceeded 1000ms. Was: 2866ms.
#0 wpe\\measure\\LoggingStopwatch->logStackTrace(2866) called at [/nas/wp/www/common/production/measure.php:198]
#1 wpe\\measure\\LoggingStopwatch->lap_ended(2866) called at [/nas/wp/www/common/production/measure.php:134]
#2 wpe\\measure\\Stopwatch->lapstart() called at [/nas/wp/www/common/production/measure.php:152]
#3 wpe\\measure\\Stopwatch->stop() called at [/nas/wp/www/common/production/statsd_monitoring.php(256) : runkit created function:19]
#4 mysql_query(SELECT rufus_sfposts.post_id, post_content, post_date, rufus_sfposts.topic_id, rufus_sfposts.forum_id,
\t\t\t\t\t\t\t\t rufus_sfposts.user_id, guest_name, post_status, post_index, forum_name, forum_slug, forum_disabled, rufus_sfforums.group_id, group_name,
\t\t\t\t\t\t\t\t topic_name, topic_slug, rufus_sftopics.post_count, topic_opened, display_name FROM rufus_sfposts JOIN rufus_sfforums ON rufus_sfforums.forum_id = rufus_sfposts.forum_id JOIN rufus_sfgroups ON rufus_sfgroups.group_id = rufus_sfforums.group_id JOIN rufus_sftopics ON rufus_sftopics.topic_id = rufus_sfposts.topic_id LEFT JOIN rufus_sfmembers ON rufus_sfmembers.user_id = rufus_sfposts.user_id WHERE rufus_sfforums.forum_rss_private = 0 AND rufus_sfposts.forum_id IN (5849,5850,5851,5852,5853,5854,5855,5856,5857,5858,5859,5863,5864) ORDER BY rufus_sfposts.post_id DESC LIMIT 15 /* From [thehomesteadingboards.com/forums/rss/] in [/nas/wp/www/cluster-2294/xxxxxx/wp-content/plugins/simple-press/sp-api/sp-api-wpdb.php:176] */, Resource id #28) called at [/nas/wp/www/cluster-2294/xxxxx/wp-includes/wp-db.php:1655]
#5 wpdb->_do_query(SELECT rufus_sfposts.post_id, post_content, post_date, rufus_sfposts.topic_id, rufus_sfposts.forum_id,
\t\t\t\t\t\t\t\t rufus_sfposts.user_id, guest_name, post_status, post_index, forum_name, forum_slug, forum_disabled, rufus_sfforums.group_id, group_name,
\t\t\t\t\t\t\t\t topic_name, topic_slug, rufus_sftopics.post_count, topic_opened, display_name FROM rufus_sfposts JOIN rufus_sfforums ON rufus_sfforums.forum_id = rufus_sfposts.forum_id JOIN rufus_sfgroups ON rufus_sfgroups.group_id = rufus_sfforums.group_id JOIN rufus_sftopics ON rufus_sftopics.topic_id = rufus_sfposts.topic_id LEFT JOIN rufus_sfmembers ON rufus_sfmembers.user_id = rufus_sfposts.user_id WHERE rufus_sfforums.forum_rss_private = 0 AND rufus_sfposts.forum_id IN (5849,5850,5851,5852,5853,5854,5855,5856,5857,5858,5859,5863,5864) ORDER BY rufus_sfposts.post_id DESC LIMIT 15 /* From [thehomesteadingboards.com/forums/rss/] in [/nas/wp/www/cluster-2294/xxxxx/wp-content/plugins/simple-press/sp-api/sp-api-wpdb.php:176] */) called at [/nas/wp/www/cluster-2294/xxxxx/wp-includes/wp-db.php:1559]
#6 wpdb->query(SELECT rufus_sfposts.post_id, post_content, post_date, rufus_sfposts.topic_id, rufus_sfposts.forum_id,
\t\t\t\t\t\t\t\t rufus_sfposts.user_id, guest_name, post_status, post_index, forum_name, forum_slug, forum_disabled, rufus_sfforums.group_id, group_name,
\t\t\t\t\t\t\t\t topic_name, topic_slug, rufus_sftopics.post_count, topic_opened, display_name FROM rufus_sfposts JOIN rufus_sfforums ON rufus_sfforums.forum_id = rufus_sfposts.forum_id JOIN rufus_sfgroups ON rufus_sfgroups.group_id = rufus_sfforums.group_id JOIN rufus_sftopics ON rufus_sftopics.topic_id = rufus_sfposts.topic_id LEFT JOIN rufus_sfmembers ON rufus_sfmembers.user_id = rufus_sfposts.user_id WHERE rufus_sfforums.forum_rss_private = 0 AND rufus_sfposts.forum_id IN (5849,5850,5851,5852,5853,5854,5855,5856,5857,5858,5859,5863,5864) ORDER BY rufus_sfposts.post_id DESC LIMIT 15) called at [/nas/wp/www/cluster-2294/xxxxx/wp-includes/wp-db.php:1950]
#7 wpdb->get_results(SELECT rufus_sfposts.post_id, post_content, post_date, rufus_sfposts.topic_id, rufus_sfposts.forum_id,
\t\t\t\t\t\t\t\t rufus_sfposts.user_id, guest_name, post_status, post_index, forum_name, forum_slug, forum_disabled, rufus_sfforums.group_id, group_name,
\t\t\t\t\t\t\t\t topic_name, topic_slug, rufus_sftopics.post_count, topic_opened, display_name FROM rufus_sfposts JOIN rufus_sfforums ON rufus_sfforums.forum_id = rufus_sfposts.forum_id JOIN rufus_sfgroups ON rufus_sfgroups.group_id = rufus_sfforums.group_id JOIN rufus_sftopics ON rufus_sftopics.topic_id = rufus_sfposts.topic_id LEFT JOIN rufus_sfmembers ON rufus_sfmembers.user_id = rufus_sfposts.user_id WHERE rufus_sfforums.forum_rss_private = 0 AND rufus_sfposts.forum_id IN (5849,5850,5851,5852,5853,5854,5855,5856,5857,5858,5859,5863,5864) ORDER BY rufus_sfposts.post_id DESC LIMIT 15, OBJECT) called at [/nas/wp/www/cluster-2294/xxxxx/wp-content/plugins/simple-press/sp-api/sp-api-wpdb.php:176]
#8 spdb_select(set, SELECT rufus_sfposts.post_id, post_content, post_date, rufus_sfposts.topic_id, rufus_sfposts.forum_id,
\t\t\t\t\t\t\t\t rufus_sfposts.user_id, guest_name, post_status, post_index, forum_name, forum_slug, forum_disabled, rufus_sfforums.group_id, group_name,
\t\t\t\t\t\t\t\t topic_name, topic_slug, rufus_sftopics.post_count, topic_opened, display_name FROM rufus_sfposts JOIN rufus_sfforums ON rufus_sfforums.forum_id = rufus_sfposts.forum_id JOIN rufus_sfgroups ON rufus_sfgroups.group_id = rufus_sfforums.group_id JOIN rufus_sftopics ON rufus_sftopics.topic_id = rufus_sfposts.topic_id LEFT JOIN rufus_sfmembers ON rufus_sfmembers.user_id = rufus_sfposts.user_id WHERE rufus_sfforums.forum_rss_private = 0 AND rufus_sfposts.forum_id IN (5849,5850,5851,5852,5853,5854,5855,5856,5857,5858,5859,5863,5864) ORDER BY rufus_sfposts.post_id DESC LIMIT 15, OBJECT) called at [/nas/wp/www/cluster-2294/xxxxx/wp-content/plugins/simple-press/sp-api/sp-api-wpdb.php:308]
#9 spdbComplex->select() called at [/nas/wp/www/cluster-2294/xxxxx/wp-content/plugins/simple-press/forum/content/classes/sp-list-post-class.php:154]
#10 spPostList->sp_postlistview_query(rufus_sfforums.forum_rss_private = 0, rufus_sfposts.post_id DESC, 15, post-content) called at [/nas/wp/www/cluster-2294/xxxxx/wp-content/plugins/simple-press/forum/content/classes/sp-list-post-class.php:80]
#11 spPostList->__construct(rufus_sfforums.forum_rss_private = 0, rufus_sfposts.post_id DESC, 15, post-content) called at [/nas/wp/www/cluster-2294/xxxxx/wp-content/plugins/simple-press/forum/feeds/sp-feeds.php:87]
#12 include(/nas/wp/www/cluster-2294/xxxxx/wp-content/plugins/simple-press/forum/feeds/sp-feeds.php) called at [/nas/wp/www/cluster-2294/xxxxx/wp-content/plugins/simple-press/sp-startup/site/sp-site-support-functions.php:258]
#13 sp_feed()
#14 call_user_func_array(sp_feed, Array ([0] => )) called at [/nas/wp/www/cluster-2294/xxxxx/wp-includes/plugin.php:505]
#15 do_action(template_redirect) called at [/nas/wp/www/cluster-2294/xxxxx/wp-includes/template-loader.php:12]
#16 require_once(/nas/wp/www/cluster-2294/xxxxx/wp-includes/template-loader.php) called at [/nas/wp/www/cluster-2294/xxxxx/wp-blog-header.php:16]
#17 require(/nas/wp/www/cluster-2294/xxxxx/wp-blog-header.php) called at [/nas/wp/www/cluster-2294/xxxxx/index.php:17]

[Wed Oct 29 10:44:06 2014] [error] [client xx.xxx.xx.xx] [WPE Monitoring] Slow mysql_query() call was running query:
SELECT rufus_sfposts.post_id, post_content, post_date, rufus_sfposts.topic_id, rufus_sfposts.forum_id,
\t\t\t\t\t\t\t\t rufus_sfposts.user_id, guest_name, post_status, post_index, forum_name, forum_slug, forum_disabled, rufus_sfforums.group_id, group_name,
\t\t\t\t\t\t\t\t topic_name, topic_slug, rufus_sftopics.post_count, topic_opened, display_name FROM rufus_sfposts JOIN rufus_sfforums ON rufus_sfforums.forum_id = rufus_sfposts.forum_id JOIN rufus_sfgroups ON rufus_sfgroups.group_id = rufus_sfforums.group_id JOIN rufus_sftopics ON rufus_sftopics.topic_id = rufus_sfposts.topic_id LEFT JOIN rufus_sfmembers ON rufus_sfmembers.user_id = rufus_sfposts.user_id WHERE rufus_sfforums.forum_rss_private = 0 AND rufus_sfposts.forum_id IN (5849,5850,5851,5852,5853,5854,5855,5856,5857,5858,5859,5863,5864) ORDER BY rufus_sfposts.post_id DESC LIMIT 15 /* From [thehomesteadingboards.com/forums/rss/] in [/nas/wp/www/cluster-2294/xxxxx/wp-content/plugins/simple-press/sp-api/sp-api-wpdb.php:176] */

Avatar
Yellow Swordfish
Glinton, England
SP Master
sp_UserOfflineSmall Offline
Oct 29, 2014 - 9:56 am

I see 2 errors mentioned. It is rather a shame that there is no attempt to diagnose why they took so long. I don not believe there is anything more complex about RSS queries than any other to be frank.

So - why were they slow? Well - first thing to check would be the database tables to ensure there are none that need a good optimisation. Bad data fragmentation can kill queries. But it could also simply be that there was a lot going on when the queries were made and the database was under fierce contention... I don't know if that is likely. But I would check the tables first.

andy-signature.png
YELLOW
SWORDFISH
Avatar
kvr28
Member
Free Members
sp_UserOfflineSmall Offline
Oct 29, 2014 - 10:09 am

 I run wp-optimize weekly and select all the tables through php myadmin monthly and select all the tables and optimize them, would it be because some of the tables are InnoDB? If I try to optimize those I get this

Table does not support optimize, doing recreate + ...

but then it shows okay right below it

I had contacted wpengine, they said it really wasn't a error, it's just to show what may be causing performance issues

Those two errors are what shows in the log anytime someone tries to access the forum feed

Avatar
Yellow Swordfish
Glinton, England
SP Master
sp_UserOfflineSmall Offline
Oct 29, 2014 - 3:16 pm

And it doesn't look problematic, Strange.

Are you seeing any corresponding errors or entries in the php error log to do with the Db query?

andy-signature.png
YELLOW
SWORDFISH
Avatar
kvr28
Member
Free Members
sp_UserOfflineSmall Offline
Oct 29, 2014 - 5:16 pm

not seeing php errors that I know of, just these query issues

Avatar
Mr Papa
Simi Valley, CA
SP Master
Free Members
sp_UserOfflineSmall Offline
Oct 29, 2014 - 9:33 pm

yeah, strange... are you using the rss feeds out of the box? some folks use filters to modify which can slow down, though wouldnt think that was the query itself...

is that the All RSS feed?  how many groups and forums do you have?

Avatar
kvr28
Member
Free Members
sp_UserOfflineSmall Offline
Oct 30, 2014 - 6:27 am

yes the all rass, just out of the box, 3 group, 14 forums total, had the rss feed set at 15 topics

Avatar
Yellow Swordfish
Glinton, England
SP Master
sp_UserOfflineSmall Offline
Oct 30, 2014 - 8:11 am

You can probably guess that both Steve and I are at a loss to understand why this should be slow!

Would you be able to run the query outside of WordPress - i,e., using phpMyAdmin for example - to see if it runs OK there - or messages out? Possible?

andy-signature.png
YELLOW
SWORDFISH
Avatar
kvr28
Member
Free Members
sp_UserOfflineSmall Offline
Oct 30, 2014 - 8:20 am

I can, what would be the exact query I should run?

Avatar
Yellow Swordfish
Glinton, England
SP Master
sp_UserOfflineSmall Offline
Oct 30, 2014 - 8:28 am

Sorry. I am assuming it is the one in the log you publshed above:

SELECT rufus_sfposts.post_id, post_content, post_date, rufus_sfposts.topic_id, rufus_sfposts.forum_id, rufus_sfposts.user_id, guest_name, post_status, post_index, forum_name, forum_slug, forum_disabled, rufus_sfforums.group_id, group_name, topic_name, topic_slug, rufus_sftopics.post_count, topic_opened, display_name FROM rufus_sfposts JOIN rufus_sfforums ON rufus_sfforums.forum_id = rufus_sfposts.forum_id JOIN rufus_sfgroups ON rufus_sfgroups.group_id = rufus_sfforums.group_id JOIN rufus_sftopics ON rufus_sftopics.topic_id = rufus_sfposts.topic_id LEFT JOIN rufus_sfmembers ON rufus_sfmembers.user_id = rufus_sfposts.user_id WHERE rufus_sfforums.forum_rss_private = 0 AND rufus_sfposts.forum_id IN (5849,5850,5851,5852,5853,5854,5855,5856,5857,5858,5859,5863,5864) ORDER BY rufus_sfposts.post_id DESC LIMIT 15
andy-signature.png
YELLOW
SWORDFISH
Forum Timezone: Europe/Stockholm
Most Users Ever Online: 1170
Currently Online:
Guest(s) 1
Currently Browsing this Page:
1 Guest(s)
Top Posters:
Mr Papa: 19448
Ike: 2086
Brandon: 864
kvr28: 804
jim: 649
FidoSysop: 577
Conrad_Farlow: 531
fiddlerman: 358
Stefano Prete: 325
Member Stats:
Guest Posters: 616
Members: 17344
Moderators: 0
Admins: 4
Forum Stats:
Groups: 7
Forums: 17
Topics: 10117
Posts: 79600