2

Drupal 7 site experiencing slow execution/load time for first page visit and slower execution/load time for login. The web server and database servers are dedicated and well resourced, the site has no traffic currently.

Settings already in place

  • JS/CSS compression enabled
  • Cron is run via crontab every hour and disabled in Drupal
  • Cache warming 2 times a day with min, max cache expiry time at 1 day for anon
  • APC is set to 192MB and using about half memory
  • Database is on another dedicated box lots of RAM
  • Update manager disabled
  • Content translation disabled
  • No missing modules

Setup info

  • About 100 modules: 70 contrib, 30 custom
  • Drupal core and modules are on NFS server
  • apc.stat=1 , apc.stat_ctime=Off, apc.ttl=3600
  • php.ini - realpath_cache_size=512k
  • settings.php - database set via IP (not hostname)
  • Mysql - query_cache_size no effect with both enabled or disabled
  • Mysql - innodb_flush_log_at_trx_commit =2
  • Mysql - innodb_buffer_pool_size=4G #current DB is 100mb total

DB queries are < 110 ms. XHprof snapshots below.

XHprof for first login

XHprof for second login

Update1: Login after few silent hours XHprof for first login after few silent hours

Update2: Update.php XHprof timing enter image description here

Update: NFS info

%nfsstat -m Flags: rw,nosuid,nodev,relatime,vers=3,rsize=1048576,wsize=1048576,namlen=255,hard,proto=tcp,timeo=600,retrans=2,sec=sys,mountaddr=xx.xx.xx.xx,mountvers=3,mountport=xxxx,mountproto=udp,local_lock=none,addr=xx.xx.xx.xx

enter image description here

Any suggestions to improve load times?

Update 3: Cache configurations in settings.php When I enable and run test for cache and APC cache using Drupal's Testing module. I get fatal errors with "Class 'Database' not found"

I am using APC cache module, below are my settings. Is something wrong with this config. APC has 192MB and used about 110MB

/****
 * APC Caching.
 ****/
$conf['cache_backends'][] = 'sites/XYZ/modules/apc/drupal_apc_cache.inc';

// cache - is used for all common cache purposes. is a default cache bin for Drupal.
$conf['cache_class_cache'] = 'DrupalAPCCache';

$conf['cache_class_cache_admin_menu'] = 'DrupalAPCCache';

// cache_block - is used for storing block's cache
$conf['cache_class_cache_block'] = 'DrupalAPCCache';

$conf['cache_class_cache_bootstrap'] = 'DrupalAPCCache';

$conf['cache_class_cache_field'] = 'DrupalAPCCache';

// cache_filter - is used for storing filtered input
$conf['cache_class_cache_filter'] = 'DrupalAPCCache';

// cache_form - is used for storing forms. 
// This cache bin should not be assigned to volatile storage
//$conf['cache_class_cache_form'] = 'DrupalAPCCache'; // use Database

//$conf['cache_class_cache_image'] = 'DrupalAPCCache';

$conf['cache_class_cache_libraries'] = 'DrupalAPCCache';

// cache_menu - is used for storing assembled and processed menu
$conf['cache_class_cache_menu'] = 'DrupalAPCCache';

// cache_page - is used to store cached pages 
//$conf['cache_class_cache_page'] = 'DrupalAPCCache';

$conf['cache_class_cache_path'] = 'DrupalAPCCache';

$conf['cache_class_cache_path_breadcrumbs'] = 'DrupalAPCCache';

// cache_update - if module Update status' is enabled this 
// bin stores Drupal, modules and themes update information. 
$conf['cache_class_cache_update'] = 'DrupalAPCCache';


//$conf['apc_show_debug'] = TRUE;  // Remove the slashes to use debug mode.

/*****
 * Contributed module cache
 ****/

// Browscap module
$conf['cache_class_cache_browscap'] = 'DrupalAPCCache';

// Entity cache module
// This will cache items in Database when not pointed to another cache
// There is no way to disable this caching for particular entity, it is 
// all or nothing, erasing the potential little benefit for enabling this 
// module for caching entity_user to increase performance of web services
/*
//$conf['cache_class_cache_entity_comment'] = 'DrupalAPCCache';
//$conf['cache_class_cache_entity_file'] = 'DrupalAPCCache';
//$conf['cache_class_cache_entity_node'] = 'DrupalAPCCache';
//$conf['cache_class_cache_entity_taxonomy_term'] = 'DrupalAPCCache';
//$conf['cache_class_cache_entity_taxonomy_vocabulary'] = 'DrupalAPCCache';
$conf['cache_class_cache_entity_user'] = 'DrupalAPCCache';
*/

//Panels module
$conf['cache_class_cache_panels'] = 'DrupalAPCCache';

// Registration module
//$conf['cache_class_cache_entity_registration'] = 'DrupalAPCCache'; 
//$conf['cache_class_cache_entity_state'] = 'DrupalAPCCache'; 
//$conf['cache_class_cache_entity_type'] = 'DrupalAPCCache'; 

// Rules module
$conf['cache_class_rules'] = 'DrupalAPCCache';

// Token module
$conf['cache_class_cache_token'] = 'DrupalAPCCache';

// View module
$conf['cache_class_cache_views'] = 'DrupalAPCCache';
//$conf['cache_class_cache_views_data'] = 'DrupalAPCCache';

// Default DB for the ones that change too frequently and are small
$conf['cache_default_class']    = 'DrupalDatabaseCache';
// THIS MUST BE SERVED FROM DB FOR STABILITY
$conf['cache_class_cache_form'] = 'DrupalDatabaseCache';
  • 1
    "Drupal core and modules are on NFS server"? Do you mean the PHP code is not on the actual webserver? That would be a red flag for me. – Alfred Armstrong Feb 20 '15 at 17:41
  • Yes, all files are on NFS not on webserver. APC is caching all code with high hit rate, so that helps big time. since apc.stat=1 it still needs to check for any changed files, it known that this can be slow, but I don't see anything related to this in XHprof by searching on lstat , *stat. Is there a good way to find out NFS latency? Also see time-consuming functions in XHprof images, they don't directly scream NFS issue. – amit Feb 20 '15 at 18:42
  • I'd try having the files locally before eliminating this as a cause. file_get_contents() and drupal_parse_info_format() are called during bootstrap to load module data. – Alfred Armstrong Feb 20 '15 at 19:15
1

If using NFS I highly recommend using apc.stat=0 and then if you want to update the apc cache run apc_clear_cache('opcode');.

Seeing how drupal_parse_info_file() is ran on every page load I'm guessing this core patch will help you out: https://www.drupal.org/node/1081266#comment-9411015

Another thing that can help with running code from a NFS drive is this issue: https://www.drupal.org/node/1443308

Also related to potential NFS issues these 2 modules usually help in that situation
https://www.drupal.org/project/imageinfo_cache
https://www.drupal.org/project/advagg

  • Earlier I had debugged the install for missing module and found ATCommerce theme was the culprit and patched So I doubt that patch will make a dent. imagecache_info may be handy for nodes that don't have style generated, but this is not an issue with login page. advagg is more suitable for delivery which is the next step and it did not work for my case, the page generation time is high. Today I also did registry check which was fine. Added new XHprof for a cold start which is even worse. – amit Feb 20 '15 at 21:48
  • New one looks like the vast majority of the time spent with the latest output is time spent in the file system (NFS), use stat=0; the other part is due to the cache miss inside _theme_load_registry(). A cache miss on a cold start is hard to fix; thus at this point I would still be looking at fixing NFS. – mikeytown2 Feb 20 '15 at 21:58
  • Also odds are you will need to increase realpath_cache_size as well. You can check it by comparing realpath_cache_size() to ini_get('realpath_cache_size'). If they are close (I use 10% in APDQC) increase the realpath_cache_size and restart php. Rinse and repeat until they are no longer within 10% of each other. – mikeytown2 Feb 20 '15 at 22:18
  • Sorry it was not a cold start but site access after a silent couple hours. This is problem which is bothering me the most. The realpath_cache_size looks fine I have seen it go unto 350k in previous instance, currently it is 80k – amit Feb 20 '15 at 22:50
0

It seems your top time consuming function is ob_flush() which is called only once, but for 200-500ms.

This call is invoked in drupal_page_footer() as follow:

function drupal_page_footer() {
  // ...

  if (variable_get('cache', 0) && ($cache = drupal_page_set_cache())) {
    drupal_serve_page_from_cache($cache);
  }
  else {
    ob_flush();
  }

So in both of your cases cache doesn't work, either by the 1st load or for the reason that the page was loaded by authenticated user (drupal_page_is_cacheable()). So probably nothing that we can do here.

Function ob_flush() send the contents of the output buffer to the client, and the latency of this transport to the client is probably higher than the actually PHP buffer flushing. See: Why does calling ob_flush() slow down my latency so much?.

Here are few ideas how to improve the load times:

  • enable/disable zlib.output_compression (and see which option is quicker),
  • test for network bottlenecks, if the problem is not with NFS server by checking the load times of simple PHP files (such as update.php or plain php files),
  • if your buffer is flushed too slow, something holds the buffer until the page has finished loading, this can be caused by some Apache modules or client it-self,
    • if it's server fault, review your Apache modules and APC settings (you can use strace to investigate the problem by debugging your Apache process when it handles the request),
    • if it's client fault, test your page by disabling plugins or use different web browser, as well as disable any antivirus softwares (which can hold the buffer until it's checked for web viruses)
  • install XCache instead of APC, set xcache.count to your cpu count something between 4-8 (check sample xcache.ini).
  • 1
    @mikeytown2 Added timing for update.php. All that stuff looks like a check for new files, so nfs is hit pretty hard in this case. zlib.output_compression caused problems with some downloads getting double zipped as we use mod_deflate. Web browser should not be an issue as we just looking XHprof output which is all server side. The database queries are under 100ms so Apache config or NFS are remaining culprits. Will try to set apc.stat=0 to rule out NFS issue. I am also tempted to try apdqc with entity cache, but that has to wait till the basic stuff is resolved. Thank you both – amit Feb 20 '15 at 22:48
  • @amit Based on your update.php, it seems your file operations are very slow. Double check if APC works correctly or you may compare the results with XCache (set xcache.count to your # of CPUs, like 4-8). – kenorb Feb 20 '15 at 23:09
  • 1
    I am using APCcache module to store some extra bins. When I run cache and apc cache tests I get fatal errors with "Class 'Database' not found" so something is misconfigured. I have updated my settings above. Could you take a look. – amit Feb 21 '15 at 4:21
  • 1
    Confirmed that my APC setup is hosed with this test My APC settings indicate Version 3.1.9, MMAP Support Enabled, MMAP File Mask /tmp/apc.a7zvYc, Locking type pthread mutex Locks So it seems like using file based caching not memory. Apparently disabled APC is slightly better in above test. – amit Feb 23 '15 at 23:25
  • @amit Good to know. Try XCache, which I think it should perform better, as apart of file caching, it has a code optimization and you can customize it more. – kenorb Feb 23 '15 at 23:40

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.