Slows down nav-menus.php save function #39

Closed
Coopeh opened this Issue Feb 5, 2013 · 18 comments

Comments

Projects
None yet
2 participants

Coopeh commented Feb 5, 2013

When saving a navigation menu with the latest version (0.4) or previous version of wp-varnish (0.3) enabled it can triple or quadruple the time it takes to actually save the menu. I've taken a screenshot in NewRelic of the process trace: http://c.ed.gs/MebR.

Also since updating to 0.4 we seem to be experiencing random bouts of mass PURGE requests taking over PHP, in effect killing or slowing down our server massively.

Cheers,
Ed

Collaborator

cd34 commented Feb 5, 2013

Can you send a trace of the varnishlog output? Also, are you using VCL that supports purge? If not, the plugin gets a 404 generated from WordPress and tries again.

Coopeh commented Feb 5, 2013

I'll test it with the purge functions now in the VCL, previously we were just using acl purge and it seemed to work. I'll let you know once I've tested it this evening.

Cheers!

Coopeh commented Feb 5, 2013

Here is the extremely long (28000 line) varnishlog tail for running a save on nav-menus.php with 95 menu items. http://c.ed.gs/Mh9i

I have added the VCL_Hit and Miss items to our VCL which seems to have rectified the mass of PURGE requests that were being sent to Varnish. However, the above is still slow when saving the menu due to 99% of the time being used to purge items.

Coopeh commented Feb 5, 2013

It appears to be that the edit_post action is called on each menu item when run, temporarily commenting it out removes the delay. I assume due to the way WP is written that we can't bind to any other action for edited posts?

Collaborator

cd34 commented Feb 5, 2013

I'll have to look through the hooks, I believe that is one of the few hooks exposed at that point. Thanks for tip there. I'll look at it a bit more.

Coopeh commented Feb 5, 2013

I've had a quick scout about but can't find anything that doesn't fire when updating nav menus. I have also found that edit_post and transition_post_status seem to work if used in conjunction or on their own, so both aren't needed unless I'm wrong.

Collaborator

cd34 commented Feb 6, 2013

I can think of a few quick fixes, but, I'm not convinced any are right. I am able to duplicate it here and I see what it is doing. I might patch it with a quick fix if I can find one that is a decent compromise.

Coopeh commented Feb 6, 2013

Yeah, I've been playing about. Best I can come up with is:

if ( strpos( $_SERVER['REQUEST_URI'], "nav-menus.php" ) == false ) {
  add_action('edit_post', array($this, 'WPVarnishPurgePost'), 99);
  add_action('edit_post', array($this, 'WPVarnishPurgeCommonObjects'), 99);
  add_action('transition_post_status', array($this, 'WPVarnishPurgePostStatus'), 99, 3);
  add_action('transition_post_status', array($this, 'WPVarnishPurgeCommonObjectsStatus'), 99, 3);
}

// When navigation menu is saved
add_action('wp_update_nav_menu',array($this, 'WPVarnishPurgeAll'), 99);

I'm not a PHP dev though :)

Coopeh commented Feb 6, 2013

Although it appears that the wp_update_nav_menu doesn't actually fire for me, or possibly the WPVarnishPurgeAll doesn't work. It doesn't clear the cache using the button in the settings either. Is that just me?

Collaborator

cd34 commented Feb 6, 2013

There are a few actions that don't appear to be doing what they should.

And one thing that struck me as I was pushing the repo was that it is a bit aggressive in its purges. I'll try to get a new version pushed out in the next day or so after I go through things a little more closely. Most of what I did was fix existing issues that I knew about and as many of the open tickets as possible. This particular issue seems related to a change in 3.5.x or possibly 3.4.x in the way the WordPress hooks are called.

Coopeh commented Feb 6, 2013

Ok great. Extending my last comment, I'm currently using the PURGE method due to the admin port version making the site timeout. Not sure what I'm doing wrong or what I need to set up for it to work. Varnish 3.0.2+ doesn't accept wildcards with the PURGE header, but I'm going to try this tomorrow http://mesmor.com/2012/02/29/varnish-purge-all-cache/

Collaborator

cd34 commented Feb 6, 2013

PURGE /(.*) is a wildcard purge.

that is how categories are cleared. It sends

PURGE /categories/(.*)

however, I don't like the fact that is hardcoded since a blog that exists in a subdirectory wouldn't get purged. So, that is something on my list to fix.

Coopeh commented Feb 6, 2013

Yeah that's what I thought, but they don't actually get purged. According to Varnish docs they're not supported - https://www.varnish-cache.org/docs/3.0/faq/general.html

Collaborator

cd34 commented Feb 6, 2013

I believe that wiki page MIGHT be a little out of date. I'll have to check the source and do some testing.

Coopeh commented Feb 6, 2013

I've tested it on my 3.0.3 install using the following in vcl_recv

if (req.request == "BAN") {
if (!client.ip ~ purge) {
error 405 "Not allowed.";
}
ban("req.url ~ "+req.url+" && req.http.host == "+req.http.host);
error 200 "Banned.";
}

Also changing the PURGE call in wp-varnish.php from:

$out = "PURGE $wpv_url HTTP/1.1\r\n";

to:

$out = "BAN $wpv_url HTTP/1.1\r\n";

All seems gravy now, purges/bans the wildcard.

Ed

Collaborator

cd34 commented Feb 7, 2013

I've made the changes to use BAN rather than PURGE which is a Varnish 3 versus Varnish 2 issue, and made some slight changes to the VCL flow.

I'm not seeing the nav-menus.php lag at this point. Did you also remove that code or do you still have it running?

I've not gone through the actions yet - most of what I did was fix the outstanding bugs and issues. I haven't gone through the code very thoroughly yet.

cd34 added a commit to cd34/wp-varnish that referenced this issue Feb 7, 2013

Coopeh commented Feb 8, 2013

Yeah, I forked your repo, changed to BAN and removed all the admin port stuff as it never worked for me anyway. Added a couple more actions too, probably already worked but I was playing about :)

Collaborator

cd34 commented Feb 8, 2013

Ok, I'm going to go ahead and push this. I think it fixes the issue as I was unable to reproduce it after the fix. Moving to the old version did exhibit the problem again.

I haven't looked through all of the actions yet, but, will go through that in the next week.

@cd34 cd34 closed this Feb 8, 2013

cd34 added a commit that referenced this issue Feb 8, 2013

Merge pull request #40 from cd34/master
Issue #39 patch ban versus purge
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment