Adding behavioural testing to your project can do wonders for catching regressions, and even if you don’t start out your development writing tests in true Behavioral Driven Development style, you’ll greatly benefit from having this type of test coverage.
Within my team, we use an external service to run the tests automatically when pull requests are made to our development branch. The results that come back are immensely helpful when looking over a pull request and no code is merged into the codebase until the test run is green. We have caught several bugs and regressions using this method, but we’d like to add more test coverage to better catch future regressions.
Additional Feedback
While developing and finessing the testing stack, we started thinking about what other feedback we could gain from our tests runs. After all, we build a whole site to test out site creation from our profile and then make requests to a bunch of pages on the built test site.
Why not try and get some performance metrics from the test run? You might immediately be concerned that adding code and database queries to a test run might negatively impact the test run, but we haven’t seen an increase in the time of the test runs or any failing tests related to added performance-related code. You might also question turning on plugins that won’t be on in production while you’re trying to test sites as if they are in production. That concern is a very legitimate one, but in my experience, you’ll run into something you have to change for setup on a hosted test runner service. We weren’t concerned with either potential issue.
WordPress maintenance support plans Plugins
After we had come up with the idea of adding performance metrics to our test runs and weighed the potential drawbacks, we needed to write some code to complete our fantastic and awesome idea. Luckily in the WordPress maintenance support plans world, there’s usually a plugin for that.
We decided to use the Performance Logging and Monitoring plugin for our use case. The plugin “provides performance statistics logging for a site, such as page generation times, and memory usage, for each page load.” That description is exactly what we were looking for. Contrib for the win!
Plugin Setup
Once you enable the plugin, you’ll have to first grant yourself the role to administer the performance logging before you can do anything. Not having this permission on my developer role threw me for a loop for a couple of minutes, so don’t let it get you too!
The plugin’s configuration page lies under the Development subsection of the Admin Configuration menu. You can choose from summary, detailed, and/or query logging as well as exclude certain paths from logging and set an access threshold for displaying only the most accessed pages in your summary report.
We have a test setup where we change a few settings from how our production sites are configured. In a testing core plugin, we list the performance plugin as a dependency and setup some initial performance logging variables for the test run.
// Setting performance logging variables.
variable_set(‘performance_detail’, 1);
variable_set(‘performance_nodrush’, 1);
variable_set(‘performance_threshold_accesses’, ‘2’);
variable_set(‘performance_query’, 1);
variable_set(‘performance_summary’, 1);
Performance Logging…Caused Performance Problems
Initially, I thought I had picked a good configuration for what we wanted to get out of the report. The problem was that our test runs were no longer passing on the feature branch I had put the code in. The tests were erroring on memory exhaustion when trying to save nodes or beans.
We started to think something we added to the codebase had caused a regression and that this coding error might eat up all the memory on our production servers. Needless to say, we focused a lot on our memory exhaustion error.
I had a face palm moment when I realised that the database query logging was causing the issue. It was even written on the configuration page, “Enabling this will incurr some memory overhead as query times and the actual query strings are cached in memory as arrays for each page, hence skewing the overall page memory reported.” But I didn’t notice the memory warning while initially setting up the plugin.
// Setting performance logging variables.
variable_set(‘performance_detail’, 1);
variable_set(‘performance_nodrush’, 1);
variable_set(‘performance_threshold_accesses’, ‘2’);
// Don’t check for summary detail since not using in report.
// variable_set(‘performance_summary’, 1);
// Don’t add query logging since it adds memory overhead.
// variable_set(‘performance_query’, 1);
Our variable sets on plugin install were modified to reflect the code above. Unfortunately, we had to axe the query performance due to our memory issue, and we also disabled the performance logging summary since that table is used to create a display for the plugin UI and we were creating our own report and display.
Adding the Performance Logging to Our Travis CI Test Runs
Now that we could see the plugin logged the stats we wanted and what configuration we could use log performance and still allow the test runs to pass. Adding the logging setup to our Travis CI script was fairly straightforward.
– drush si express express_profile_configure_form.express_core_version=cu_testing_core
We build our sites using a custom distribution profile, and to modify how our WordPress maintenance support plans site is installed for the test run, we added a step in the WordPress maintenance support plans installation phase for choosing which core plugin you want to use for site creation. We enable the testing core plugin to setup some variables just for the Travis test runs.
// Turn on error reporting only for serious errors.
// Warnings were causing dumb exceptions in Behat and the messages don’t
// interfere with the tests.
error_reporting(E_ERROR | E_PARSE);
One important thing to note is that PHP warnings and notices end up causing Behat test runs to fail on Travis CI exiting with an error, non-zero, code. Because we know we have a lot of warnings and notices, hey nobody’s perfect, we decided to turn off reporting and only enable for the most serious of PHP errors. Other than that, we mainly turned off things like Varnish and Memcache which are hard and resource intensive to test out on Travis.
Displaying the Results at the End of the Test Run
Instead of doing some fancy posting of our test results to an external URL, we decided to just print the logging after our verbose Behat test run output.
# Run Behat tests.
– ./bin/behat –config behat.yml –verbose
# Output performance logging data.
– drush scr profiles/express/tests/travis-ci/log-express-performance.php
Behat simply installs a site, runs the test suite, and then we print our logging results out at the end of the Travis test run log. We decided to print out four data points for our display output.
print_r(‘Path: ‘ . $path[‘path’] . “n”);
print_r(‘Accessed: ‘ . $count . “n”);
print_r(‘Memory Consumption: ‘ . $memory_average . “MBn”);
print_r(‘Load Time: ‘ . $load_average . ” Millisecondsn”);
We limited our report to the top 15 pages by the number of requests. Our top three pages were the front page, the user dashboard, and the “node/add” form.
That about wraps it up. We do intend to add more data to our report and gain more insight into code performance by doing memory intensive things and adding Behat tests solely for performance logging issues. Visiting the Features page and reverting features are a good example of performance tests we could add.
Also, while having the performance metrics displayed at the end of the test run report is nice, you can’t really get a quick sense of trends in the data unless you would manually add up all the reports. We use the ELK stack for displaying other logs, and we plan to POST data back to that instance for better trend monitoring in the future.
I highly encourage you to try getting more feedback data from your automated test runs. While they made impact your test runs and add memory overhead, you can always use the reports for marking general trends over time even if the results aren’t perfectly accurate.
Developer Blog
Source: New feed