maksuturva / magento2_payment_module

Svea Payment module for Magento 2
Other
4 stars 13 forks source link

Payment status check throttling does not work due to the cron job failing to update the update_at timestamp #64

Open mattijv opened 9 months ago

mattijv commented 9 months ago

The throttling logic in https://github.com/maksuturva/magento2_payment_module/blob/master/app/code/Svea/Maksuturva/Model/Cron.php does not work correctly due to the fact that the Svea\Maksuturva\Model\Gateway\Implementation::ProcessStatusQueryResult method does not actually update the update_at field of the order.

The code to update the timestamp (which happens in this switch case) looks like the following:

$updatedate = $this->_localeDate->date();
$order->setUpdatedAt($updatedate->format('Y-m-d H:i:s'));
$order->save();

On a cursory glance this looks fine, but Magento has code that prevents updating the updated_at field directly, as it's intended to change only if something in the row actually changes.

Perhaps a better mechanism would be to have a dedicated timestamp column tracking when was the last time the order status was checked and use that for the throttling, instead of (ab)using the updated_at timestamp?

Svea-Maintainer commented 9 months ago

Thank you for pointing a potential bug in the code... we have tracked logs and database for multiple day timespan and in the test environment the updated_at database field gets updated as supposed to be.

Also there is this potential spot for failure in code https://github.com/maksuturva/magento2_payment_module/blob/dce430e13d34f60c5c73c1d0954b824b442e1a33/app/code/Svea/Maksuturva/Model/Cron.php#L120 date function does not use localized timestamp...

We'll try to update code so that we get rid of updated_at field overall.

mattijv commented 9 months ago

To verify, you mean the updated_at timestamp is updating in your database in the case where the switch case in the processStatusQueryResult goes to this case?

case \Svea\Maksuturva\Model\Gateway\Implementation::STATUS_QUERY_NOT_FOUND:
case \Svea\Maksuturva\Model\Gateway\Implementation::STATUS_QUERY_FAILED:
case \Svea\Maksuturva\Model\Gateway\Implementation::STATUS_QUERY_WAITING:
case \Svea\Maksuturva\Model\Gateway\Implementation::STATUS_QUERY_UNPAID:
case \Svea\Maksuturva\Model\Gateway\Implementation::STATUS_QUERY_UNPAID_DELIVERY:
default:

Here's a short test script that simulates that case (an order object is loaded from the database, the update_at field is changed and the object is saved, which is basically what happens when the cronjob processes an order that hits the above switch case).

<?php

// Place this in a Magento project root directory, replace the SOMEINCREMENTID
// and run with `php scriptname.php`.

use Magento\Sales\Model\Order;
use Magento\Sales\Model\ResourceModel\Order\CollectionFactory;
use Magento\Sales\Model\ResourceModel\Order\Collection;

require __DIR__ . '/app/bootstrap.php';

$bootstrap = \Magento\Framework\App\Bootstrap::create(BP, $_SERVER);
$om = $bootstrap->getObjectManager();

/** @var Collection $collection */
$collection = $om->get(CollectionFactory::class)->create();

$incrementId = 'SOMEINCREMENTID';

$collection->addFieldToFilter('increment_id', $incrementId);

/** @var Order $order */
$order = $collection->getFirstItem();

echo "Original updated_at: {$order->getUpdatedAt()}\n";

$order->setUpdatedAt('2222-01-01 01:02:03');
$order->save();

// Magento reloads the updated_at timestamp from the database after the update, so this
// will be the same as the original. You can also observe from the DB that the updated_at
// timestamp does not change.
echo "New updated_at: {$order->getUpdatedAt()}\n";

The result should be that the order updated_at field stays the same despite the code attempting to change the timestamp.

If the updated_at timestamp changes for you then maybe there is something wonky on our end.

Svea-Maintainer commented 8 months ago

Yes, we have some pending orders created in the test store and have been monitoring those DB rows for week time span. Timestamp gets updated for every status query. For example `| 000000011 | pending | 2024-01-10 18:00:59 | 2024-01-12 05:40:05 | .

All server and Magento timezone settings are set to "Europe/Helsinki". These DB timestamps seems to be UTC time though.

Thank you for this script! We'll test it soon and we'll deploy a new test store with exact same version 2.4.6-p2 + PHP 8.2 also...

Svea-Maintainer commented 8 months ago

Seems to be Magento version related. We tested in Magento 2.4.6 test environment now, and the updated_at timestamp does not get updated after successful status query.

Svea-Maintainer commented 8 months ago

There is a new version 1.9.6 released now and updated_at parameter is removed from status query interval logic. Also cron interval is increased from 10 minutes to 30 minutes. This is not a complete solution to this problem but helps to reduce the query count remarkably.

https://github.com/maksuturva/magento2_payment_module/releases/tag/1.9.6