Cron - fix getting warning log after the first failed job lock retry

[oleksii-lisovyi]

Description (*)

Currently there is provided a re-try mechanism for cron job locking, that write warning log message after each failed try.
The issue is that the warning doesn't actually represent any issue if the lock is successfully happened on the next try.

Similarly to the re-try mechanisms for MySQL PDO Adapter and Queue Message I propose to write the only critical log message if the lock doesn't happen after all 5 tries.

Related Pull Requests

Fixed Issues (if relevant)

Manual testing scenarios (*)

No sure how to test this case manually.

Questions or comments

Contribution checklist (*)

• Pull request has a meaningful description of its purpose
• All commits are accompanied by meaningful commit messages
• All new or changed code is covered with unit/integration tests (if applicable)
• All automated tests passed successfully (all builds are green)

[m2-assistant]

Hi @oleksii-lisovyi. Thank you for your contribution
Here is some useful tips how you can test your changes using Magento test environment.
Add the comment under your pull request to deploy test or vanilla Magento instance:

• @magento give me test instance - deploy test instance based on PR changes
• @magento give me 2.4-develop instance - deploy vanilla Magento instance

❗ Automated tests can be triggered manually with an appropriate comment:

• @magento run all tests - run or re-run all required tests against the PR changes
• @magento run <test-build(s)> - run or re-run specific test build(s)
  For example: @magento run Unit Tests

<test-build(s)> is a comma-separated list of build names. Allowed build names are:

1. Database Compare
2. Functional Tests CE
3. Functional Tests EE,
4. Functional Tests B2B
5. Integration Tests
6. Magento Health Index
7. Sample Data Tests CE
8. Sample Data Tests EE
9. Sample Data Tests B2B
10. Static Tests
11. Unit Tests
12. WebAPI Tests

You can find more information about the builds here

ℹ️ Please run only needed test builds instead of all when developing. Please run all test builds before sending your PR for review.

For more details, please, review the Magento Contributor Guide documentation.

⚠️ According to the Magento Contribution requirements, all Pull Requests must go through the Community Contributions Triage process. Community Contributions Triage is a public meeting.

🕙 You can find the schedule on the Magento Community Calendar page.

📞 The triage of Pull Requests happens in the queue order. If you want to speed up the delivery of your contribution, please join the Community Contributions Triage session to discuss the appropriate ticket.

🎥 You can find the recording of the previous Community Contributions Triage on the Magento Youtube Channel

✏️ Feel free to post questions/proposals/feedback related to the Community Contributions Triage process to the corresponding Slack Channel

[oleksii-lisovyi]

@magento run all tests

[rogyar]

Hi @oleksii-lisovyi. Thank you for your collaboration. It totally makes sense.
But rather than changing this logging behavior, I would extend it slightly. So if there's an unsuccessful attempt to acquire the lock, we have a message like the following.

"Failed attempt to acquire lock for cron job: {$schedule->getJobCode()}, retrying"

Once all attempts have spent the system will say

"Could not acquire lock for cron job: {$schedule->getJobCode()}"

What do you think?

Also, I would ask you to cover your change with a simple unit test.

Thank you!

[oleksii-lisovyi]

@rogyar, thank you for the comment.

So we can end up with logging a debug message if lock try is failed and with error one after all the 5 failed tries.
If you're OK with this, I'll make appropriate update and cover each of the case with unit tests.

[rogyar]

Hi @oleksii-lisovyi. That sounds fair enough. Please, proceed.

Thank you!

[oleksii-lisovyi]

Sorry for a long inactivity. I've had a vacation and simply forgot about the issue.
Working on it.

[oleksii-lisovyi]

@magento run all tests

[rogyar]

Hi @oleksii-lisovyi. Thank you for your contribution. According to the definition of done all changes should be covered by automated tests. You may cover this particular case by extending the existing integration test.

Thank you!

[hostep]

Any updates here? @Den4ik maybe?

PR makes sense to me, I'm currently investigating a bunch of Could not acquire lock for cron job messages myself on a shop and got confused why I saw many lines at the exact same timestamp, this PR could have helped I think because in the logs it's not very clear if eventually the cron ran or if it kept being blocked.

[hostep]

It looks like this got fixed in ACP2E-82: Same cron job executes twice, this fix got included in Magento 2.4.4 and higher.

If you're curious like I why if ($retries === 1) { got used instead of if ($retries === 0) {, it's because then we actually get 5 attempts. With if ($retries === 0) { we would have gotten 6 attempts which is one too many since MAX_RETRIES is set to 5.

So, I think this PR can be closed 🙂