Log when an order update lock is held past its timeout

Problem/Motivation

OrderStorage::loadForUpdate() acquires the commerce_order_update:ID lock with the lock backend's default timeout of 30 seconds. If the holder is still working when that timeout passes, the lock expires silently. A request waiting in loadForUpdate() can then acquire it, load the same order and save it, while the first request is still working on its own copy.

Both requests believe they have exclusive access, and nothing records that the lock stopped protecting the order. For example, a payment gateway notification and the customer returning from the offsite payment page can both place the same order this way, and each runs the order's place transition and its subscribers.

The holder is the only request that can tell this happened, but releaseLock() currently releases the lock without checking how long it was held.

Steps to reproduce

1. Request A calls loadForUpdate() on an order and saves it, and the save takes longer than 30 seconds (for example, a slow query or a slow API call in a presave hook or in a subscriber to the order's transition).
2. While A's save is still running, request B calls loadForUpdate() on the same order. B waits, the lock expires, and B acquires it, loads the order and saves it.
3. Both saves go through. Nothing is logged about the overlap.

Why the order version check does not catch this

The version check in Order::preSave() compares the order being saved with $this->original, which is read at the start of the save without a row lock, and the UPDATE is not conditioned on the version. So it only catches a writer that starts its save after the other one has committed:

• If A is slow before calling save() and B commits first, A's save throws (or, with log_version_mismatch, logs) OrderVersionMismatchException. That is caught, but the message only says the versions differ, not that the lock expired or for how long.
• If A is slow inside its save, A's check has already passed. B loads the last committed version, so its check passes too, and the second write silently overwrites the first. Work done in presave hooks and transition subscribers is usually what makes a save long, so this is the more likely case.

Only the lock holder knows that it outlived its lock, in both cases.

Proposed resolution

• Record when each update lock is acquired in OrderStorage::$updateLocks, using the datetime.time service.
• In releaseLock(), if the lock was held longer than its timeout, try to extend it before releasing it. Extending a lock only succeeds while the current request still owns it, so this tells an expired lock that no one claimed apart from one that another request acquired.
• Log a warning in the first case and an error in the second, with the order ID and how long the lock was held.
• Pass the timeout explicitly through a new OrderStorage::UPDATE_LOCK_TIMEOUT constant (30.0, the current default), so the check and the lock use the same value.

A lock released within its timeout costs nothing extra: the extra lock backend call only happens after a timeout. release() already only removes the lock owned by the current request, so a lock another request acquired in the meantime is left in place.

Remaining tasks

• Review.

User interface changes

None.

API changes

New OrderStorage::UPDATE_LOCK_TIMEOUT constant. The values of the protected OrderStorage::$updateLocks property change from TRUE to the acquisition time.

Data model changes

None.

AI disclosure: this issue was drafted with the help of an AI assistant and reviewed by a human before posting.