New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[2.5] Using over 100Mb more memory for some code path #9922

Closed
DavidAnderson684 opened this Issue Dec 30, 2015 · 20 comments

Comments

Projects
None yet
3 participants
@DavidAnderson684
Copy link
Contributor

DavidAnderson684 commented Dec 30, 2015

I update one of my sites with a CLI tool (http://wordshell.net) that (when asked) queries the wordpress.org API to find the latest version,and installs it.

Somehow, on December 11th, when I ran this tool assuming it'd update to WC 2.4.12, it instead updated to WC 2.5.0-beta2. Was there a moment when wordpress.org was returning that? Anyway, however it happened, I never noticed until now. The store's got about 10 WooCommerce extension plugins. So, it looks like WC 2.5 isn't going to break as many things as previous major releases! Anyway, that's just background to the problem...

What I have noticed since then is several PHP fatal errors in the PHP error logs due to running out of memory. I've been progressively increasing the memory limit from 512Mb to 600Mb, and it's still occurring. According to the logs, no other plugins have been updated since Dec 11th, and neither has WordPress, or any other system component (such as PHP). The stack trace is always the same (shown below). I've noticed some things about changes to do with transients in 2.5. Could this be related?

In this case (below), it's wanting another 11Mb. As I say, I've increased the memory limit by 88Mb so far, so, the memory profile on this code path appears to have increased by at least 100Mb since 2.4 (it could be more - there are no PHP fatals in the logs from before the (inadvertant) WC 2.5 upgrade; I don't know how much there was to spare before then).

        PHP Fatal error:  Allowed memory size of 629145600 bytes exhausted (tried to allocate 11091458 bytes) in wp-
        includes/functions.php on line 384
        PHP Stack trace:
        PHP   1. {main}() index.php:0
        PHP   2. require() index.php:21
        PHP   3. require_once() wp-blog-header.php:16
        PHP   4. include() wp-includes/template-loader.php:75
        PHP   5. wc_get_template_part() wp-content/plugins/woocommerce/templates/single-product.php:36
        PHP   6. load_template() wp-content/plugins/woocommerce/includes/wc-core-functions.php:167
        PHP   7. require() wp-includes/template.php:557
        PHP   8. do_action() wp-content/plugins/woocommerce/templates/content-single-product.php:77
        PHP   9. call_user_func_array:{wp-includes/plugin.php:503}() wp-includes/plugin.php:503
        PHP  10. woocommerce_output_related_products() wp-includes/plugin.php:503
        PHP  11. woocommerce_related_products() wp-content/themes/Divi/functions.php:8035
        PHP  12. wc_get_template() wp-content/plugins/woocommerce/includes/wc-template-functions.php:1204
        PHP  13. include() wp-content/plugins/woocommerce/includes/wc-core-functions.php:197
        PHP  14. wc_get_template_part() wp-content/plugins/woocommerce/templates/single-product/related.php:56
        PHP  15. load_template() wp-content/plugins/woocommerce/includes/wc-core-functions.php:167
        PHP  16. require() wp-includes/template.php:557
        PHP  17. do_action() wp-content/plugins/woocommerce/templates/content-product.php:82
        PHP  18. call_user_func_array:{wp-includes/plugin.php:503}() wp-includes/plugin.php:503
        PHP  19. woocommerce_template_loop_price() wp-includes/plugin.php:503
        PHP  20. wc_get_template() wp-content/plugins/woocommerce/includes/wc-template-functions.php:651
        PHP  21. include() wp-content/plugins/woocommerce/includes/wc-core-functions.php:197
        PHP  22. WC_Product_Variable->get_price_html() wp-content/plugins/woocommerce/templates/loop/price.php:25
        PHP  23. WC_Product_Variable->get_variation_prices() wp-content/plugins/woocommerce/includes/class-wc-produc
        t-variable.php:334
        PHP  24. set_transient() wp-content/plugins/woocommerce/includes/class-wc-product-variable.php:317
        PHP  25. update_option() wp-includes/option.php:709
        PHP  26. maybe_serialize() wp-includes/option.php:296
        PHP  27. serialize() wp-includes/functions.php:384

@DavidAnderson684

This comment has been minimized.

Copy link
Contributor

DavidAnderson684 commented Dec 30, 2015

BTW, the shop in question only has about 25 products, and only 4 variable products - each of which has only 2 or 3 variants. So, how the data from WC_Product_Variable->get_variation_prices() to be serialized ends up being at least 11Mb seems like a good question...

@DavidAnderson684

This comment has been minimized.

Copy link
Contributor

DavidAnderson684 commented Dec 30, 2015

Okay... so, looking at the transients saved from the code in the area of that fatal error...

SELECT option_name, option_value FROM (prefix)options WHERE option_name LIKE '%wc_var_prices%';

Result - yoikes, an array with 44,132 members! For a product with 3 variations...

_transient_wc_var_prices_230 a:44132:{s:32:"c6653800be4c0f1bc34ab688fac7afaf";a:3:{s:5:"price";a:3 ...

Each of those entries appears to be identical. The key is some hash; and the value is itself an array, with keys price, regular_price, sale_price; and the value for each is an array with a key for each of the 3 variations. The whole thing is 11Mb.

@DavidAnderson684

This comment has been minimized.

Copy link
Contributor

DavidAnderson684 commented Dec 30, 2015

Now on beta 3, and it still seems to be a problem. I cleared out the transient, and since then, have been watching the array grow again. Currently grown to 274 entries...

@mikejolley

This comment has been minimized.

Copy link
Member

mikejolley commented Dec 31, 2015

2.5 beta is trunk on .org for translation purposes. Maybe its that?

The key is some hash; and the value is itself an array, with keys price, regular_price, sale_price; and the value for each is an array with a key for each of the 3 variations. The whole thing is 11Mb.

The key (hash) keeps things unique if plugins change prices, set here https://github.com/woothemes/woocommerce/blob/master/includes/class-wc-product-variable.php#L260

Then there are 3 sets of values; price, sale, regular. There should be 1 per variation: https://github.com/woothemes/woocommerce/blob/master/includes/class-wc-product-variable.php#L301-L303

Sounds like you are getting multiple hashes?

Logic for that is here: https://github.com/woothemes/woocommerce/blob/master/includes/class-wc-product-variable.php#L241-L260

How many tax rates are there in your store? And what about plugins which use any of these filters? https://github.com/woothemes/woocommerce/blob/master/includes/class-wc-product-variable.php#L252

mikejolley added a commit that referenced this issue Dec 31, 2015

@mikejolley

This comment has been minimized.

Copy link
Member

mikejolley commented Dec 31, 2015

^ that should increase performance slightly.

You'll get a unique key per tax location i.e. US taxes vs UK taxes, and a separate key for when prices are not displayed with tax.

e.g. on my local site I had 1 tax rate and visited with a US location and a non-US location. I ended up with 3 price hashes per variable product. 2 taxed (display tax and not displaying tax) and 1 for the location without taxes.

@DavidAnderson684

This comment has been minimized.

Copy link
Contributor

DavidAnderson684 commented Dec 31, 2015

2.5 beta is trunk on .org for translation purposes. Maybe its that?

The log records the command line, and this specified the latest stable - the same command line when re-run is currently correctly identifying 2.4.12. The tool's been in use for a few years on ~100 sites, and it queries the wordpress.org API. So, I guess there was some temporary glitch at that end.

Concerning the issue itself, it's this bit...

$filter_names = array( 'woocommerce_variation_prices_price', 'woocommerce_variation_prices_regular_price', 'woocommerce_variation_prices_sale_price' );
        foreach ( $filter_names as $filter_name ) {
            if ( ! empty( $wp_filter[ $filter_name ] ) ) {
                $price_hash[ $filter_name ] = $wp_filter[ $filter_name ];
            }
        }
        $price_hash = md5( json_encode( apply_filters( 'woocommerce_get_variation_prices_hash', $price_hash, $this, $display ) ) );

I do have an extension that uses those filters. The value of $wp_filter[$filter_name] varies on every run. There's a different prefix every time:

<?php
require('wp-load.php');
global $wp_filter;
var_dump($wp_filter['woocommerce_variation_prices_regular_price']);

Result the first time:

array(1) {
  [5] =>
  array(1) {
    '00000000539e91bd000000007ef2896bwoocommerce_variation_prices_regular_price' =>
    array(2) {
      'function' =>
      array(2) {
        ...
      }
      'accepted_args' =>
      int(3)
    }
  }
}

... and the second time:

array(1) {
  [5] =>
  array(1) {
    '000000002475158e00000000770c3e04woocommerce_variation_prices_regular_price' =>
    array(2) {
      'function' =>
      array(2) {
        ...
      }
      'accepted_args' =>
      int(3)
    }
  }
}

So, it looks like this hash is different on every run, and the transient array just fills with keys that will never be used again. The one in my DB is currently up to 1,763 (since last night's reset).

@DavidAnderson684

This comment has been minimized.

Copy link
Contributor

DavidAnderson684 commented Dec 31, 2015

and, this line...


        $price_hash = md5( json_encode( apply_filters( 'woocommerce_get_variation_prices_hash', $price_hash, $this, $display ) ) );

... is json-encoding arbitrary PHP classes, in the case where the registered filter is a method within a class, which seems wrong.

@mikejolley

This comment has been minimized.

Copy link
Member

mikejolley commented Dec 31, 2015

@DavidAnderson684 I bet the plugin is using a create_function rather than proper callback.. can you share it?

@mikejolley

This comment has been minimized.

Copy link
Member

mikejolley commented Dec 31, 2015

May have to exclude closures/anonymous functions here to prevent this getting out of hand - those plugins will need to use the filters to make the hash unique.

@DavidAnderson684

This comment has been minimized.

Copy link
Contributor

DavidAnderson684 commented Dec 31, 2015

It's @daigo75 's currency switcher. The filters appear to be added in the ordinary way; e.g. for the above one:

# cd wp-content/plugins/woocommerce-aelia-currencyswitcher
# grep -R woocommerce_variation_prices_regular_price -n
lib/classes/multiprice/wc-aelia-currencyprices-manager.php:598:                 add_filter('woocommerce_variation_prices_regular_price', array($this, 'woocommerce_variation_prices_regular_price'), 5, 3);
lib/classes/multiprice/wc-aelia-currencyprices-manager.php:1261:        public function woocommerce_variation_prices_regular_price($price, $variation, $parent_product) {
@DavidAnderson684

This comment has been minimized.

Copy link
Contributor

DavidAnderson684 commented Dec 31, 2015

From what I can see, the varies-every-time-prefix comes from _wp_filter_build_unique_id() in wp-includes/plugin.php, which in turn gets it from https://secure.php.net/spl_object_hash .

@mikejolley

This comment has been minimized.

Copy link
Member

mikejolley commented Dec 31, 2015

Got it; happens for anonymous functions and class callbacks it seems.

@daigo75

This comment has been minimized.

Copy link
Contributor

daigo75 commented Dec 31, 2015

I can also add, in relation to my plugin, that it can also invalidate the cached prices (thus requiring a new transient) when the exchange rates are change. The operation is performed by calling WC_Cache_Helper::get_transient_version('product', true);. That is necessary, as new exchange rates mean new prices. When this happens, the old transient should be discarded, and replaced by a new one. If a transient history is preserved, then the pricing data will grow relatively quickly.

The "explosion" will be even quicker if multiple internationalisation plugins are used, as the number of prices stored will grow geometrically (i.e. a set of prices for each combination of currency, country and tax settings).

The FX rates are updated at most once an hour (unless an admin goes crazy and clicks "update update update", that is), therefore the above logic would take a while to trigger an issue, but I thought worth mentioning it.

@daigo75

This comment has been minimized.

Copy link
Contributor

daigo75 commented Dec 31, 2015

In relation to anonymous functions, I don't use any in my plugins. It's possible, however, that some custom code on customers' sites uses them (e.g. code in the functions.php file). Anonymous functions are not extremely common, but they are handy and it cannot be excluded that someone is using them.

@mikejolley

This comment has been minimized.

Copy link
Member

mikejolley commented Dec 31, 2015

@daigo75 this transient doesn't have version in the name any longer; its always wc_var_prices_ID

@daigo75

This comment has been minimized.

Copy link
Contributor

daigo75 commented Dec 31, 2015

@mikejolley does it mean I have to use another call to reset it?

@mikejolley

This comment has been minimized.

Copy link
Member

mikejolley commented Dec 31, 2015

@daigo75 the hash filter can still be used to void past cached results, but you can also delete_transient if you know the products ID. Let me fix the above first and Ill look into it further.

@daigo75

This comment has been minimized.

Copy link
Contributor

daigo75 commented Dec 31, 2015

My call is to invalidate all product transients in one shot (new FX rates means new prices for all products). The hash filter doesn't help, as I would not have an element that tells me that the rates changed (i.e. the hash remains the same every time for each product, but the transient should not be there once it was invalidated).

I simply need to reliably "throw away" all the prices transients in one go (like one would do when deleting them in WC tools), and everything will work fine. 👍

mikejolley added a commit that referenced this issue Dec 31, 2015

@mikejolley

This comment has been minimized.

Copy link
Member

mikejolley commented Dec 31, 2015

@DavidAnderson684 please make the above changes and let me know if that resolves your issue.

@DavidAnderson684

This comment has been minimized.

Copy link
Contributor

DavidAnderson684 commented Dec 31, 2015

That seems to have fixed it; at least, the array stored in the transient now only has a dozen entries (after a few hours).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment