woocommerce-plugin icon indicating copy to clipboard operation
woocommerce-plugin copied to clipboard

Published 20 hours ago • verified publisher icon btcpayserver

Some invoices return a Unexpected return code: 500

Open astupidmoose opened this issue 6 years ago • 74 comments

For context: I host BTCPay and Woocommerce on different machines, on different networks.

Sometimes, BTCPay generates an invoice for the customer, however it gets hit with:

Error while sending IPN (1001 invoice_created): Unexpected return code: 500

BTCPay continues to generate this error every 10 minutes until the invoice expires. BTCPay is never able to assign metadata to the woocommerce invoice. Once expired, the status is set to expired and generates another error 500:

Error while sending IPN (1004 invoice_expired): Unexpected return code: 500

This cycles 3 times every 10 minutes for 1 hour.

I know that error 500 indicates a server error, but it seems completely random at the moment and only happens to some invoices.

astupidmoose avatar Feb 15 '19 02:02 astupidmoose

I just checked my woocommerce "fatal-errors.log" file and found the following error on each attempt:

2019-02-14T15:33:49+00:00 CRITICAL Uncaught Exception: Received IPN for order 72724 with BTCPay invoice id72724 while expected BTCPay invoice is in /var/www/html/wp-content/plugins/btcpay-for-woocommerce/class-wc-gateway-btcpay.php:1001 Stack trace: #0 /var/www/html/wp-includes/class-wp-hook.php(286): WC_Gateway_BtcPay->ipn_callback('') #1 /var/www/html/wp-includes/class-wp-hook.php(310): WP_Hook->apply_filters('', Array) #2 /var/www/html/wp-includes/plugin.php(453): WP_Hook->do_action(Array) #3 /var/www/html/wp-content/plugins/woocommerce/includes/class-wc-api.php(97): do_action('woocommerce_api...') #4 /var/www/html/wp-includes/class-wp-hook.php(286): WC_API->handle_api_requests(Object(WP)) #5 /var/www/html/wp-includes/class-wp-hook.php(310): WP_Hook->apply_filters(NULL, Array) #6 /var/www/html/wp-includes/plugin.php(515): WP_Hook->do_action(Array) #7 /var/www/html/wp-includes/class-wp.php(375): do_action_ref_array('parse_request', Array) #8 /var/www/html/wp-includes/class-wp.php(715): WP->parse_request('') #9 /var/www/html/wp-includes/func in /var/www/html/wp-content/plugins/btcpay-for-woocommerce/class-wc-gateway-btcpay.php on line 1001

astupidmoose avatar Feb 15 '19 03:02 astupidmoose

When did it start appearing? which plugin version?

NicolasDorier avatar Feb 17 '19 03:02 NicolasDorier

I'm currently on Version 3.0.3.

This has been going for a few weeks. I think it might be the same issue as before, which hangfire was getting held up but not that hangfire is no longer existing it simply shows this in the logs.

I will upgrade to 3.0.6 to see if this helps, but I suspect its been like this for a while.

astupidmoose avatar Feb 17 '19 21:02 astupidmoose

@Kukks any memory about this?

NicolasDorier avatar Feb 18 '19 02:02 NicolasDorier

No clue what could be wrong here

Kukks avatar Feb 18 '19 06:02 Kukks

I can confirm that I'm seeing this error sometimes on expired invoices as well. It's been going on for ages, I just have no idea how to troubleshoot it.

2/16/2019 8:14:20 PM | Creation of invoice starting
2/16/2019 8:14:21 PM | BTC_USD: The rating rule is coinaverage(BTC_USD)
2/16/2019 8:14:21 PM | BTC_USD: The evaluated rating rule is 3612.17840304482
2/16/2019 8:14:25 PM | Invoice 3PaGaD72UcSPkBQsPKw984 new event: invoice_created (1001)
2/16/2019 8:14:27 PM | Error while sending IPN (1001 invoice_created): Unexpected return code: 500
2/16/2019 8:24:28 PM | Error while sending IPN (1001 invoice_created): Unexpected return code: 500
2/16/2019 8:34:29 PM | Error while sending IPN (1001 invoice_created): Unexpected return code: 500
2/16/2019 8:44:22 PM | Invoice status is expired
2/16/2019 8:44:22 PM | Invoice 3PaGaD72UcSPkBQsPKw984 new event: invoice_expired (1004)
2/16/2019 8:44:24 PM | Error while sending IPN (1004 invoice_expired): Unexpected return code: 500
2/16/2019 8:44:25 PM | Error while sending IPN (1004 invoice_expired): Unexpected return code: 500
2/16/2019 8:44:30 PM | Error while sending IPN (1001 invoice_created): Unexpected return code: 500
2/16/2019 8:54:25 PM | Error while sending IPN (1004 invoice_expired): Unexpected return code: 500
2/16/2019 8:54:26 PM | Error while sending IPN (1004 invoice_expired): Unexpected return code: 500
2/16/2019 8:54:31 PM | Error while sending IPN (1001 invoice_created): Unexpected return code: 500
2/16/2019 9:04:26 PM | Error while sending IPN (1004 invoice_expired): Unexpected return code: 500
2/16/2019 9:04:27 PM | Error while sending IPN (1004 invoice_expired): Unexpected return code: 500
2/16/2019 9:04:33 PM | Error while sending IPN (1001 invoice_created): Unexpected return code: 500
2/16/2019 9:14:28 PM | Error while sending IPN (1004 invoice_expired): Unexpected return code: 500
2/16/2019 9:14:28 PM | Error while sending IPN (1004 invoice_expired): Unexpected return code: 500
2/16/2019 9:24:29 PM | Error while sending IPN (1004 invoice_expired): Unexpected return code: 500
2/16/2019 9:24:30 PM | Error while sending IPN (1004 invoice_expired): Unexpected return code: 500
2/16/2019 9:34:30 PM | Error while sending IPN (1004 invoice_expired): Unexpected return code: 500
2/16/2019 9:34:31 PM | Error while sending IPN (1004 invoice_expired): Unexpected return code: 500
2/17/2019 4:14:22 AM | Invoice 3PaGaD72UcSPkBQsPKw984 is not monitored anymore.

I'm unable to connect the events happening with any error WooCommerce/WordPress or server side logs.

pavlenex avatar Feb 18 '19 08:02 pavlenex

screenshot 2019-02-18 at 08 28 56

I'm running the latest version, 3.0.6, I`m not seeing any problems, with any expired invoices, just so you know!!

Eskyee avatar Feb 18 '19 08:02 Eskyee

Can any of you experiencing the issue see if there is a fatal errors log file in woocommerce and if there is anything corresponding to the ipn error time in btcpay

On Mon, Feb 18, 2019, 09:32 Esky33 <[email protected] wrote:

[image: screenshot 2019-02-18 at 08 28 56] https://user-images.githubusercontent.com/30862925/52937553-530c5800-3357-11e9-9639-6c721ca8c394.png

I'm running the latest version, 3.0.6, I`m not seeing any problems, with any expired invoices, just so you know!!

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/btcpayserver/woocommerce-plugin/issues/23#issuecomment-464635300, or mute the thread https://github.com/notifications/unsubscribe-auth/ABu-_iKAFZk3X4eL4S55f38OC7pN_Fwtks5vOmUxgaJpZM4a81y7 .

Kukks avatar Feb 18 '19 09:02 Kukks

@Kukks I think I remember this issue. I think I fixed it in the old version, you may have thrown the fix away when migrated.

Basically it is a race condition if somebody click twice on the checkout button too fast.

NicolasDorier avatar Feb 18 '19 09:02 NicolasDorier

@astupidmoose can you check that for your order, BTCPay created 2 different BTCPay invoices?

NicolasDorier avatar Feb 18 '19 09:02 NicolasDorier

@astupidmoose can you also confirm that the customer does not have any issue and you did not had to manually fix anything?

NicolasDorier avatar Feb 18 '19 09:02 NicolasDorier

@astupidmoose can you check that for your order, BTCPay created 2 different BTCPay invoices?

No, for this example, 72724 is only generated once in BTCPay.

@astupidmoose can you also confirm that the customer does not have any issue and you did not had to manually fix anything?

Customers never pay these invoices when this happens. I am thinking they are presented an Error that BTCPAY is not working and abandon the cart. Unfortunately, this is happening to customers who do not inform us of an issue and simply leave.

astupidmoose avatar Feb 18 '19 19:02 astupidmoose

Customers never pay these invoices when this happens. I am thinking they are presented an Error that BTCPAY is not working and abandon the cart. Unfortunately, this is happening to customers who do not inform us of an issue and simply leave.

OK this could be wrong....

I found an invoice where the error happened on creation, however was paid by the customer and then fixed itself.

On creation, the fatal-errors log shows:

2019-02-15T19:15:00+00:00 CRITICAL Uncaught Exception: Received IPN for order 72954 with BTCPay invoice id72954 while expected BTCPay invoice is in /var/www/html/wp-content/plugins/btcpay-for-woocommerce/class-wc-gateway-btcpay.php:1001 Stack trace: #0 /var/www/html/wp-includes/class-wp-hook.php(286): WC_Gateway_BtcPay->ipn_callback('') #1 /var/www/html/wp-includes/class-wp-hook.php(310): WP_Hook->apply_filters('', Array) #2 /var/www/html/wp-includes/plugin.php(453): WP_Hook->do_action(Array) #3 /var/www/html/wp-content/plugins/woocommerce/includes/class-wc-api.php(97): do_action('woocommerce_api...') #4 /var/www/html/wp-includes/class-wp-hook.php(286): WC_API->handle_api_requests(Object(WP)) #5 /var/www/html/wp-includes/class-wp-hook.php(310): WP_Hook->apply_filters(NULL, Array) #6 /var/www/html/wp-includes/plugin.php(515): WP_Hook->do_action(Array) #7 /var/www/html/wp-includes/class-wp.php(375): do_action_ref_array('parse_request', Array) #8 /var/www/html/wp-includes/class-wp.php(715): WP->parse_request('') #9 /var/www/html/wp-includes/func in /var/www/html/wp-content/plugins/btcpay-for-woocommerce/class-wc-gateway-btcpay.php on line 1001

BTCPay logs show as:

`

2/15/2019 11:14:58 AM Invoice 6ayYoquW8SNo21PfKLTny3 new event: invoice_created (1001)
2/15/2019 11:15:00 AM Error while sending IPN (1001 invoice_created): Unexpected return code: 500
2/15/2019 11:15:54 AM Invoice 6ayYoquW8SNo21PfKLTny3 new event: invoice_receivedPayment (1002)
2/15/2019 11:15:55 AM Invoice status is paid
2/15/2019 11:15:55 AM Invoice 6ayYoquW8SNo21PfKLTny3 new event: invoice_paidInFull (1003)
2/15/2019 11:15:55 AM IPN (1002 invoice_receivedPayment) sent for invoice 6ayYoquW8SNo21PfKLTny3
2/15/2019 11:15:57 AM IPN (1003 invoice_paidInFull) sent for invoice 6ayYoquW8SNo21PfKLTny3
2/15/2019 11:15:58 AM IPN (1003 invoice_paidInFull) sent for invoice 6ayYoquW8SNo21PfKLTny3
2/15/2019 11:17:37 AM Invoice status is confirmed
2/15/2019 11:17:37 AM Invoice 6ayYoquW8SNo21PfKLTny3 new event: invoice_confirmed (1005)
2/15/2019 11:17:39 AM IPN (1005 invoice_confirmed) sent for invoice 6ayYoquW8SNo21PfKLTny3
2/15/2019 11:17:39 AM IPN (1005 invoice_confirmed) sent for invoice 6ayYoquW8SNo21PfKLTny3
2/15/2019 11:25:00 AM IPN (1001 invoice_created) sent for invoice 6ayYoquW8SNo21PfKLTny3
2/15/2019 11:49:01 AM Invoice status is complete
2/15/2019 11:49:02 AM Invoice 6ayYoquW8SNo21PfKLTny3 new event: invoice_completed (1006)
2/15/2019 11:49:02 AM Invoice 6ayYoquW8SNo21PfKLTny3 is not monitored anymore.
2/15/2019 11:49:02 AM IPN (1006 invoice_completed) sent for invoice 6ayYoquW8SNo21PfKLTny3
2/15/2019 11:49:03 AM IPN (1006 invoice_completed) sent for invoice 6ayYoquW8SNo21PfKLTny3

`

astupidmoose avatar Feb 18 '19 19:02 astupidmoose

Still having the same issue. I'm running 3.0.6 now.

For some reason, woocommerce and btcpay stop talking to each other. BTCPay just starts throwing up Error 500 on every invoice creation request.

2019-03-03 02:57:52.958 -08:00 [INF] Invoice MFqPtE28CUvwbiSDFbSkWu new event: invoice_created (1001)
2019-03-03 02:57:53.655 -08:00 [INF] Error while sending IPN (1001 invoice_created): Unexpected return code: 500
2019-03-03 02:58:20.054 -08:00 [INF] Invoice TdPXSp7dgLu8bjGHmmTyZS new event: invoice_created (1001)
2019-03-03 02:58:20.850 -08:00 [INF] Error while sending IPN (1001 invoice_created): Unexpected return code: 500
2019-03-03 02:59:57.432 -08:00 [INF] Invoice 5w9sH7Gr7sKt5G1bVg8QgZ new event: invoice_created (1001)
2019-03-03 02:59:58.388 -08:00 [INF] Error while sending IPN (1001 invoice_created): Unexpected return code: 500

The only way to fix this is completely restarting btcpay which allows it to start generating invoices again. That leads me to beleive its a BTCPay issue more then a plugin one.

astupidmoose avatar Mar 03 '19 20:03 astupidmoose

I know the issue. invoice_created IPN is sent before php saved the invoice in the DB. This should not impact anything though. The rest of notification should works fine right?

NicolasDorier avatar Mar 04 '19 10:03 NicolasDorier

@Kukks Have the same with 3.0.6 and woocommerce 3.6.1 Basically I could see a call to /wc-api/WC_Gateway_BtcPay/ from btcpayserver with all json data, but reply from a server is 500. In plugin log: [Error] The BTCPay payment plugin was called to process an IPN message but could not obtain the order ID from the invoice. If I try to log . $order_id or . $responseData those are empty Btcpayserver constantly tries to send IPN, but all its receiving is 500.

cryptofuture avatar Apr 22 '19 17:04 cryptofuture

@cryptofuture are you running on an SSD?

The solution for me ended up switching to an SSD setup as I was running on sata before. The issue was that the invoice was taking too long to create for woocommerce with sata

astupidmoose avatar Apr 22 '19 17:04 astupidmoose

@cryptofuture are you running on an SSD?

The solution for me ended up switching to an SSD setup as I was running on sata before. The issue was that the invoice was taking too long to create for woocommerce with sata

On SSD RAID10

cryptofuture avatar Apr 22 '19 17:04 cryptofuture

@cryptofuture it does that for every invoice or only once in a while?

NicolasDorier avatar Apr 23 '19 03:04 NicolasDorier

@cryptofuture it does that for every invoice or only once in a while?

For an every invoice. Error in the log says:

[Error] The BTCPay payment plugin was called to process an IPN message but could not obtain the order ID from the invoice.

But from what i think there is an issue with $invoice = $client->getInvoice($json['id']); but it passes the check: [Info] The IPN check appears to be valid.

As i said if I try to log . $responseData its empty

But what I could say 100% is that btcpayserver sending data on /wc-api/WC_Gateway_BtcPay/ correctly

Screenshot from 2019-04-23 04-35-54

cryptofuture avatar Apr 23 '19 04:04 cryptofuture

@cryptofuture can you see, in the order metadata if you have BTCPay_id or BTCPay_rate or something like this?

NicolasDorier avatar Apr 23 '19 05:04 NicolasDorier

do you have a orderId field in your btcpay invoice?

NicolasDorier avatar Apr 23 '19 05:04 NicolasDorier

When you go inside btcpay's invoice details do you see an order id?

NicolasDorier avatar Apr 23 '19 05:04 NicolasDorier

When you go inside btcpay's invoice details do you see an order id?

Yes, it also has hyperlink to the woocommerce order-received (redirectUrl) on it in the interface But, in the data that is send to /wc-api/WC_Gateway_BtcPay/ I didn't found orderId. It should be there, right?

cryptofuture avatar Apr 23 '19 06:04 cryptofuture

@cryptofuture see

image

NicolasDorier avatar Apr 23 '19 06:04 NicolasDorier

Yes, I have it

cryptofuture avatar Apr 23 '19 06:04 cryptofuture

Damn, I don't know how this can happen...

look https://github.com/btcpayserver/woocommerce-plugin/blob/master/src/class-wc-gateway-btcpay.php#L964

This is where we get the orderId after querying the API. If you have the orderId this should not be empty or null.... Do you have a way to poke around this code to find what happen?

NicolasDorier avatar Apr 23 '19 06:04 NicolasDorier

For example, you can try to print

$client->getResponse()->getBody() if you can

NicolasDorier avatar Apr 23 '19 06:04 NicolasDorier

$client->getResponse()->getBody()

Trying now. That is full data that is btcpayserver sending to the /wc-api/WC_Gateway_BtcPay/ btw

{
  "id": "JiNQgy89Cyf8fmuGsPKbuA",
  "url": "https://mybtcpayserver/invoice?id=JiNQgy89Cyf8fmuGsPKbuA",
  "posData": null,
  "status": "confirmed",
  "btcPrice": "0.00155163",
  "price": 8.0,
  "currency": "USD",
  "invoiceTime": 1555329871000,
  "expirationTime": 1555330771000,
  "currentTime": 1555330028152,
  "btcPaid": "0.00155163",
  "btcDue": "0.00000000",
  "rate": 5155.88959990332,
  "exceptionStatus": false,
  "buyerFields": {
    "buyerEmail": "[email protected]"
  },
  "transactionCurrency": null,
  "paymentSubtotals": {
    "btc": 155163
  },
  "paymentTotals": {
    "btc": 155163
  },
  "amountPaid": "0.00000000",
  "exchangeRates": {
    "btc": {
      "usd": 0.0
    }
  }
}

cryptofuture avatar Apr 23 '19 06:04 cryptofuture

No orderId...

can you go to https://your.btcpayserver.example.org/invoices/JiNQgy89Cyf8fmuGsPKbuA and tell me your Order Id?

NicolasDorier avatar Apr 23 '19 06:04 NicolasDorier