nexcess / magento-turpentine

A Varnish extension for Magento.
GNU General Public License v2.0
519 stars 253 forks source link

Error clearing cache #149

Closed studio2f closed 11 years ago

studio2f commented 11 years ago

We're getting the following error when we manually clear the cache with version 0.5.3 on our 1.7.0.2 store in Admim > System > Cache Management

Fatal error: Call to a member function getCollection() on a non-object in /OURPATH/public_html/app/code/community/Nexcessnet/Turpentine/Helper/Cron.php on line 168

It's also not invaliding the cache for a product page when the product is edited or stock is changed. Is this normal? We switched from the Phoenix module and are used to the individual product pages having their page cache invalided when edited and saved.

aheadley commented 11 years ago

We're getting the following error when we manually clear the cache with version 0.5.3 on our 1.7.0.2 store in Admim > System > Cache Management

Do you have any extensions installed related to Magento's CMS? I'm not able to reproduce that error in my dev environment on a vanilla 1.7.0.2 install.

It's also not invaliding the cache for a product page when the product is edited or stock is changed. Is this normal?

No, it should be doing that automatically. Can you give me an example of a URL that isn't getting invalidated?

studio2f commented 11 years ago

1) We have two CMS extensions: Aheadwork's Blog and SweetTooth's BetterStoreCMS. The error also appeared when trying to cancel an existing order. Turning off the Site Crawler fixed both problems.

2) Any product that we edit on the backend is not updated on the front-end without a manual cache clear. An example would be: http://www.joannehudson.com/emma-bridgewater-pottery-usa/eb-limited-edition-items/black-toast-black-on-cream-1-2-pint-mug.html

Let me know if there is anything else we can provide you.

aheadley commented 11 years ago

1) Ok, those are probably the cause of the error, and I would recommend disabling the built-in crawler for large sites anyway, it's very simple and inefficient.

2) Can you tell me the value of the URL Key field for that product from the Magento backend?

studio2f commented 11 years ago

The URL Key is "black-toast-black-on-cream-1-2-pint-mug"

Not sure if that would affect the cache clearing, but as an fyi, we are also using Mageworx SEO Ultimate that is handling Canonical URLs for products

aheadley commented 11 years ago

Turpentine bans product URLs by their URL key so that should be working. Are you seeing any errors in your webserver/PHP logs?

The only two ways I can think this would happen would be if one of your extensions changed what Mage_Catalog_Model_Product::getUrlKey() returned, or if Turpentine wasn't able to communicate with Varnish. Do you get any errors when you hit the Apply Varnish Config button on the System > Cache Management page?

studio2f commented 11 years ago

Thanks again for all your continuing help.

No PHP errors in the apache log. No errors when we Apply Varnish Config. It's also not just the product pages, the Categories aren't getting refreshed as well when a product changes. We have to dump the cache for categories as well.

aheadley commented 11 years ago

Very strange. Can you enable Magento's logging (if it's not already) and see if anything shows up in var/log/system.log after saving a product and/or category?

studio2f commented 11 years ago

nothing in system.log or exception.log

aheadley commented 11 years ago

It's also not just the product pages, the Categories aren't getting refreshed as well when a product changes.

Categories are also banned by their URL key so if it is an extension incompatiblility that's not real suprising. Can you try temporarily disabling the Mageworx SEO Ultimate extension to see if that fixes it?

studio2f commented 11 years ago

We disabled Mageworx -- which was a bit of a bear -- and it's still not invalidating the cache when a product is saved. Also if it helps, we're using the Magento Connect installed version and not the GIT code here.

aheadley commented 11 years ago

Ok, next thing to check would be to see if/what Turpentine is banning when you save a product. Can you run varnishlog -i CLI | tee varnish-cli.log then save a product and put the varnish-cli.log file on gist.github.com or pastebin (or email it to me)?

studio2f commented 11 years ago

Here's a product save:

https://dl.dropboxusercontent.com/u/8230194/varnish-cli.log

aheadley commented 11 years ago

Ok, that's not good but we're getting somewhere. It looks like Turpentine isn't trying to clear the product page cache (vs trying with the wrong regex or something) so either it's a bug in Turpentine or an extension you have installed is causing the catalog_{category,product}_save_commit_after events to not be triggered. Both are going to relatively difficult to debug so just to be sure, can you try doing the logging again and let the log run for a 10-15 seconds after you save the product (the Varnish log is buffered so it needs a bit of time to show up)?

studio2f commented 11 years ago

I let it run for about a minute:

https://dl.dropboxusercontent.com/u/8230194/varnish-cli-2.log

aheadley commented 11 years ago

Ok, I see that Turpentine is trying to ban a product page now:

    0 CLI          - Rd ban.url (?:veneerware-9in-square-bulk-100-pack-of-bamboo-plates) 

Is that URL Key (veneerware-9in-square-bulk-100-pack-of-bamboo-plates) for the product you saved?

studio2f commented 11 years ago

veneerware-9in-square-bulk-100-pack-of-bamboo-plates is the product I saved. I notice there seems to be a lot of "sessionClose c timeout" does that mean anything?

aheadley commented 11 years ago

I notice there seems to be a lot of "sessionClose c timeout" does that mean anything?

No, those are just the client connections to Varnish closing and are normal.

veneerware-9in-square-bulk-100-pack-of-bamboo-plates is the product I saved.

Hmmm, the page should be flushed then. I do see you're using Cloudflare on your site, which could maybe be caching the page? Can you check with the direct domain to your site (I think it's usually something like direct.example.com) by loading a product page with the direct domain (to get it cached by Varnish), then save that product and see if the direct domain page is flushed correctly?

studio2f commented 11 years ago

Cloudflare is off and we still have the problem

studio2f commented 11 years ago

Alex, don't give up on me ;)

aheadley commented 11 years ago

This has got me pretty stumped, everything you've sent so far indicates that everything is working as expected, but clearly something is wrong if you're not getting the new pages.

Do you have any other cache related extensions installed? Which caches do you have enabled under System > Cache Management?

studio2f commented 11 years ago

No other caching extensions. Here's the builtin caches we have enabled:

Configuration Layouts Blocks HTML output Translations Collections Data EAV types and attributes Web Services Configuration Varnish Pages Varnish ESI Blocks

aheadley commented 11 years ago

Ok, before going any further we need to know if the old pages are actually from a Varnish cache hit or not. Can you try applying this patch:

diff --git a/app/code/community/Nexcessnet/Turpentine/misc/version-3.vcl b/app/code/community/Nexcessnet/Turpentine/misc/version-3.vcl
index 981664d..5ec76ea 100644
--- a/app/code/community/Nexcessnet/Turpentine/misc/version-3.vcl
+++ b/app/code/community/Nexcessnet/Turpentine/misc/version-3.vcl
@@ -369,4 +369,5 @@ sub vcl_deliver {
         # session validation or that session can be hijacked
         unset resp.http.X-Varnish-Set-Cookie;
     }
+    set resp.X-Varnish-Hits = obj.hits;
 }

Then to test (with the dev tools enabled in your browser):

studio2f commented 11 years ago

Closed is fine. Sorry but we had to go back to the Phoenix Page cache extension. Not only where products and categories not getting purged, we experienced all types of errors during checkout where error messages from earlier in the user's session would be displayed during checkout-- almost as if the error's cache block hole wasn't punched on the cached pages, and when they hit a no-cached page the errors would finally show up.