ColdFusion on Wheels Blog


Debugging plugin performance in CFWheels 2.x with FusionReactor

The Issue

Shortly after the release of CFWheels 2.0, we started to get reports of slower running requests under certain conditions. For instance, a page which might have had 1000 calls to `linkTo()` could take anything from 1-2ms to 5-6ms a call, which, after 1000 iterations, is one hell of a performance bottle neck. In 1.x, the same call would be between 0-1ms, usually with a total execution time of sub 200ms. 

This behaviour was something which could be proven by a developer, but not everyone was seeing the same results: what was the difference? Plugins (or rather, plugins which override or extend a core function, like linkTo()). To make matters worse, the performance degradation was doubled for each plugin, so you might get 1-2ms for 1 plugin, 2-4 ms for adding another plugin and so on.

So what was causing this?

Enter FusionReactor

We approached FusionReactor, who were kind enough to give us a temporary licence to help debug the issue (it’s great when companies support open-source!). So next up were some tests to help diagnose the issue.

Installing FusionReactor was really simple. As we use CommandBox locally, we could just utilise the existing module via install commandbox-fusionreactor to bootstrap FusionReactor onto our local running servers, which gave us access to the FR instance, already plumbed in. As we were looking for a specific line of code, we also installed the FusionReactor Lucee Plugin and configured it track CFML line execution times using the CF line performance explorer.

This was instantly illuminating, and tracked the problem to our new pluginrunner() method. When we released CFWheels 2.0, there was a fairly heft rewrite of the plugins system. It was designed to be able to allow for plugins to be chained, and execute in a specific order, so you could hypothetically have the result from one plugin overriding the previous one in the chain.

The way it did this was by creating a “stack” of plugins in an array, working out where it was in that stack, and executing the next plugin in the stack till it reached the end. It did that via a combination of callStackGet() and getFunctionCalledName() function to do the comparison.

As you can see from the screenshot below, the line debugger clearly highlights this. This app had four plugins, two of which extended core functions.

Example of FR Lucee 4 Line Debugger

callStackGet() gets invoked 2364 times in this example, but appeared performant, only causing 10ms execution time. getFunctionCalledName() is called the same number of times, but has a total execution time of 2242ms(!). We had our potential culprit. Either way, it was looking like the combination of calling the stack and trying to find the calling function name which was causing so much pain. I suspect it’s to do with how Java deals with this: I think it might be calling a full stack trace and writing it to disk on each call – at least that was the hint from FusionReactor’s thread profiler (I’m sure those who have a better understanding of Java’s underlying functions will chip in).

After some deliberation, we decided to revert this behaviour in CFWheels 2.1 back to how it used to work in 1.x, as the vast majority weren’t using it, but were being affected by it. We’d seen no plugins in the wild which used this behaviour either, which was largely undocumented.

Obviously thanks to FusionReactor for helping us out – hopefully this gives some insight into just one of the ways FusionReactor can be used. Maybe one day I’ll understand Java stack traces – maybe.


CFWheels 2.1.0-beta Now Available

It’s been far too long in the making, but the beta for 2.1 has now arrived! Please do check it out: this should be considered an essential upgrade for anyone on 2.x. A huge thanks to all have contributed!

Make sure to check the “Potenitally Breaking Changes” section below, and please report any bugs.

What’s New:

New GUI

Probably the most obvious change in 2.1 beta is the new internal user interface. Previously, Wheels internal pages like test outputs and routing tables could accidentally be broken by your app, as they extended your Controller.cfc by default. Now, they’re completely isolated, and have been significantly beefed up to show everything that you might want to look at as a developer. 

The new GUI has it’s own dedicated internal routes which can be accessed directly at /wheels/info (assuming you’ve got URL rewriting on) or via the usual links in the debug footer. 

It’s made up of six main sections:

  • General Wheels info – which displays all the settings for your development environment, such as datasources and other core configuration;   
  • a new routing table – which includes a handy route tester as well as a quick search;   
  • improved test outputs so you can more easily access unit tests for your app, core tests if you’re on the master branch, and plugin tests if they’re available;   
  • a new database migration interface, which allows for SQL previews, so you can actually check your migration is going to do what you think it’s going to do before executing;   
  • a more comprehensive documentation output, which includes your own autogenerated application docs as well as the internal wheels function references,   
  • and a better plugins list, showing all the information we know about any installed plugins. 

This GUI is only available in development mode by default, but can be enabled in other modes – this isn’t recommended, but it can be done if you really need to check the configuration or try and track something specific down. You can enable it via set(enablePublicComponent=true) in your environment specific configuration files. 

Improved CORS handling

Next up is some much needed and improved CORS handling. CORS, or Cross-Origin Resource Sharing, will be very familiar to any of you who have a javascript component or fully fledged progressive web app which runs on one domain, but needs to get information from another. A full explanation of CORS is probably beyond the scope of this post, but if you’re thinking of running your own API on a standalone domain where other applications talk to it, you’ll need to be able to handle CORS.

In Wheels 2.0, you could handle CORS requests, but they could only be configured in a very broad way. For instance, the CORS Allow Methods just returned all methods by default in an OPTIONS request, which kinda defeated the whole point.

The CORS Headers –  Access-Control-Allow-Origin, Access-Control-Allow-Methods, Access-Control-Allow-Credentials can now be directly set by their respective functions. 

However, for most people, a new helper configuration, accessControlAllowMethodsByRoute() will be the single most useful function to set: it allows for automatic matching of available methods for a route and sets the CORS Header Access-Control-Allow-Methods automatically; so now when your OPTIONS request hits your wheels app, it will actually respond with the available methods which are allowed for that resource endpoint. This makes it much easier to diagnose why certain requests might not get through, and means javascript libraries such as axios can respond more appropriately to hitting the wrong URL with the wrong HTTP method.

Improvements to mapper()

Redirects can now be put directly in the mapper() routing call, so you can quickly add a simple redirect for a route if you need.

mapFormat can now be set as false, which bypasses the additional ‘.[format]’ routes which were put in by default for each resource. So if you don’t use them, you can now just turn them off, and make your routing table a lot cleaner. This can be set either globally on the mapper() call itself, or on a per resource basis when using resources()

params._json if request is Array

Previously, if you POSTed or PUT/PATCHed json to an endpoint with an array as it’s root element, it would just get ignored, and you’d not be able to access it in the params struct. This has now been changed and if the incoming payload is a json array, it will be available at params._json which matches rails conventions.

New FlashAppend Behaviour

You can now change the default flash behaviour to append to an existing key, rather than directly replacing it. To turn on this behaviour, add set(flashAppend=true) to your /config/settings.cfm file. This allows you to more easily collect flash notifications during a request:
flashInsert(success="One");
flashInsert(success="Two");

Plugin performance

The plugins system has been reverted back to 1.x behaviour, as it was simply non-performant; more on this in a future post.

Full Changelog:

Potentially breaking changes

  • The new CFWheels internal GUI is more isolated and runs in it’s own component: previously this was extending the developers main Controller.cfc which caused multiple issues. The migrator, test runner and routing GUIs have therefore all been re-written.
  • The plugins system behaviour no longer chains multiple functions of the same name as this was a major performance hit. It’s recommended that plugin authors check their plugins to run on 2.1
  • HTTP Verb/Method switching is now no longer allowed via GET requests and must be performed via POST (i.e via _method)

Model Enhancements

  • Migrator now automatically manages the timestamp columns on addRecord() and updateRecord() calls – #852 [Charley Contreras]
  • Migrator correctly honors CFWheels Timestamp configuration settings (setUpdatedAtOnCreate, softDeleteProperty, timeStampMode, timeStampOnCreateProperty, timeStampOnUpdateProperty) – #852 [Charley Contreras]
  • MSSQL now uses NVARCHAR(max) instead of TEXT #896 [Reuben Brown]
  • Allow createdAt and updatedAt to be explicitly assigned using the allowExplicitTimestamps=true argument – #887 – [Adam Chapman]

Controller Enhancements

  • New set(flashAppend=true) option allows for appending of a Flash key instead of replacing – #855 – [Tom King]
  • flashMessages() now checks for an array of strings or just a string and outputs appropriately – #855 – [Tom King]
  • flashInsert() can now accept a one dimensional array – #855 – [Tom King]

Bug Fixes

  • Allow uppercase table names containing reserved substrings like OR and AND – #765 [Dmitry Yakhnov, Adam Chapman]
  • Calculated properties can now override an existing property – #764 [Adam Chapman, Andy Bellenie]
  • Filters are now correctly called if there is more than one after filter – #853 [Brandon Shea, Tom King, Adam Chapman]
  • Minor fix for duplicate debug output in the test suite – #176 [Adam Chapman, Tom King]
  • Convert handle to a valid variable name so it doesn’t break when using dot notation – #846 [Per Djurner]
  • The validatesUniquenessOf() check now handles cases when duplicates already exist – #480 [Randall Meeker, Per Djurner]
  • validatesConfirmationOf() now has a caseSensitive argument to optionally perform a case sensitive comparison – #918 [Tom King]
  • sendFile() no longer expands an already expanded directory on ACF2016 – #873 [David Paul Belanger, Tom King, strubenstein]
  • Automatic database migrations onApplicationStart now correctly reference appropriate Application scope – #870 [Tom King]
  • usesLayout() now can be called more than once and properly respects the order called – #891 [David Paul Belanger]
  • Migrator MSSQL adapter now respects Time and Timestamp Column Types – #906 [Reuben Brown]
  • Automatic migrations fail on application start – #913 [Adam Chapman]
  • Default cacheFileChecking to true in development mode – [Adam Chapman, Steve Harvey]
  • Migrator columnNames list values are now trimmed – #919 [Adam Chapman]
  • Fixes bug when httpRequestData content is a JSON array – #926 [Adam Chapman]
  • When httpRequestData content is a JSON array, contents are now automatically added to params._json – #939 [Tom King]
  • Fixes bug where Migrator $execute() always appends semi-colon – #924 [Adam Chapman]
  • Fixes bug where model createdAt property is changed upon update – #927 [Brandon Shea, Adam Chapman]
  • Fixed silent application.wheels scope exception hampering autoMigrateDatabase – #957 [Adam Chapman, Tom King]

Miscellaneous

  • Added the ability to pass &lock=false in the URL for when reload requests won’t work due to locking – [Per Djurner]
  • Basic 302 redirects now available in mapper via redirect argument for GET/PUT/PATCH/POST/DELETE – #847 – [Tom King]
  • .[format] based routes can now be turned off in resources() and resource() via mapFormat=false – #899 – [Tom King]
  • mapFormat can now be set as a default in mapper() for all child resources() and resource() calls – #899 – [Tom King]
  • HEAD requests are now aliased to GET requests #860 – [Tom King]
  • Added the includeFilters argument to the processRequest function for skipping execution of filters during controller unit tests – [Adam Chapman]
  • Added the useIndex argument to finders for adding table index hints #864 – [Adam Chapman]
  • HTTP Verb/Method switching is now no longer allowed via GET requests and must be performed via POST #886 – [Tom King]
  • CORS Header Access-Control-Allow-Origin can now be set either via a simple value or list in accessControlAllowOrigin() #888 [Tom King]
  • CORS Header Access-Control-Allow-Methods can now be set via accessControlAllowMethods(value) #888 [Tom King]
  • CORS Header Access-Control-Allow-Credentials can now be turned on via accessControlAllowCredentials(true)#888 [Tom King]
  • accessControlAllowMethodsByRoute() now allows for automatic matching of available methods for a route and sets CORS Header Access-Control-Allow-Methods appropriately #888 [Tom King]
  • CORS Header can now be set via accessControlAllowHeaders(value) #888 [Tom King]
  • Performance Improvement: Scanning of Models and Controllers #917 [Adam Chapman]
  • Added the authenticityToken() function for returning the raw CSRF authenticity token #925 [Adam Chapman]
  • Adds enablePublicComponentenableMigratorComponent,enablePluginsComponent environment settings to completely disable those features #926 [Tom King]
  • New CFWheels Internal GUI #931 [Tom King]
  • pluginRunner() now removed in favour of 1.x plugin behaviour for performance purposes #916 [Core Team]
  • Adds validateTestPackageMetaData environment setting for skipping test package validation on large test suites #950 [Adam Chapman]
  • Added aliases for migrator.TableDefinition functions to allow singular variant of the columnNames property #922 [Sébastien FOCK CHOW THO]
  • onAbort is now supported via events/onabort.cfm #962 [Brian Ramsey]

CFWheels 2.0.2 Security Release

Today sees a security release for the 2.x series.

It is strongly recommended to update to CFWheels 2.0.2 if you are running either 2.0.0 or 2.0.1. This issue does not affect 1.x releases. This release introduces a potentially breaking change, so you are encouraged to test your application appropriately before deploying. Thanks to Bryan Welter for bringing it to our attention.

Download 2.0.2

Potential Breaking Changes

  • Blank strings in SQL are no longer converted to null

CFWheels on CF Alive

David Belanger and Tom King from the CFWheels core team chat to host Michaela Light on the CF Alive Podcast! Have a watch/listen and share far and wide…

You can view the original post on the TeraTech website here 


Core Team Updates

Thanks to Per & Chris

Over the past ten years we’ve been very lucky to have some great developers being part of the CFWheels core team. Unfortunately every now and then, we have to let people move on to other things as their jobs or circumstances change, and sadly we’ve had to say goodbye to Per Djurner (@perdjurner) and Chris Peters (@chrisdpeters) recently.

Both have contributed massively to CFWheels over many years: I think there are a lot of people who can blame Chris for his original series of screencasts getting them hooked (myself included!) on Wheels, and I’d wager that every CFWheels user has benefited from Per’s knowledge and guidance; both of them will be missed – a huge thank you to both of them.

Welcome to David & Andy

We’re pleased to announce that David Belanger (Github/dbelanger) and Andy Bellenie (Github/andybellenie) have agreed to join the Core team. Andy used to be on the team a few years ago, and brings lots of years of CFWheels experience with him. David joins us from Argentina (and occasionally Canada), making us a highly international group, with Tom & Andy in the UK and Adam over in Australia (unfortunately, with very few timezone crossovers!). It’s fantastic to have them on-board.

Up Next

Our next milestone is finishing up a 2.1 release: Please check the 2.1 Milestone to hear about upcoming features such as improved CORS headers, and also check the Changelog for all the bug fixes and improvements already implemented since 2.0.1. 


Screencast: Introduction to Unit Testing in CFWheels 2.x

Update: (2nd part on controllers)


Creating a mega quick JSON API in CFWheels 2.x


Screencast: Routing in CFWheels 2.x – part 2

Covers constraints, wildcard segments and shallow resources.


Screencast: Routing in CFWheels 2.x

A quick  overview of routing in Wheels 2.x

 


Screencast: Basic CRUD interface in CFWheels 2.x