Knows which specs are slowing down my spec suite

December 06, 2008

I often watch my specs run with the ........'s marching across my terminal and sometimes it seems to pause as it hits a particularly slow one. I figure there's some poorly written spec that's slowing my entire suite down and I should figure out what it is and fix it. But I rarely (if ever) take the time to track down the offender so never fix it. I just discovered that the clever folks writing rspec have taken away my excuse for laziness. I can tell it to report on the slowest specs by putting a line in my spec.opts file telling it to use the ProfileFormatter (see the first line below)

--format profile
--loadby mtime

For example running the specs on my current project I get this output.

Profiling enabled.
........(a bunch more dots)

Top 10 slowest examples:
2.4908950 WikiContent should find all activity for a user
0.8061750 WikiContent should find recent activity for a user in last 15 days
0.2438460 WikiContent::Version should allow limit on results from finding recent activity
0.1821710 User should have a list of owned content
0.1700670 WikiContent should find results if access type is not same as role of the user but role of user is 'Leader'
0.1593900 ContentsController allows PUT request to 'update' action for 'member' role
0.1514150 Search::SearchResponse gets the wiki content id of an asset from the xml response
0.1470310 Content should always allow leaders to see all pages
0.1394920 Page should delete all comments when destroyed
0.1370330 ContentsController should save content and create the uploaded asset on successful POST to the 'create' action

Over the next few days I will find time to take a look at 'WikiContent find all activity' and 'WikiContent find recent activity' specs as they are the two clear outliers.

I now have no excuse to not optimize my slowest specs because I didn't know which they were!