cancel
Showing results for 
Search instead for 
Did you mean: 

Long Time to First Byte - Over 30 Seconds

Long Time to First Byte - Over 30 Seconds

Like the subject says, it's taking the better part of a minute to load any page the website. Profiler shows "mage" having a 34s execution time

Here's some of the profiler output:
profiler.jpg

13 REPLIES

Re: Long Time to First Byte - Over 30 Seconds

Hey @jerome_leung,

Could you please provide the full data from profiler? Do you use 3rd party extensions btw?

Re: Long Time to First Byte - Over 30 Seconds

 @MageWorx Team will this work?

Code ProfilerTimeCntEmallocRealMem
mage36.5241100
CORE::create_object_of::Mage_Core_Model_Cache0.0006189,3520
mage::app::init::config::load_cache0.004415520
mage::app::init::stores0.8251226,416262,144
CORE::create_object_of::Mage_Core_Model_Resource_Website_Collection0.8211148,816262,144
DISPATCH EVENT:resource_get_tablename0.001916710,2720
DISPATCH EVENT:core_collection_abstract_load_before0.0009854,4880
DISPATCH EVENT:core_collection_abstract_load_after0.0012854,4880
init_config_section:stores_usa0.001518800
mage::app::init_front_controller0.00251170,512262,144
DISPATCH EVENT:controller_front_init_before0.0004170,0560
OBSERVER: mana_core0.009675118,5040
mage::app::init_front_controller::collect_routers0.0016179,752262,144
DISPATCH EVENT:controller_front_init_routers0.0003113,3440
CORE::create_object_of::Mage_Core_Model_Url_Rewrite0.0003106,0080
mage::dispatch::db_url_rewrite0.1575110,0080
DISPATCH EVENT:model_load_after0.0009573,2080
DISPATCH EVENT:core_abstract_load_after0.0003322,0080
mage::dispatch::routers_match35.5298100
mage::dispatch::controller::action:Smiley Tongueredispatch0.36911592,3121,048,576
CORE::create_object_of::Mage_Core_Model_Session0.002242,8560
Mage_Core_Model_Session_Abstract_Varien::start/start0.0009119,8560
mage::dispatch::controller::action:Smiley Tongueredispatch::load_area::frontend::design0.158148,4080
CORE::create_object_of::Mage_Core_Model_Design_Package0.0004128,1120
mage::dispatch::controller::action:Smiley Tongueredispatch::load_area::frontend::translate0.2043152,8881,048,576
Mage_Core_Model_Design_Package::getFilename0.0183146152,7760
DISPATCH EVENT:controller_action_predispatch0.00411402,5680
OBSERVER: xmlconnect0.0002171,3360
CORE::create_object_of::Mage_XmlConnect_Model_Observer0.0001164,0400
OBSERVER: mana_db0.00071107,6880
CORE::create_object_of::Mage_Index_Model_Indexer0.0005188,4480
CORE::create_object_of::Mage_Index_Model_Resource_Process_Collection0.0004134,4720
OBSERVER: log0.0007110,5680
OBSERVER: pagecache0.0003118,2480
OBSERVER: persistent0.00073148,6560
mage::dispatch::controller::action::cms_index_index35.1604100
DISPATCH EVENT:model_load_before0.0005472,6640
mage::dispatch::controller::action::cms_index_index::layout_load1.2181115,7440
layout/package_update: default0.1112165,2800
layout/db_update: default34.7317100
layout/db_update: cms_page34.5735100
layout/db_update: STORE_usa34.4157100
layout/db_update: THEME_frontend_default_v-tac34.2579100
layout/db_update: cms_index_index34.0998100
layout/db_update: page_one_column33.942100
layout/db_update: customer_logged_out33.7838100
DISPATCH EVENT:controller_action_layout_generate_blocks_before0.0022129,8720
Mana_Core_Helper_Js:Smiley TonguerocessFiles0.001819,5760
mage::dispatch::controller::action::cms_index_index::layout_generate_blocks0.035212,219,2402,097,152
BLOCK: formkey0.0005116,1200
DISPATCH EVENT:core_block_abstract_prepare_layout_before0.00111095,6400
DISPATCH EVENT:core_block_abstract_prepare_layout_after0.008410912,544262,144
OBSERVER: currencypricing_add_product_tabs0.002410918,8560
DISPATCH EVENT:core_layout_block_create_after0.00091095,6400
BLOCK ACTION: head -> addJs0.00021015,5520
BLOCK ACTION: head -> addItem0.00031724,7600
BLOCK: js_cookies0.0003167,2320
BLOCK ACTION: head -> addCss0.00031726,0800
BLOCK: global_notices0.0003165,9920
BLOCK: catalog.topnav0.00051112,256262,144
BLOCK: top.container0.0003157,2800
BLOCK: welcome0.0003164,3440
BLOCK: global_cookie_notice0.0003165,3040
BLOCK ACTION: top.links -> addLink0.0034438,536262,144
CORE::create_object_of::Mage_Core_Model_Url0.003612876,1680
BLOCK: catalog.compare.sidebar0.00041158,7440
BLOCK ACTION: footer_links -> addLink0.0024413,8480
BLOCK: catalog_product_price_template0.0003156,6480
BLOCK: return_link0.0008172,5520
BLOCK ACTION: checkout_cart_link -> addCartLink0.0016141,4240
BLOCK: paypal.partner.top_cart.shortcut0.00041155,112262,144
BLOCK: wishlist_sidebar0.00041176,1360
BLOCK: paypaluk.partner.top_cart.shortcut0.0003166,936262,144
BLOCK: head_rss0.0005169,0960
BLOCK: addthis_smartlayers0.0003168,7200
BLOCK: right.clnews.menu0.00071142,672262,144
BLOCK: right.clnews.latest0.0005174,2000
BLOCK ACTION: top.clnews.link -> getTopLink0.0007126,1920
BLOCK: ipredirect0.003194,320262,144
BLOCK: m_core_singletons0.0003157,8000
BLOCK: paypal.partner.right.logo0.0003165,0320
BLOCK: bml.center.logo0.0003166,3600
BLOCK: sale.reorder.sidebar0.0003167,0560
DISPATCH EVENT:controller_action_layout_generate_blocks_after0.0004116,9840
mage::dispatch::controller::action::cms_index_index::layout_render33.5866100
DISPATCH EVENT:core_block_abstract_to_html_before0.0006693,7040
frontend/default/v-tac/template/page/1column.phtml33.513616,246,7526,553,600
frontend/default/v-tac/template/page/html/head.phtml0.02231222,312262,144
DISPATCH EVENT:core_block_abstract_to_html_after0.304568365,360524,288
OBSERVER: modify0.00336815,6560
OBSERVER: mana_core_require0.00346815,6800
OBSERVER: mana_filters0.00286820,8160
OBSERVER: sharingtool0.00316818,8000
OBSERVER: apptrian_minify_core_block_abstract_to_html_after0.273368352,664524,288
frontend/default/v-tac/template/directory/js/optional_zip_countries.phtml0.0003121,5120
frontend/default/v-tac/template/googleanalytics/ga.phtml0.0004118,5040
frontend/default/default/template/addthis/smartlayers/smartlayers.phtml0.001719,1600
frontend/default/v-tac/template/page/html/header.phtml8.39351894,0481,048,576
frontend/default/default/template/unibanner/banner.phtml9.499415505,344262,144
CORE::create_object_of::Uni_Banner_Model_Bannergroup0.00083117,7040
CORE::create_object_of::Uni_Banner_Model_Mysql4_Bannergroup_Collection0.009731211,5120
CORE::create_object_of::Uni_Banner_Model_Mysql4_Bannergroup0.00113215,5840
CORE::create_object_of::Uni_Banner_Model_Banner0.00093821,6240
CORE::create_object_of::Uni_Banner_Model_Mysql4_Banner_Collection0.01238225,1280
CORE::create_object_of::Uni_Banner_Model_Mysql4_Banner0.00133918,8880
frontend/default/default/template/unibanner/effects/custom.phtml4.741815232,8960
CORE::create_object_of::Mage_Catalog_Model_Category0.32367224,2400
DISPATCH EVENT:core_abstract_load_before0.0003261,7200
DISPATCH EVENT:catalog_category_load_before0.0002191,392262,144
DISPATCH EVENT:catalog_category_load_after0.0002191,3760
CORE::create_object_of::Mage_Catalog_Model_Category_Url0.0004346,4400
REWRITE: Mage_Catalog_Model_Category_Url::getCategoryUrl1.426834138,2160
DISPATCH EVENT:catalog_category_flat_loadnodes_before0.0001108880
CORE::create_object_of::Mage_Widget_Model_Template_Filter0.00011313,8960
Mage_Core_Model_Design_Package::getSkinUrl0.00363234,2880
frontend/default/v-tac/template/searchautocomplete/topsearch.phtml0.0018116,6800
frontend/default/v-tac/template/page/custom.phtml24.422314,961,7444,980,736
frontend/default/v-tac/template/clnews/eventlist.phtml2.20982449,496524,288
CORE::create_object_of::CommerceLab_News_Model_Mysql4_News_Collection0.0005210,4640
CORE::create_object_of::CommerceLab_News_Model_Mysql4_Category_Collection0.0003210,2640
CORE::create_object_of::CommerceLab_News_Model_Mysql4_Comment_Collection0.0007418,3520
CORE::create_object_of::Int_Featuredproducts_Model_Mysql4_Featuredproducts_Collection0.0004210,3040
CORE::create_object_of::Mage_Catalog_Model_Resource_Product0.1579116,6560
EAV: Mage_Eav_Model_Config::getEntityType0.787212046,7920
__EAV_LOAD_MODEL__0.814411,515,5201,572,864
EAV: Mage_Eav_Model_Config::_initAttributes0.48151916,0961,048,576
CORE::create_object_of::Mage_Catalog_Model_Resource_Product_Attribute_Collection0.1599167,8880
CORE::create_object_of::Mage_Catalog_Model_Resource_Eav_Attribute0.001810166,5840
EAV: Mage_Eav_Model_Config::getAttribute2.517315079,2080
__EAV_LOAD_MODEL_AFTER_LOAD__0.16551524,560524,288
CORE::create_object_of::Mage_Eav_Model_Entity_Attribute_Backend_Default0.00035311,1760
DISPATCH EVENT:catalog_product_load_after0.63131310,152262,144
OBSERVER: inventory0.47362231,0560
OBSERVER: currencypricing_load_product_compound_price0.15851119,152262,144
OBSERVER: currencypricing_load_product_compound_special_price0.157111,7280
CORE::create_object_of::Innoexts_CurrencyPricing_Model_Mysql4_Catalog_Product_Collection0.47661373,328524,288
DISPATCH EVENT:catalog_product_collection_apply_limitations_after0.0025182,960262,144
OBSERVER: currencypricing_after_product_collection_apply_limitations0.00165180,224262,144
DISPATCH EVENT:catalog_block_product_list_collection1.4252427,152262,144
OBSERVER: review1.42482424,424262,144
__EAV_COLLECTION_LOAD_ENT__0.47431155,3680
__EAV_COLLECTION_AFTER_LOAD__0.63441163,376262,144
DISPATCH EVENT:catalog_product_collection_load_after0.47651152,880262,144
OBSERVER: tax0.0007171,4080
OBSERVER: currencypricing_load_product_collection_compound_price0.1585110,9680
OBSERVER: currencypricing_load_product_collection_compound_special_price0.158113,2880
frontend/default/v-tac/template/videogallery/videogallery.phtml1.5732170,7120
CORE::create_object_of::Krishinc_Videogallery_Model_Videogallery0.0003106,0240
CORE::create_object_of::Krishinc_Videogallery_Model_Mysql4_Videogallery_Collection0.0008418,6560
frontend/default/v-tac/template/page/custom_files/looking_for.phtml3.32082306,648524,288
_LOAD_ATTRIBUTE_BY_CODE__1.8844430,7360
CORE::create_object_of::Mage_Eav_Model_Resource_Entity_Attribute_Option_Collection0.0021553,6320
frontend/default/v-tac/template/page/html/footer.phtml0.51121137,5920
frontend/default/v-tac/template/newsletter/subscribe.phtml0.001416,3840
CACHE_URL0.00431124,8480

Re: Long Time to First Byte - Over 30 Seconds

Hey @jerome_leung,

Thanks for providing extra data.

We'd say that  the prolonged page load time is directly related to the issues in certain blocks, as a great deal of time takes layout load: (mage::dispatch::controller::action::cms_index_index::layout_render    33.5866, that's where header loads for too long as well: (frontend/default/v-tac/template/page/html/header.phtml    8.3935) , banner (frontend/default/default/template/unibanner/banner.phtml    9.4994) and some impossibly slow block (set of blocks) - (frontend/default/v-tac/template/page/custom.phtml    24.4223).

We'd recommend to start with disabling the extension that slowly loads banners. Then try to switch to the standard theme. Then review all the blocks that it takes too long to load, one after another (check out all the blocks with time higher than 0.5 seconds in profiler).

It's highly likely that huge collection loads are called in those blocks.

    

---------------------------------------------------------

If you've found one of our answers useful, please give 'Kudos' or 'Accept as Solution'.

Re: Long Time to First Byte - Over 30 Seconds

@MageWorx Team, is there a way for me to show you a list of the extensions that this site has?

Re: Long Time to First Byte - Over 30 Seconds

@jerome_leung, sure. Copy paste the list of files from app/etc/modules.

Anyways, to deal with the issue, switch to the default theme and debug a block after block. This should work out.

Re: Long Time to First Byte - Over 30 Seconds

@MageWorx Team, here is the list of extensions

AddThis_Sharingtool.xml
AjaxNewsletter_Ajaxnewsletter.xml
Anowave_Price.xml
Aoe_Scheduler.xml
Apptrian_Minify.xml
Aschroder_SMTPPro.xml
BusinessKing_OutofStockSubscription.xml
Clarion_Customerattribute.xml
Clearandfizzy_EnhancedCMS.xml
Cm_RedisSession.xml
CommerceLab_News.xml
Creation_Afipredirect.xml
Dexxtz_Productzoom.xml
ET_Lytebox.xml
Inchoo_Shipping.xml
Innoexts_Core.xml
Innoexts_CurrencyPricing.xml
Int_Featuredproducts.xml
Int_Pdfupload.xml
Italian_locale.xml
Jain_Bought.xml
Kanavan_Searchautocomplete.xml
Krishinc_Videogallery.xml
Mage_All.xml
Mage_Api.xml
Mage_Api2.xml
Mage_Authorizenet.xml
Mage_Bundle.xml
Mage_Captcha.xml
Mage_Centinel.xml
Mage_Compiler.xml
Mage_Connect.xml
Mage_CurrencySymbol.xml
Mage_Downloadable.xml
Mage_ImportExport.xml
Mage_Oauth.xml
Mage_PageCache.xml
Mage_Persistent.xml
Mage_Weee.xml
Mage_Widget.xml
Mage_XmlConnect.xml
Magehouse_Infinity.xml
Magpleasure_Filesystem.xml
Mana_Core.xml
Mana_Db.xml
Mana_Filters.xml
Netzarbeiter_CustomerActivation.xml
Phoenix_Moneybookers.xml
Pulsestorm_Tinymceconfig.xml
Raveinfosys_Deleteorder.xml
SaveTheMage_CustomInvoiceAndOrderNumber.xml
SF9_Realex.xml
Uni_Banner.xml
Uni_Banner_13012016.xml
V2store_Catalog.xml
V2store_Checkout.xml
V2store_Sales.xml
V2store_Shipping.xml
Vestrics_Casestudies.xml
Vestrics_ConnectorSales.xml
Vestrics_Core.xml
Vestrics_Coreextended.xml
Vestrics_Custom.xml
Vestrics_Lightingcal.xml
Vestrics_ProductCurrency.xml
Vestrics_Quickorder.xml
Vestrics_Sap.xml
Vestrics_Sapapi.xml
Vestrics_Tracking.xml
WP_CustomMenu.xml

 

Which directory are the blocks kept in?

Re: Long Time to First Byte - Over 30 Seconds

@jerome_leung,

Magehouse_Infinity Mana_* BusinessKing_OutofStockSubscription Anowave_Price Int_Featuredproducts Innoexts_CurrencyPricing Jain_Bought Kanavan_Searchautocomplete Krishinc_Videogallery Uni_Banner V2store_* Vestrics_*  are potentially 'dangerous' modules. We'd recommend to turn off all of them and check the speed without them. If it gets better, enable them in turns and check. Don't forget to update cache each time you enable/disable modules. 

* are modules of the same vendor.

This should help, but without having a look at the code, it's hard to tell for sure.

---------------------------------------------------------

If you've found one of our answers useful, please give 'Kudos' or 'Accept as Solution'.

Re: Long Time to First Byte - Over 30 Seconds

@MageWorx Team

Disabling Int_Featuredproducts and Innoexts_CurrencyPricing reduce the load time by about 8 seconds but makes the main part of the site disappear. Disabling Uni_Banner breaks the site altogether, but it loads almost immediately. All the other extensions don't seem to have much effect on the site.

Re: Long Time to First Byte - Over 30 Seconds

@jerome_leung,

Hm, I checked module code with the banners, requests to collections and image resize are the heaviest requests. But there are attempts to use cache and maximally decrease the load. So, that's unlikely what's causing the issue. You should check out why the module breaks the site and fix it (that's not the way a module should operate), and then take a look what will be next. The banner block is likely to be wired within the cms page, which may cause the error when the module is disabled. I'd recommend to off it and try further.

 

---------------------------------------------------------

If you've found one of our answers useful, please give 'Kudos' or 'Accept as Solution'.