search

woocommerce / woocommerce

A customizable, open-source ecommerce platform built on WordPress. Build any commerce solution you can imagine.
https://woocommerce.com
9.31k stars 10.75k forks source link

Order meta data cache doesn't account for multiple objects. #50944

Open peterwilsoncc opened 2 weeks ago

peterwilsoncc commented 2 weeks ago

Prerequisites

Describe the bug

The order meta data cache does not get cleared when multiple order objects are in memory (perhaps created by different functions). This can lead to a situation in which the order meta is updated in one object but stale data is returned in subsequent calls to get meta data.

Expected behavior

Caching should account for multiple in memory objects.

Actual behavior

Stale caches cross objects.

Steps to reproduce

It's easiest to reproduce this via WP-CLI. 

$ wp shell
wp> $order_id = 432
=> int(432)
wp> $order_copy_1 = wc_get_order( $order_id );
=> class Automattic\WooCommerce\Admin\Overrides\Order [SNIP]
wp> $order_copy_2 = wc_get_order( $order_id );
=> class Automattic\WooCommerce\Admin\Overrides\Order [SNIP]
wp> $order_copy_1->get_meta( 'stale_test_meta' );
=> string(0) ""
wp> $order_copy_2->update_meta_data( 'stale_test_meta', 'test meta' );
=> NULL
wp> $order_copy_2->save();
=> int(423)
wp> $order_copy_2->get_meta( 'stale_test_meta' );
=> string(9) "test meta"
wp> $order_copy_1->get_meta( 'stale_test_meta' );
=> string(0) ""

WordPress Environment

System Status Report ``` ### WordPress Environment ### WordPress address (URL): [Redacted] Site address (URL): [Redacted] WC Version: 9.1.4 Legacy REST API Package Version: The Legacy REST API plugin is not installed on this site. Action Scheduler Version: ✔ 3.7.4 Log Directory Writable: ✔ WP Version: 6.6.1 WP Multisite: ✔ WP Memory Limit: 256 MB WP Debug Mode: ✔ WP Cron: – Language: en_US External object cache: – ### Server Environment ### Server Info: nginx/1.18.0 PHP Version: 7.4.33 PHP Post Max Size: 1 GB PHP Time Limit: 900 PHP Max Input Vars: 1000 cURL Version: 7.81.0 OpenSSL/3.0.2 SUHOSIN Installed: – MySQL Version: 8.0.36-0ubuntu0.22.04.1 Max Upload Size: 0 B Default Timezone is UTC: ✔ fsockopen/cURL: ✔ SoapClient: ✔ DOMDocument: ✔ GZip: ✔ Multibyte String: ✔ Remote Post: ✔ Remote Get: ✔ ### Database ### [REDACTED] ### Post Type Counts ### attachment: 35 page: 6 post: 2 product: 21 product_variation: 46 revision: 4 shop_order_placehold: 1 wp_template: 2 ### Security ### Secure connection (HTTPS): ✔ Hide errors from visitors: ✔ ### Active Plugins (8) ### Query Monitor: by John Blackbourn – 3.16.3 WooCommerce Dummy Payments Gateway: by SomewhereWarm – 1.0.9 WooCommerce Pre-Orders: by WooCommerce – 2.1.3 WooCommerce Subscriptions Core: by Automattic – 7.4.0 WooCommerce Subscriptions: by WooCommerce – 6.5.0 (update to version 6.6.0 is available) WooCommerce: by Automattic – 9.1.4 (update to version 9.2.2 is available) Query Monitor: by John Blackbourn – 3.16.3 User Switching: by John Blackbourn – 1.8.0 ### Inactive Plugins (2) ### Airplane Mode: by Andrew Norcross – 0.2.5 WooCommerce Square: by WooCommerce – 4.7.2 (update to version 4.7.3 is available) ### Dropin Plugins () ### db.php: Query Monitor Database Class (Drop-in) ### Must Use Plugins (14) ### Add an 11 cent surcharge to all orders.: by – allow-admin-access.php: by – Cavalcade-loader.php: by – Demo of WooCommerce Subscriptions Update Date Bug: by – more-products-per-page.php: by – no-express-pay.php: by – no-ssl.php: by – pre-orders-fast-schedule.php: by – Preload options used by Woo that do not use autoload.: by – revisions-link.php: by – rewrite-apple-pay.php: by – Unique order IDs: by – wpcli-dev-commands.php: by – _qm-mappings.php: by – ### Settings ### API Enabled: – Force SSL: – Currency: AUD ($) Currency Position: left Thousand Separator: , Decimal Separator: . Number of Decimals: 2 Taxonomies: Product Types: external (external) grouped (grouped) simple (simple) subscription (subscription) variable (variable) variable subscription (variable-subscription) Taxonomies: Product Visibility: exclude-from-catalog (exclude-from-catalog) exclude-from-search (exclude-from-search) featured (featured) outofstock (outofstock) rated-1 (rated-1) rated-2 (rated-2) rated-3 (rated-3) rated-4 (rated-4) rated-5 (rated-5) Connected to WooCommerce.com: – Enforce Approved Product Download Directories: ✔ HPOS feature enabled: ✔ Order datastore: Automattic\WooCommerce\Internal\DataStores\Orders\OrdersTableDataStore HPOS data sync enabled: – ### Logging ### Enabled: ✔ Handler: Automattic\WooCommerce\Internal\Admin\Logging\LogHandlerFileV2 Retention period: 30 days Level threshold: – Log directory size: 160 KB ### WC Pages ### Shop base: #4 - /shop/ Cart: #326 - /cart/ - Contains the woocommerce/cart block Checkout: #327 - /checkout/ - Contains the woocommerce/checkout block My account: #7 - /my-account/ Terms and conditions: ❌ Page not set ### Theme ### Name: Storefront Version: 4.6.0 Author URL: https://woocommerce.com/ Child Theme: ❌ – If you are modifying WooCommerce on a parent theme that you did not build personally we recommend using a child theme. See: How to create a child theme WooCommerce Support: ✔ ### Templates ### Overrides: – ### Subscriptions ### WCS_DEBUG: ✔ No Subscriptions Mode: ✔ Live Subscriptions Live URL: https://xu-a8c-woo.local Subscriptions-core Library Version: 7.4.0 Subscription Statuses: – WooCommerce Account Connected: ❌ No Report Cache Enabled: ✔ Yes Cache Update Failures: ✔ 0 failure ### Store Setup ### Country / State: Australia — Victoria ### Subscriptions by Payment Gateway ### ### Payment Gateway Support ### Check payments: products Cash on delivery: products Dummy Payment: pre-orders products subscriptions subscription_cancellation subscription_suspension subscription_reactivation subscription_amount_changes subscription_date_changes multiple_subscriptions ### Admin ### Enabled Features: activity-panels analytics product-block-editor coupons core-profiler customize-store customer-effort-score-tracks import-products-task experimental-fashion-sample-products shipping-smart-defaults shipping-setting-tour homescreen marketing mobile-app-banner navigation onboarding onboarding-tasks product-custom-fields remote-inbox-notifications remote-free-extensions payment-gateway-suggestions shipping-label-banner subscriptions store-alerts transient-notices woo-mobile-welcome wc-pay-promotion wc-pay-welcome-page launch-your-store Disabled Features: experimental-blocks minified-js pattern-toolkit-full-composability product-pre-publish-modal printful settings async-product-editor-category-field product-editor-template-system Daily Cron: ✔ Next scheduled: 2024-08-27 00:51:50 +10:00 Options: ✔ Notes: 79 Onboarding: completed ### Action Scheduler ### Complete: 20 Oldest: 2024-08-26 11:21:45 +1000 Newest: 2024-08-26 11:54:59 +1000 Failed: 2 Oldest: 2023-11-30 10:22:05 +1100 Newest: 2023-11-30 11:15:07 +1100 Pending: 1 Oldest: 2024-08-27 10:47:28 +1000 Newest: 2024-08-27 10:47:28 +1000 ### Status report information ### Generated at: 2024-08-26 12:04:35 +10:00 ```

Isolating the problem

barryhughes commented 2 weeks ago

Hi @peterwilsoncc,

Caching should account for multiple in memory objects.

Why do you think this, is there a particular scenario you are dealing with that would help us understand why this is desirable in your case? I think what you are suggesting could in fact be confusing and counter-intuitive for many, but we'd love to hear more about what you are actually trying to do.

peterwilsoncc commented 2 weeks ago

@barryhughes I left the ->save() out of my WPCLI steps, I've added that in.

I hit it while working on Pre-orders#544.

Some of the hooks in use passed the order ID and others passed the order object. When updating the meta data in a hook using the order ID, the order would return the old data and I needed to work around it.

As a simplified example using the woocommerce_order_status_changed hook (which passes both the ID and the object), if an extension updates the meta data for the order prior to a second extension running on the same hook I'd expect the data to be reflected regardless of how I access the order.

Using the code below when checking out with the build in Check payments method, extension_runs_second() doesn't update the meta data even though it's been saved in the database

add_action( 'woocommerce_order_status_changed', 'extension_runs_first', 10, 3 );
add_action( 'woocommerce_order_status_changed', 'extension_runs_second', 20, 4 );

function extension_runs_first( $order_id, $from, $to ) {
    // Only run when the Check payment transitions to On hold.
    if ( $to !== 'on-hold' ) {
        return;
    }

    $order = wc_get_order( $order_id );
    $order->add_meta_data( '_first', 'has run' );

    $order->update_meta_data( '_ticket50944', 'ticket 50944' );
    $order->save();
}

function extension_runs_second( $order_id, $from, $to, $order ) {
    // Only run when the Check payment transitions to On hold.
    if ( $to !== 'on-hold' ) {
        return;
    }

    $order->add_meta_data( '_second', 'has run' );

    $meta = $order->get_meta( '_ticket50944' );
    /*
     * At this point the meta data is saved in the database but the
     * order object does not have access to the data.
     *
     * Rather than reflect the database, $meta will be empty and the
     * second update will not be made.
     */
    if ( 'ticket 50944' === $meta ) {
        $order->update_meta_data( '_ticket50944', 'ticket 50944 - updated' );
    }
    $order->save();
}

https://github.com/user-attachments/assets/d25d2514-bf49-46ed-aa78-5fcea18ec90f

barryhughes commented 2 weeks ago

OK. So in the existing model, each separate instance of an order is its own self-contained snapshot. Updates in one don't automatically surface in another. I still don't really see a strong case for changing this, and it would need to be a very strong case, because of the potential for hard-to-predict backwards-compatibility breaks.

In your snippet, you are obtaining a fresh instance of the order object in one callback, and are using the instance supplied by the hook in the other. Given how you want it to work, is there a reason you can't change your code so that either:

Is there a reason you are using a mix of strategies?

peterwilsoncc commented 2 weeks ago

The example was just to use a convenient hook that passes both.

It becomes more of a problem when different hooks use different strategies for passing data within the same flow. For example in WC_Checkout::create_order():

So it's not really a case of choosing to use different patterns as that's how the data is supplied by WooCommerce.

Updates in one don't automatically surface in another. I still don't really see a strong case for changing this, and it would need to be a very strong case, because of the potential for hard-to-predict backwards-compatibility breaks.

I understand why this would be the case prior to calling ::save() or ::save_meta_data() but once the data has been stored in the database, I think the general expectation from developers is that the data would be updated across objects.

barryhughes commented 2 weeks ago

Thanks ... so, in case useful for others getting up to speed on this, the problem I think you are describing can be seen with a snippet like this (perhaps the easiest way to trigger this is to place an order via the classic checkout, then inspect the logs):

// Fires first. We will be supplied with an order object.
add_action( 'woocommerce_checkout_create_order', function ( $order ) {
    $order->update_meta_data( 'foo', 'bar' );
    $order->save();
} );

// Fires second. We will be supplied with the order ID.
add_action( 'woocommerce_checkout_update_order_meta', function ( $order_id ) {
    $order = wc_get_order( $order_id );
    wc_get_logger()->debug( $order->get_meta( 'foo' ) );

    $order->update_meta_data( 'foo', 'baz' );
    $order->save();
} );

// Fires last. We will be supplied with the same order object as in the first callback.
add_action( 'woocommerce_checkout_order_created', function ( $order ) {
    wc_get_logger()->debug( $order->get_meta( 'foo' ) );
} );

Especially if you ignore the last of my comments—that explains we're receiving the same instance we accessed in the first callback—we might reasonably expect the resulting log entries to look like this:

<timestamp> Debug: bar
<timestamp> Debug: baz

Instead, we see:

<timestamp> Debug: bar
<timestamp> Debug: bar

I agree that's not ideal, and is confusing. Yet ... I still don't think we should make the change you are suggesting: we'd be trading one source of confusion for another, and it could result in a lot of breakages across the ecosystem.

Perhaps it would be safer for us to ensure that whenever we supply a CRUD object to callbacks, and there has also been an opportunity for the underlying record to be mutated by yet other callbacks, we should 'refresh' our copy of the object first of all. That is, instead of:

do_action( 'woocommerce_checkout_create_order', $order, $data );
do_action( 'woocommerce_checkout_update_order_meta', $order_id, $data );
do_action( 'woocommerce_checkout_order_created', $order );

We should do:

do_action( 'woocommerce_checkout_create_order', $order, $data );
do_action( 'woocommerce_checkout_update_order_meta', $order_id, $data );
do_action( 'woocommerce_checkout_order_created', wc_get_order( $order_id ) );

Of course, this does nothing to address situations where other callbacks acting earlier on the same object, via the same hook, make other modifications of their own.

Still, I recognize the problem you are sharing—but we need to pick the solution with care. Polling the team for more thoughts on this, and of course definitely open to more conversation.