Transaction Status Stuck In Running Status

[sprankhub]

This is a follow-up of #370.

It works quite well that transaction statuses are processed again if they have the error status. However, I sometimes have issues, where the transaction status is stuck in the status running. In this case, the transaction status will not be processed again, but the order is not in the right status either. Could this be handled as well? So if a transaction status is in the status running for more than X minutes, try to process it again?

Here is a log of such a transaction status:

payone_cron.log.5.gz:2020-04-15T15:57:22+00:00 INFO (6): ID: 123456 - Execute - Execute TransactionStatus action: paid - store-id: 1
payone_cron.log.5.gz:2020-04-15T15:57:22+00:00 INFO (6): ID: 123456 - Execute - Set status to running
payone_cron.log.5.gz:2020-04-15T15:57:22+00:00 INFO (6): ID: 123456 - Process - Got order id: 987654 store-id: 1
payone_cron.log.5.gz:2020-04-15T15:57:22+00:00 INFO (6): ID: 123456 - Process - Config loaded with config.store-id=1, order.store-id: 1
payone_cron.log.5.gz:2020-04-15T15:57:22+00:00 INFO (6): ID: 123456 - Process - Update TransactionStatus
payone_cron.log.5.gz:2020-04-15T15:57:22+00:00 INFO (6): ID: 123456 - Process - Update order status
payone_cron.log.5.gz:2020-04-15T15:57:22+00:00 INFO (6): ID: 123456 - Process - Add order comment
payone_cron.log.5.gz:2020-04-15T15:57:22+00:00 INFO (6): ID: 123456 - Process - Store clearing parameters
payone_cron.log.5.gz:2020-04-15T15:57:22+00:00 INFO (6): ID: 123456 - Process - Save before events
payone_cron.log.5.gz:2020-04-15T15:57:22+00:00 INFO (6): ID: 123456 - Process - Trigger event payone_core_transactionstatus_all
payone_cron.log.5.gz:2020-04-15T15:57:22+00:00 INFO (6): ID: 123456 - Process - Trigger event payone_core_transactionstatus_paid

Compared to a successful status processing, three log entries are missing at the end:

payone_cron.log:2020-04-20T06:17:39+00:00 INFO (6): ID: 123456 - Process - Finished
payone_cron.log:2020-04-20T06:17:39+00:00 INFO (6): ID: 123456 - Execute - Finished service execution, set status to complete
payone_cron.log:2020-04-20T06:17:39+00:00 INFO (6): ID: 123456 - Execute - Finished

Any idea how this could happen?

[T-Kuchel]

Hi @sprankhub ,

we will take a look at this, and come back here with a solution.

Regards Timo

[sprankhub]

Any update?

[T-Kuchel]

Hi @sprankhub ,

sorry for the delay. We are on it, and we will inform you on any available news.

Greetings from Kiel Timo

[carlosblackdd]

Hi,

are there any new developments in this issue? We have the same problems in the new second store (Website A --> Store AA and Store AB | Website B --> Store BA | Website C --> Store CA)

It's really strange, because the problem does only show up in Store AB - Mostly all configurations are Website-based configured. We tried different things - but no chance.

Please let us know if you have some hints for us.

Best from Chemnitz

[T-Kuchel]

Hi @carlos86 ,

we are still on it, but not with the highest priority.

Greeting from Kiel Timo

[carlosblackdd]

Hi @T-Kuchel,

ok. Are there any releases for M1 in the near future? There are a bunch of issues, that could be related to each other. In my feeling that are - which are really close.

119

434

431

429

Hope to get some positive feedback

[T-Kuchel]

Hi @carlos86 ,

there is a release in the starting blocks, and we are only waiting for some tiny nasty bugs to be fixed.

Greetings from Kiel Timo

[carlosblackdd]

Hi @T-Kuchel ,

we are still in research. We got more RAM (512 MB to 1GB). 10 out of 50 orders still stays in the transaction_status=running.

The last log line of these transactions is: 2020-07-14T08:36:04+00:00 INFO (6): ID: 451605 - Process - Save before events

The code after that is::

    $this->helper()->logCronjobMessage("ID: {$transactionStatus->getId()} - Process - Save before events", $order->getStoreId());
    $resource = $this->getFactory()->getModelResourceTransaction();
    $resource->addObject($order);
    $resource->addObject($transactionStatus);
    $resource->save();

    // Trigger Event
    $params = array(
        self::EVENT_PARAMETER_TRANSACTIONSTATUS => $transactionStatus,
        self::EVENT_PARAMETER_TRANSACTION => $transaction,
        self::EVENT_PARAMETER_CONFIG => $config,
        self::EVENT_PARAMETER_ORDER => $order,  

Do you have an idea, what in this part could be go wrong? We will debug it, but maybe you have some special tips

Our specification: Magento 1.9.4.5 Payone 4.6

[T-Kuchel]

Hi @carlos86 ,

without any Logs/Exceptions it seems to be very heavy to figure out, what problem is occurring here. Right now i/we have no special tips or known bugs on that for you.

Perhaps you have any kind of Log which could help here?

Greeting from Kiel Timo

[carlosblackdd]

The problems does not create logs/exceptions - except a db transaction rollback.

[T-Kuchel]

Hi @carlos86 ,

maybe the PR - https://github.com/PAYONE-GmbH/magento-1/pull/435 (which is right now under development, but testable) could help you there, to have more and detailed logging. Perhaps too much logging but the PR is going to have a switch for 'talkative'- on/off.

Greetings from Kiel Timo

[carlosblackdd]

Hi @T-Kuchel,

thanks for you answer. We will check this, if we can integrate it.

Actually we could identity, that our problem exists if there are 2 orders (first order from Website A Store A, second order from Website A Store B) which should be processed in one cron execution. Actually we want to clarify, if the analysis is correct and changed the code that it only takes one order in one cron exectution.

If it will be confirmed, I will come back again.

Best, Carlo

[carlosblackdd]

Hi @T-Kuchel,

after one weekend we can confirm that the problem with the running-order-status is gone away as soon as there is only one processing per cron execution. In these cases all of the processings are completed.

We also can identify that the problem with the running-status only exists if there is a processing of two orders from different stores with the same website - in the same cron execution. In this case the second order from store B won't be processed completely and it stucks in running-status.

Do you have an idea what the problem could create? Is there a configuration/object for the order of store A loaded which is not reloaded when the processing of for store B is running?

It stucks in the area of: // Save before Event is triggerd $this->helper()->logCronjobMessage("ID: {$transactionStatus->getId()} - Process - Save before events", $order->getStoreId()); $resource = $this->getFactory()->getModelResourceTransaction(); $resource->addObject($order); $resource->addObject($transactionStatus); $resource->save();

Thanks for your help.

[T-Kuchel]

Hi @carlos86 ,

thank you for your time and the hints. We will investigate on that.

Greetings from Kiel Timo

[thampe]

Hi,

we also have a shop (just one store view) that has since last week this problem. This never happend before. I uprgaded afterwards to the current payone extension version, but the problem persists:

Some order transaction status are stuck on "running". After I reset the status back to pending and the cronjob runs, it works. The transaction status is correctly processed.

Do you need any Data / Log Files that can help?

Feel free to contact me.

Thanks!

[carlosblackdd]

Hi. What is the php-memory-Limit of Your Shop? We could identify that a too low php-Memory limit can also force the problem!

[thampe]

Hi,

thanks, this seems to be the fix!

[carlosblackdd]

Perfect. What is your php-memory-limit?

In our scenario the problem is also with a php-memory-limit of 2 or even 4GB still there. So we think there should be a memory leak or a wrong function.

[thampe]

We now have 1G for the Cronjob.

[thampe]

Hi,

sadly we the problem still exists. If I execute the cron manually I now get an error:

****@***:~/htdocs/****/magento$  /opt/php-5.6/bin/php n98-magerun.phar sys:cron:run payone_core_cronjob_transactionstatus_process
Run Payone_Core_Model_Cronjob_TransactionStatus_Worker::execute
Fatal error: Call to a member function hasForcedState() on boolean in /var/www/*******/magento/app/code/core/Mage/Sales/Model/Order/Invoice.php on line 415

The problem is that these orders have no invoice but got the corresponding event from payone. I suspect it is some chnage in the config / setup on payones site that sends these. The payone merchant support could also not help since this is specific error...

I now have to check every other day the transaction log an change the running codes, which can not be solution... Does anyone has a better solution?

[fjbender]

With #435 we have been roughly shooting in the general direction of all the issues mentioned here. However, we are not sure if we fixed this behavior for good.

Is anyone brave enough to give #435 a try in a production-like environment, ideally with the verbose logging flag in https://github.com/PAYONE-GmbH/magento-1/pull/435/files#diff-af76dc03eb64f5b4e1f81b14b586de3eR971 turned on? This might give us more insight.

[thampe]

Hi,

thanks for the update, we might be testing the PR but I need approval from the shop owner first. I will provide new feedback as I have it.

[fjbender]

Anything new here?

As we're having trouble reproducing the errors mentioned here, we would be very grateful for someone with a production-like environment that could validate the PR :)

[carlosblackdd]

Hi,

we will check if we can deploy it in the Stage system. In our scenario (2 orders, 2 different stores) I could reproduce it - so I should be able to get some information for you

[fjbender]

Much appreciated!

[thampe]

Hi,

I talked to the customer and we decided that right now we do not want to use the patch in our store. We instead have a shell script (as a cron) which processed the failed transaction status entires. This seems to be working, but can obviously be not the long term solution.

[sprankhub]

Unfortunately, our client does not use PAYONE any more, so that I am not able to help with this.

[carlosblackdd]

Hi @fjbender,

we tested the PR. The first test was better. Two orders from different stores have been proceed in the same cron execution. .

Cause I had to create multiple orders in a short time from different stores to get two or more payment-processes in the same cron execution, I deactivated the cron (Aoe Cron Scheduler), made 4 orders (store A, store B, store A, store B), waited until all transactions status have been delivered (in the database). After that I activated the cron again, but nothing happened. The cron seems to be working fine, but all transactions are still in pending. the times in our database are UTC

What should we do?

Best, Carlo

[fjbender]

Hi @carlos86 ,

Thank you for trying this out! Could you provide me with some more detailed logs from the cron run, maybe through magento@payone.com? Did you turn on the verbose logging flag?

Thanks Florian

[fjbender]

Hi @carlos86 and all,

with 5b0f9f016c200feb0c67668c8e0f01caece66c66 we have fixed an issue with the tx processing where we assumed wrongly that we could find the "root" status to process by looking at the txtime field. Now we look at created_at, which makes a lot more sense.

The problem that all status are stuck in pending shouldn't occur any more now.

Thanks Florian

[thampe]

Hi,

do you have any information regarding when this fix will make into a release. As far as I can see, this is not in the new 5.0.0 release, correct?

Thanks!

[fjbender]

Hi @thampe,

our tests were successful, but we'd like to see some real-live tests in staging environments before merging this in the master and making it available to all merchants. The difficulty here is that we can not reproduce every edge case and make completely sure that the solution doesn't break anything for all merchants.

If you have a staging system available for testing, it would be greatly appreciated!

Thanks Florian

[thampe]

Hi @fjbender,

do you have got a branch or patch that we can use? I am not very happy about using an unreleased but we do not have another choice at this point.

Thanks, Thomas

[fjbender]

Hi @thampe,

yes, the patch would be in PR #435

Thanks Florian

[fjbender]

Hi all,

does anyone have any feedback?

[carlosblackdd]

Hi @fjbender,

actually we have no luck with Payone. We solved the problem of weird status and no invoices with the one transaction processing by cron execution. This works for store B of website A.

Now we implemented for the second and third website an second store.

In this case: The processing for the new two stores does not work again the processing is still one time per cron execution.

What are the problems:

1. the transactions (payone_protocol_transactionstatus) stays on "running" for appointed and paid-transactions
2. no invoice is created
3. no emails are sent (only manual with backend button)

Like in the first post of the issue - it stops before:

payone_cron.log:2020-04-20T06:17:39+00:00 INFO (6): ID: 123456 - Process - Finished payone_cron.log:2020-04-20T06:17:39+00:00 INFO (6): ID: 123456 - Execute - Finished service execution, set status to complete payone_cron.log:2020-04-20T06:17:39+00:00 INFO (6): ID: 123456 - Execute - Finished

Actually we don't really know what we can do. Maybe it could be more efficient to test a new payment provider

[carlosblackdd]

One more thing is also, that sometimes the paid-transaction is transferred before the appointed-transaction or in the same time. Through the prio of created-time, sometimes it takes the paid-transaction as first.

[sprankhub]

@carlos86 I had my issues with PAYONE as you can see from the issues in this repo. However, I saw quite some payment providers these years and PAYONE is one of the best I worked with. What they do in terms of order processing is replicable and transparent. They do listen if there are issues and they do help very well. Just my two cents :man_shrugging:

[carlosblackdd]

Thats right. Payone is really good - but actually we have no real solution. I don't want to create pressure, but we have no clue anymore.

My developers invest approx. 15-20 days to debug and analyze these different problems.

[fjbender]

Thank you for getting back with the info, and thanks also for the kind words.

I'll take this up with the team today and see, if we would be able to have a developer working directly with you on this issue.