Brain Teaser: Randomly, Load time> 30,000 ms instead of 60ms (InitContent)

[HeineFR]

Hello,

I would like to share with you my brain teaser as follows:
My shop is on 2 dedicated high performance servers (1Web Apache 2 & PHP-CFM 7.2.17 + 1Mariadb & CDN) all the caches are activated which gives me profiling a load time of "Unicorn" (40 to 80ms)

The site is extremely fast, but .... like that, for no apparent reason, it grinds, grinds, grinds and it ends up being displayed.

It does not matter if one is identified or not, with a cart or not and it does not matter the page ... the Http request is sent and no response before X seconds then instant display and it is left with the unicorn.

This can happen 2 times an hour (very very rarely) as 2 times a day and never more than 30 seconds, it completely blocks the site + the backoffice (which, in turn, runs on another instance of PHP -CFM) while the phpmyadmin which runs under the same instance of PHP-CFM as the front office and with the same MariaDB server works perfectly.

After several days of attempts, I managed to "catcher" the profiling in prod (with a condition $ _SERVER ['REMOTE_ADDR'] on my ip) and to my great amazement it is the initContent which does that:

Knowing that this problem is completely intermittent, it also happened to me in Dev (over 6 months) protected by Htaccess.

On the other hand, in Dev being alone on it I triggered the latency and typed me automatically the 30 seconds of waiting while, there, a visitor can trigger it and I can only undergo it for 15 seconds if I have a request which is performed in the middle of this latency.

So it's not a load problem or anything.

Now that I know that it is at the level of "InitContent" and completely random the question is: how can I debug this ???

[razaro]

Well interesting issue

Could you give more info like how many products do you have, categories? 

Do you have some cron jobs defined or some modules that sync products ?

Does any module have auto update? Do you have any MailChimp module?

 

And for profiling do you have more info blocks, like for modules and hooks ?

Also just as guess, any syncing between servers?

[HeineFR]

Thanks razaro for your investigation;

The problem was here in dev, when i just had 10 products to make my CSS, and now i got ~400products with a total of ~1200 combinations.

I've got some Cron jobs during night to refresh caches, search indexes, checking webp files. Some task At precise hours that don't match with this problem. Nothing seems strange on this way.

I dont see any module that could try to update something bringing this problem.
I don't sync the imap with my mails/shop.
mails are SMTP mode by a mailing plateform

This is the list of active modules  :      

amp    
blockreassurance    
cartabandonmentpro    
cdc_googletagmanager    
chronopost    
cmsproducts    
colissimo    
contactform    
cronjobs    
dashactivity    
dashgoals    
dashproducts    
dashtrends    
everpscustomerconnect    
graphnvd3    
gridhtml    
gsitemap    
infinitescroll    
modalcrossselling    
oscmigrationpro    
pagesnotfound    
paypal    
pickuppayment    
pm_advancedpack    
pm_advancedtopmenu    
postaldeliv    
prettyurls    
pscleaner    
pstglossary 
ps_buybuttonlite    
ps_categoryproducts    
ps_categorytree 
ps_contactinfo    
ps_currencyselector    
ps_customeraccountlinks    
ps_customersignin      
ps_emailsubscription    
ps_facetedsearch    
ps_featuredproducts   
ps_imageslider    
ps_languageselector    
ps_linklist    
ps_mbo    
ps_searchbar    
ps_sharebuttons    
ps_socialfollow    
ps_themecusto    
ps_viewedproduct    
ptm_controlcenter    
ptm_cookielaw    
ptm_dropdowncart    
ptm_multiblocks    
ptm_paymenticons    
pwfavorites    
sekeywords    
seoexpert    
seoimg    
smartsupp    
statsbestcategories    
statsbestcustomers    
statsbestproducts    
statsbestsuppliers    
statsbestvouchers    
statscarrier    
statscatalog    
statscheckup    
statsdata    
statsequipment    
statsforecast    
statslive    
statsnewsletter    
statsorigin    
statspersonalinfos    
statsproduct    
statsregistrations    
statssales    
statssearch    
statsstock    
statsvisits    
systempay    
totloyaltyadvanced    
welcome 

   
On profiling i saw an empty chart, i dont understand why the list of modules is empty, do i need debug mode activated?

 

The 2 servers syncing their partition with drdb and mariadb master / slave.

I'm Sure that It's really not a performance problem, i tried this benchmark:

10 threads of crawlers from an other dedicated server thats follow and test all the 1188 website links in 56s discovery links process included, the worst result is 0.222s

 

load impact test with 1000 users in 30sec :

load impact test with 500 users in 60sec :

As you can see i didnt get the 30s "Latency" while i perform all this test, that make it very hard to catch.

Tommorow i'll put a wget cronjob to hope to catch one more, my shop is actually live...

[HeineFR]

What i did today at first time:

I put back the hook/modules profiling modules following this : https://github.com/PrestaShop/PrestaShop/pull/16231/commits/931c6540f7515ab9e12ad2dd301e2b73f0f1ace0

 

Then,

I put a wget in cron every 15s.

Now, i have to wait it.... 

[HeineFR]

I got it !

But it don't seems to come from any module....

Have you any idea what can i debug next?

[HeineFR]

My wget of homepage every 15 seconds give me good info: i've greped "toaster" and this is the result:

Something is happening more than i was thinking !

it's Most of time EVERY 15 minutes !

I don't have any  cronjob every 15min, only one every 30 min on mariadb server but query time is always good.

Does prestashop have something to rebuild every 15 minutes??

[JBW]

Tricky issue. Do you have any overrides active? How are your smarty template complications settings?

[HeineFR]

On 1/27/2020 at 10:32 AM, JBW said:

Tricky issue. Do you have any overrides active? How are your smarty template complications settings?

Yes i've got some overrides, i'll try to bypass override dir constant for my webserver testing that make the wget's requests.

My smarty params are:

• Never recompile
• Cache : Yes
• Sync multi-server : No
• Cache : File System
• Never clear cache files

[EndermanAPM]

I'm having similar issues, did this get resolved eventually? 

[HeineFR]

For my personnal case it was an inexplicable server problem, we just changed it and this work perfectly since several years.