• Resolved AndyPlak

    (@socarrat)


    Hi,

    I’ve been trying to get to the bottom of an issue that could be down to a number of plugins, but after debugging, I think the problem lies with BNFW. We’ve got a site setup with Directories Pro with a notification due to go out when a listing is published. The listings get published when payment is completed. This has been working fine for some time when using the WooCommerce PayPal gateway. We’ve recently added Stripe giving users the choice, but when a user pays via the Stripe?gateway the listing published notification does not go out (even though the listing is marked as published).

    I’ve done a fair bit of debugging, and think this may be down to a race condition exacerbated by the asynchronous notifications queue. After payment I see?the notification is created via publish_post() and send_notification_async() is invoked with the correct notification.
    This is where the problems seem to start. set_transient( 'bnfw-async-notifications', $transient, 600 ); call is returning 0, suggesting that the value is already in the transient?. Debugging at this point with:

    error_log( $wpdb->last_error );
    error_log( $wpdb->last_query );

    I get no error and the query looks something like this:

    UPDATE wpqc_options SET option_value = ‘a:2:{i:0;a:3:{s:6:\\”ref_id\\”;i:105057;s:15:\\”notification_id\\”;i:14207;s:17:\\”notification_type\\”;s:21:\\”pending-sales_dir_ltg\\”;}i:1;a:3:{s:6:\\”ref_id\\”;i:105057;s:15:\\”notification_id\\”;i:21088;s:17:\\”notification_type\\”;s:17:\\”new-sales_dir_ltg\\”;}}’ WHERE option_name = ‘_transient_bnfw-async-notifications’

    Fast forward to on_shutdown() and the get_transient( 'bnfw-async-notifications' ); call returns false / empty and thus no notification is sent. I’m really stumped as to why BNFW is failing to write the transient for the message queue under these circumstances.

    Have you seen issues similar to this before? Could multiple requests (checkout complete and Stripe webhook) be causing problems with this? Any help or pointers very gratefully received.

    Thanks,
    Andy

Viewing 9 replies - 1 through 9 (of 9 total)
  • Plugin Author bnfw

    (@voltronik)

    Hi @socarrat,
    Thanks for your message.

    I have also come across this issue and I’ve been unable to pin it down either.
    Everything until that point seems to work fine.
    Are you publishing using the Block Editor/Gutenberg plugin?

    Thread Starter AndyPlak

    (@socarrat)

    Hi @voltronik,

    Thanks for your reply. No, these posts are not published via Gutenberg or any block editor. They are created via the Directories Pro create listing form, and marked as published when the payment completes.

    What makes me suspect multiple concurrent requests may be the problem is that the transient seems to exist as DNFW / WordPress core tries to update the transient, rather than insert it, so I assume it has detected one. By the time it goes to actually update it, it no longer exists and the update fails.

    You say you’ve seen it before, can you remember the circumstances? Was this as a payment was made via a WC payment gateway?

    Plugin Author bnfw

    (@voltronik)

    Hi @socarrat,
    Thanks, that’s helpful and gives me something to investigate beyond what IO had already found.

    I found the issue when publishing using the Block Editor which uses the WP REST API so assume the issue lies there somewhere. Adding posts via the Classic Editor plugin doesn’t seem to have the same issue.

    Am investigating…

    Thread Starter AndyPlak

    (@socarrat)

    Hi @voltronik,

    I’ve found the cause of this on our sites. It’s the Hummingbird plugin, and in particular it’s page caching. The ?wc-ajax=checkout POST submission triggers off a whole load of PURGE, PURGEALL, GET and POST requests, all going off while the checkout submission is doing its work. What appears to be happening is that the two WooCommerce order notifications get added to the bnfw-async-notifications transient, but one of the hummingbird requests then triggers the onShutdown() processing sending those notification and deleting the transient, while the original checkout request (presumably delayed slightly due to Stripe API interaction) then tries to update the transient which fails, as it is no longer set.

    Disabling Hummingbird page caching fixes the issue seen here. I know just need to understand why hummingbird is triggering off so many requests (most of which result in 301s or 404s), but that isn’t you’re problem.

    Thanks for taking the time to look into this.
    Andy

    Plugin Author bnfw

    (@voltronik)

    Hi @socarrat,
    Thanks. That is interesting! I was getting it using Local by Flywheel for developing sites with no caching on. It could be that it’s a weak point in BNFW in general but could also be a compounded problem from multiple plugins in sequence.

    Thread Starter AndyPlak

    (@socarrat)

    Yeah, it’s a pretty unique setup, but I guess that’s a weakness of the asynchronous send queue (which makes sense on many other levels). Concurrent requests manipulating the queue simultaneously will cause issues. Perhaps some kind of queue locking to a particular request might do it?

    Plugin Author bnfw

    (@voltronik)

    Hi @socarrat,
    Thanks, that’s an idea.

    I’ll do some more investigation into this and see if I can find a better way.

    Thread Starter AndyPlak

    (@socarrat)

    Hi @voltronik

    Unfortunately, this isn’t resolved. I’ve taken Hummingbird out of the equation, but enabling the Stripe Webhooks causes concurrent requests to come in and break the async message queue. This time the Stripe Webhook is clearing the queue on shutdown before the Woo Commerce wp-ajax=checkout request completes. See the access log for an example of the requests coming in and note the time stamps vs the order they were recorded in the logs:

    127.0.0.1 - - [13/Jul/2021:21:24:27 +0100] "POST /quirky-campers/?wc-api=wc_stripe HTTP/1.1" 200 259 "-" "Stripe/1.0 (+https://stripe.com/docs/webhooks)"
    127.0.0.1 - - [13/Jul/2021:21:24:29 +0100] "POST /quirky-campers/?wc-api=wc_stripe HTTP/1.1" 200 259 "-" "Stripe/1.0 (+https://stripe.com/docs/webhooks)"
    127.0.0.1 - - [13/Jul/2021:21:24:25 +0100] "POST /quirky-campers/?wc-ajax=checkout HTTP/1.1" 200 1298 "https://bb0e0edbaadc.ngrok.io/quirky-campers/shop-checkout/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/91.0.4472.106 Safari/537.36"
    127.0.0.1 - - [13/Jul/2021:21:24:30 +0100] "GET /quirky-campers/shop-checkout/order-received/105276/?key=wc_order_84VabAxHpeJsT HTTP/1.1" 200 121232 "https://bb0e0edbaadc.ngrok.io/quirky-campers/shop-checkout/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/91.0.4472.106 Safari/537.36"
    127.0.0.1 - - [13/Jul/2021:21:24:32 +0100] "POST /quirky-campers/?wc-ajax=get_refreshed_fragments HTTP/1.1" 200 1121 "https://bb0e0edbaadc.ngrok.io/quirky-campers/shop-checkout/order-received/105276/?key=wc_order_84VabAxHpeJsT" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/91.0.4472.106 Safari/537.36"
    127.0.0.1 - - [13/Jul/2021:21:24:32 +0100] "POST /quirky-campers/wp-cron.php?doing_wp_cron=1626207872.5538508892059326171875 HTTP/1.1" 200 166 "https://bb0e0edbaadc.ngrok.io/quirky-campers/wp-cron.php?doing_wp_cron=1626207872.5538508892059326171875" "WordPress/5.7.2; https://bb0e0edbaadc.ngrok.io/quirky-campers"
    127.0.0.1 - - [13/Jul/2021:21:24:32 +0100] "POST /quirky-campers/?wc-ajax=wc_stripe_get_cart_details HTTP/1.1" 200 1098 "https://bb0e0edbaadc.ngrok.io/quirky-campers/shop-checkout/order-received/105276/?key=wc_order_84VabAxNpeJsT" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/91.0.4472.106 Safari/537.36te how"

    Could you re-open the ticket for me (I can’t see how to do that myself)?
    I do think some kind of locking on the async message queue is called for.

    Thanks,
    Andy

    Plugin Author bnfw

    (@voltronik)

    Hi @socarrat,
    I haven’t had a chance to investigate this yet but I will as soon as I can.

Viewing 9 replies - 1 through 9 (of 9 total)
  • The topic ‘Dir Pro Notification Not sent when using Stripe Gateway’ is closed to new replies.