magento / magento2

Prior to making any Submission(s), you must sign an Adobe Contributor License Agreement, available here at: https://opensource.adobe.com/cla.html. All Submissions you make to Adobe Inc. and its affiliates, assigns and subsidiaries (collectively “Adobe”) are subject to the terms of the Adobe Contributor License Agreement.
http://www.magento.com
Open Software License 3.0
11.56k stars 9.32k forks source link

Cache lock issue #34078

Closed jonathanribas closed 3 years ago

jonathanribas commented 3 years ago

Preconditions (*)

  1. Adobe Commerce 2.3.7 / 2.4.3

This one relates to the famous https://github.com/magento/magento2/pull/22829

Steps to reproduce (*)

  1. After a deployment, Adobe Commerce cache is emptied, having some concurrency on cache generation, it can lead to long running time saving keys.
  2. I've tested to kill PHP-FPM master process when SYSTEM CONFIG key was being generated on Redis cache.

After killing it, I can still see the lock for SYSTEM CONFIG with a 7200 seconds TTL. During some minutes, it was very difficult to render a page on my local env as it keeps loading lock without any success:

1631628812.442996 [0 172.25.0.7:52150] "hget" "zc:k:cad_SYSTEM_DEFAULT" "d" 1631628812.443861 [0 172.25.0.7:52150] "hget" "zc:k:cad_LOCKED_RECORD_INFO_SYSTEM_CONFIG" "d" 1631628812.444582 [0 172.25.0.7:52162] "hget" "zc:k:cad_SYSTEM_DEFAULT" "d" 1631628812.445426 [0 172.25.0.7:52162] "hget" "zc:k:cad_LOCKED_RECORD_INFO_SYSTEM_CONFIG" "d" 1631628812.445471 [0 172.25.0.7:52120] "hget" "zc:k:cad_SYSTEM_DEFAULT" "d" 1631628812.445766 [0 172.25.0.7:52184] "hget" "zc:k:cad_SYSTEM_DEFAULT" "d" 1631628812.446496 [0 172.25.0.7:52120] "hget" "zc:k:cad_LOCKED_RECORD_INFO_SYSTEM_CONFIG" "d" 1631628812.446598 [0 172.25.0.7:52184] "hget" "zc:k:cad_LOCKED_RECORD_INFO_SYSTEM_CONFIG" "d" 1631628812.447747 [0 172.25.0.7:52088] "hget" "zc:k:cad_SYSTEM_DEFAULT" "d" 1631628812.448711 [0 172.25.0.7:52088] "hget" "zc:k:cad_LOCKED_RECORD_INFO_SYSTEM_CONFIG" "d" 1631628812.448845 [0 172.25.0.7:52146] "hget" "zc:k:cad_SYSTEM_DEFAULT" "d" 1631628812.448892 [0 172.25.0.7:52178] "hget" "zc:k:cad_SYSTEM_DEFAULT" "d"

I've decided to set expire manually to 20 seconds to that key and pages were generated immediately.

I think setting back $defaultLifetime to 10 seconds will maybe create another issue, I hope not as huge as this one.

Does someone know why lock TTL is set to 7200 seconds (2 hours) here https://github.com/magento/magento2/blame/2.4-develop/lib/internal/Magento/Framework/Lock/Backend/Cache.php#L46?

Expected result (*)

  1. Cache keys should generate without any issue even with concurrency
  2. User Experience should not be impacted by cache key saving

Actual result (*)

  1. After a deployment or during site life, sometimes (random) our end users are affected with more than 10 seconds loading time on several pages.

Please provide Severity assessment for the Issue as Reporter. This information will help during Confirmation and Issue triage processes.

m2-assistant[bot] commented 3 years ago

Hi @jonathanribas. Thank you for your report. To help us process this issue please make sure that you provided the following information:

Please make sure that the issue is reproducible on the vanilla Magento instance following Steps to reproduce. To deploy vanilla Magento instance on our environment, please, add a comment to the issue:

@magento give me 2.4-develop instance - upcoming 2.4.x release

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

Please, add a comment to assign the issue: @magento I am working on this


:clock10: You can find the schedule on the Magento Community Calendar page.

:telephone_receiver: The triage of issues 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.

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

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

kandy commented 3 years ago

@jonathanribas W We don't recommend using \Magento\Framework\Lock\Backend\Cache implementation due to described problem. Can you check if this issue is reproduced with \Magento\Framework\Lock\Backend\Database?

jonathanribas commented 3 years ago

@kandy thanks for your help!

I've just tested \Magento\Framework\Lock\Backend\Database on 2.3.7 and now we have the following error on some homepage blocks (Page Builder): Error filtering template: Current connection is already holding lock for 9af174cd8e68c0ec0d719dd1cd00434, only single lock allowed

If I reload homepage, as it's on FPC it stills show this error on all blocks. User Experience is really bad :(

Looking inside method comment on 2.3.7:

`/**

I can see the following. 2.4.3 has been updated and works fine even if I kill PHP-FPM master process and start it again: https://github.com/magento/magento2/blob/2.3.7/lib/internal/Magento/Framework/Lock/Backend/Database.php#L95

Do you know if lauching an Adobe Commerce upgrade from command line will update the app/etc/di.xml file? In our case it was still with old cache mechanism \Magento\Framework\Lock\Backend\Cache for Magento\Framework\Cache\LockGuardedCacheLoader.

kandy commented 3 years ago

@jonathanribas Yes, by default composer will overwrite the di.xml file You also can specify adapter in env.php file. see https://github.com/magento/magento2/blob/2.3.7/lib/internal/Magento/Framework/Lock/LockBackendFactory.php#L98 or https://devdocs.magento.com/cloud/env/variables-deploy.html#lock_provider for Adobe Cloud

if you think that there is no issue in 2.4.3 feel free to close the ticket ;)

jonathanribas commented 3 years ago

@kandy, great to know, thank you!

Closing this one at the moment, will reopen if we still have issues.

Thanks again.