CPU usage at 100% 24-7 after last update

Wordpress Plugin
1

We run a very large content website and after the recent update was pushed out or server’s CPU usage spiked to 100% and has not come down. Way too many SQL calls going on prior to the plugin update wp_posts select was called 17 times. Now wp_posts select is called 75 times on a single page.

You can see exactly when the update was pushed in this screenshot

2018-03-21_16-33-39
2018-03-21_16-33-39.png1374×544 56.7 KB

This is wreaking havoc on a bunch of other areas of the site. Facebook API can not pull Opengraph data consistently because the connection times out, our WP to Twitter plugin is timing out, the Media Library takes almost 2 minutes to load.

The problem seems to be related to Patreon_Protect and looking for protected images on every page load.

Whatever was pushed out though has made this plugin completely unusable for a large website and we have had to disable it much to the frustration of people paying for an ad free experience.

2

Very curious…

Do these posts have many images embedded?

3

1 image per post at most and a Featured image. Nothing out of the norm I would say.

4

I have some more detailed screen grabs from New Relic and a few other tools I can provide if it would help at all as well.

5

Hmmm…

We actually reduced cpu usage with this version since we are now caching the patronage details that are queried from API - we query now once per page load.

In Patreon_Protect class we have new code that checks for protected images, only for logged in users. (If you are using a cache already).

This should do an extra query for attachment info, but not to the order you mention.

However what is eye-catching is that before the update you mention that there were already 17 queries being made to wp_posts table. Even before the update plugin didnt have code that could do that many queries. We actually use the $post global in most of the operations, so the post info should already exist in a single post context and therefore shouldnt be queried.

Chances are that there is a plugin (or more plugins) which apply or re-apply the_content filter, and since our protection mechanism hooks into that it gets called as many times as the_content filter is called.

Have you run Plugin Performance Profiler to detect precise cpu usage of plugins?

If you can provide me WP admin access, we can look into this very curious situation together. In that case, please create a new admin user with a sufficiently complex password and mail it to me at ozgur@c.patreon.com . This account should be deleted after we are done with debugging.

1 Like
6

Much appreciated! I just sent over some login credentials and some more info.

Thanks @codebard!

1 Like
7

My pleasure. I’ll be looking into this soon. I’ll update you from direct message with the findings.

8

I debugged queries and performance using Query Monitor. Im posting the results with permission of dreadcentral with site-specific info redacted.

Before.jpg is the performance of your #1 page with our plugin disabled. There are a total of 235 queries.

Before
Before.jpg1690×821 152 KB

After.jpg is performance of the #1 page with our plugin on. There are 236 queries. Only one more.

After
After.jpg1651×815 148 KB

Checking query details, Slow.jpg shows that there are 4 slow sql queries which in total add a ~1.5 sec to query time, which would also cause high cpu spikes.

Slow-Queries
Slow-Queries.jpg1740×905 206 KB

These are not related to our plugin. It seems your theme is pulling related posts from the same category and showing them under the post being viewed. This means that ~4 more times everything related to a post will run in every one of your single post pages - because you show 4 posts in one go.

Long story short this is a situation with your related posts plugin or related posts functionality that is built into your theme. If you show 4 posts in one go while showing a single post, anything related to posts will be called 4 times - naturally.

Speaking of the theme/plugins:

Warning.jpg shows that there is an issue in code relevant to a query which gets next/previous posts (probably to show them in your single post page), that causes a warning to be given by WordPress core. The code causing this seems to be in your theme - Zox News, inside its single post display template single.php. Line 383.

Warning
Warning.jpg1689×843 314 KB

I advise against changing the theme or doing major changes to the theme since this could affect your SEO ranking for your popular pages. However the code that causes the warning must be looked at first.

I wasnt able to notice any notable change in total time the queries take. With our plugin disabled, or enabled, it seems to take in between ~1.1 seconds and ~2.5 seconds randomly.

Summary; this seems to be related to your theme displaying 4 posts in one go while showing 1 single post. Any plugin that uses the_content filter will kick in 4 times with this setup.

We can see if we can do some optimizations on our end, after you have that PHP warning looked at.

For the time being, you can just drop the below code to your theme’s functions.php or any plugin to disable image protection:

define(‘PATREON_BYPASS_IMAGE_FILTERING’,true);

9

The first paragraph of the above post stays bold and heading-size for some reason…