AndyPlak

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

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?

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

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?

@oliveconcepts, thank you!

I believe this is down to the the custom date placeholders only being designed for use with the Event Date, and not the Event time. The docs suggest it is for custom dates only and not event times. The following combination should get the result you want: #@g:#@i #@a

I’ll discuss with the lead developer to confirm if this is actually a bug or if the documentation should be more specific.