{"id":226,"date":"2019-06-18T09:02:28","date_gmt":"2019-06-18T09:02:28","guid":{"rendered":"http:\/\/www.ebi.ac.uk\/about\/teams\/its-web-development\/?p=226"},"modified":"2022-06-25T20:16:30","modified_gmt":"2022-06-25T20:16:30","slug":"diagnosing-and-preventing-performance-problems-on-a-drupal-website","status":"publish","type":"post","link":"https:\/\/www.ebi.ac.uk\/about\/teams\/its-web-development\/2019\/06\/diagnosing-and-preventing-performance-problems-on-a-drupal-website\/","title":{"rendered":"Diagnosing and preventing performance problems on a Drupal website"},"content":{"rendered":"\n

Last week we noticed a problem after deploying a new version of the EMBL-EBI homepage<\/a>.  The links to the upcoming events were taking a long time to load.  A really, really, long time.  It wasn\u2019t that the page was taking a long time to render, but the initial delivery of the HTML page was taking over 10 seconds when it wasn\u2019t hitting the cache.  That was obviously much longer than acceptable!  Time to investigate this performance problem.<\/p>\n\n\n\n

The immediate investigation and workarounds<\/h3>\n\n\n\n
\"\"
Graph\n showing the slowest page response times on the EBI public information \nand training websites. Dot size shows the relative popularity of pages.<\/figcaption><\/figure>\n\n\n\n

First we validated that this wasn\u2019t a one off.  Using the \nElasticsearch, Logstash, Kibana (ELK) stack that runs over the EMBL-EBI \nweb logs provided by the Web Production team we were able to validate \nthat several pages were taking an incredibly long time to load. \n Specifically it was events and course pages.  This gave us a clue as to\n where this issue was.<\/p>\n\n\n\n

Our public information site, e.g. the informational areas of the site\n rather than the scientific service applications uses Drupal.  It was \nthe initial HTML page response that was slow suggesting something in \nDrupal was the culprit.<\/p>\n\n\n\n

This gave us an opportunity to apply a couple of immediate \u2018band-aid\u2019\n mitigations.  Firstly increasing the caching time, and secondly warming\n this cache for the next 6 events that were linked from the homepage. \n This reduced the impact of this issue, but did have a knock on impact \nfor those producing content, as they would now have longer waits before \nchanges to pages would be public as the caches cleared over hours.  We \nlet the content editors know about these temporary measures, and then \nstarted to investigate the route cause.<\/p>\n\n\n\n

\"\"
Average\n page load times for an upcoming event were significantly reduced after \nincreases to caches and \u2018cache warming\u2019 for our top events. You can see \nan unfortunate side effect of the cache warming, the large dots signify a\n large number of loads of these pages, skewing our server side \nstatistics unless these are filtered out.<\/figcaption><\/figure>\n\n\n\n

Resolving the issue<\/h3>\n\n\n\n

We create these event pages by feeding information from our Content \nDatabase (a headless Drupal instance) into our public facing Drupal \ninstance using an XML feed.  The public instance then uses a series of \nviews to render the page based on these XML files.  We\u2019d chosen at the \ntime of implementation to use a single feed containing all events, a \nchoice acknowledged at the time was not going to be scalable forever. \nOver time, and with the rate EMBL-EBI hold events this XML file had \ngrown to contain many 100s of events. One of our intrepid developers \nwalked the code and confirmed that we were loading a 18MB XML file 16 \ntimes for every page load!  Suspect identified.  After making a couple \nof tests locally using smaller XML files we\u2019d found our route cause.<\/p>\n\n\n\n

The first change we made was to alter the rendering of these pages to\n reduce the number of Drupal blocks involved in these views. That \nreduced the number of times each page load had to read these files. \n Ideally that number should be once, but that will take some more \nrearchitecting and will need to wait until we\u2019re out of the woods for \nthis issue.<\/p>\n\n\n\n

The second change was to rearchitect this system to use one small XML\n file per event page, rather than one giant file used for all events. \n This change made a massive reduction to page load time in development. \n Some more testing and then this change was deployed and monitored.<\/p>\n\n\n\n

\"\"
The deployment at 12:30 brought in a reduction from ~8 seconds to 3 seconds for uncached loads of a seminar event page.<\/figcaption><\/figure>\n\n\n\n

Learning and prevention for the future<\/h3>\n\n\n\n

We\u2019ve learnt more about our Drupal system, the diagnostic tools \navailable for us to use in our environments, and identified an \narchitectural pattern that we should avoid going forward as it doesn\u2019t \nscale.  We\u2019re continuing to evolve our Content Database, and this is \nuseful feedback input to future development.<\/p>\n\n\n\n

We\u2019ve also started to continually track and monitor the page loading \ntimes for key pages.  This will let us see if changes we make, or \nchanges based on the volume of content are having an impact on these key\n metrics.  We\u2019re now capturing these load times in a Graphite\/Graphana \ninstance, and get alerted if they creep over a threshold.<\/p>\n\n\n\n

\"\"
Uncached response times for different types of pages on the EMBL-EBI website. Shown in a Grafana dashboard<\/figcaption><\/figure>\n\n\n\n

Update: 28(ish) days later<\/h3>\n\n\n\n

The act of measuring this metric made us focus more on performance. \nWe\u2019d resolved an acute issue in the initial investigation, but we were \nstill unsure about why some of these relatively simple pages were taking\n so long for Drupal to generate. Especially as we run a number of Drupal\n sites and could see must faster response times for other sites of \nsimilar complexity.<\/p>\n\n\n\n

Using the Xhprof<\/a>\n performance profiling tool for PHP we investigated where time was being\n spent and identified a Drupal module (that we were no longer using) \nthat was very inefficient and being called on every page load.  Removing\n this module made a signifiant improvement to all page response times.<\/p>\n\n\n\n

\"Chart
After removing the rogue module a significant drop in page response time can be seen.<\/figcaption><\/figure>\n","protected":false},"excerpt":{"rendered":"

Last week we noticed a problem after deploying a new version of the EMBL-EBI homepage.  The links to the upcoming events were taking a long time to load.  A really, really, long time.  It wasn\u2019t that the page was taking a long time to render, but the initial delivery of the HTML…<\/p>\n","protected":false},"author":1,"featured_media":1787,"comment_status":"closed","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"_acf_changed":false,"footnotes":""},"categories":[1],"tags":[],"embl_taxonomy":[],"class_list":["post-226","post","type-post","status-publish","format-standard","has-post-thumbnail","hentry","category-general"],"acf":[],"embl_taxonomy_terms":[],"featured_image_src":"https:\/\/www.ebi.ac.uk\/about\/teams\/its-web-development\/wp-content\/uploads\/2019\/06\/images.png","_links":{"self":[{"href":"https:\/\/www.ebi.ac.uk\/about\/teams\/its-web-development\/wp-json\/wp\/v2\/posts\/226","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/www.ebi.ac.uk\/about\/teams\/its-web-development\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/www.ebi.ac.uk\/about\/teams\/its-web-development\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/www.ebi.ac.uk\/about\/teams\/its-web-development\/wp-json\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/www.ebi.ac.uk\/about\/teams\/its-web-development\/wp-json\/wp\/v2\/comments?post=226"}],"version-history":[{"count":3,"href":"https:\/\/www.ebi.ac.uk\/about\/teams\/its-web-development\/wp-json\/wp\/v2\/posts\/226\/revisions"}],"predecessor-version":[{"id":3444,"href":"https:\/\/www.ebi.ac.uk\/about\/teams\/its-web-development\/wp-json\/wp\/v2\/posts\/226\/revisions\/3444"}],"wp:featuredmedia":[{"embeddable":true,"href":"https:\/\/www.ebi.ac.uk\/about\/teams\/its-web-development\/wp-json\/wp\/v2\/media\/1787"}],"wp:attachment":[{"href":"https:\/\/www.ebi.ac.uk\/about\/teams\/its-web-development\/wp-json\/wp\/v2\/media?parent=226"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/www.ebi.ac.uk\/about\/teams\/its-web-development\/wp-json\/wp\/v2\/categories?post=226"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/www.ebi.ac.uk\/about\/teams\/its-web-development\/wp-json\/wp\/v2\/tags?post=226"},{"taxonomy":"embl_taxonomy","embeddable":true,"href":"https:\/\/www.ebi.ac.uk\/about\/teams\/its-web-development\/wp-json\/wp\/v2\/embl_taxonomy?post=226"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}