Posted by Charlie
Thu, 13 Nov 2008 18:11:00 GMT
Last year I wrote about how to profile your Rails application, which is a lot harder then it seems. Its not so much the profiling itself - its easy enough to create one-off results. Instead, its coming up with a reproducible process that lets you measure performance changes over time.
Some things that don't work over the long term:
- Insert profiling code into your application code
- Use unit tests for profiling
- Use functional tests for profiling
- Use integration tests for profiling
- Modify standard rails environments (test, development, production for profiling)
So the latest version of ruby-prof introduces a new approach to profiling your Ruby or Rails code that is heavily based on the excellent work Jeremy has done on the request profiler included in newer versions of Rails.
The basic idea is to extend Ruby's TestUnit library so that individual test cases are profiled by including a new RubyProf::Test module. When you include this module, ruby-prof will run each test once as a warm up and then ten more times to gather profiling data (using another new feature of the 0.7.0 release, the ability to pause and resume a profiling run). Profile data is then output for each test.
Let's look at an example:
class ExampleTest < Test::Unit::TestCase
include RubyProf::Test
def test_stuff
puts "Test method"
end
end
The line include RubyProf::Test turns the test case into a profiling test case. The same approach could be used for hooking into other testing frameworks - all patches are of course welcome!
Using a Profile Environment for Rails
Now lets talk about profiling Rails. There are two main issues that make it harder then it seems.
First, to get any useful data you need to profile a Rails app using the production environment settings in conjunction with a test database. Using the development environment doesn't work because the time it takes Rails to reload classes on each request drowns out any useful information.
Second, how should profile tests be written and where should they go?
The solution I've adopted is to use functional like-tests that use a PROFILE environment, and place them in a directory called test/profile.
Let's look at another example:
require File.dirname(__FILE__) + '/../profile_test_helper'
class MyControllerTest < Test::Unit::TestCase
include RubyProf::Test
fixtures :my_fixture
def setup
@controller = MyController.new
@request = ActionController::TestRequest.new
@response = ActionController::TestResponse.new
end
def test_get
get(:index)
end
end
The only difference between a functional test and a profile test are the inclusion of the RubyProf::Test module and loading profile_test_helper.rb. profile_test_helper is unfortunately needed because the standard test_helper.rb file Rails uses loads the TEST environment. Hopefully future versions of Rails will fix this by allowing greater flexibility in specifying a test environment.
So to get started with profiling your Rails application:
- Copy profile_test_helper.rb from the ruby-prof distribution to your rails test directory
- Modify profile_test_helper.rb as needed to set ruby-prof's output directory
- Create a profile.rb file in the environments directory
- Update your databases.yml file to include a profile database (just map it to your test database)
- Create a new directory test/profile
- Start writing profiling tests that look similar to the above example
And now you'll have reproducible profiling tests cases.
So what's missing? A way of keeping track of how your applications performance changes over time. A quick hack is to use source control to keep profile tests results around. A more sophisticated solution would be to use ruby-prof's API to dump profile results into a database and then put a nice web front end onto it. Any takers?
Posted in ruby-prof | no comments | no trackbacks
Posted by Charlie
Wed, 12 Nov 2008 16:41:00 GMT
I'm happy to announce the release of ruby-prof 0.7.0, the superfast, open-source, Ruby profiler that helps you find bottlenecks in your Ruby code. This release was a joint effort, with major contributions from Jeremy Kemper (aka bitsweat) of Rails fame and Hin Boen from CodeGear. There are two major new features in this release, as well as a number of smaller enhancements and bug fixes. For a full list of changes, take a look at the release notes.
The first major new feature is improved Rails profiling, which I'll talk about in a separate post.
The second major feature is significant internal changes that make it easier to integrate ruby-prof with IDEs. ruby-prof is already being used by Aptana's RadRails and has been integrated into the next version of Code Gear's 3rd Rail. As part of this work, Hin has built a user interface for ruby-prof that lets a user inspect individual methods to see how much time they took as well as how they were called.
One big problem though, previous versions of ruby-prof only kept track of aggregate data. This made it impossible for Hin to create the user interface he wanted. For example, look at this call sequence:
A
/ \
B K
/ \ \
C D B
/ \
C D
With earlier versions of ruby-prof, there was no way to tell what percent of the time spent in method C was a result of the A -> B -> C call sequence versus the A -> K -> B -> C call sequence.
Or take another example:
A K
| |
B B
| |
C D
In this case, if you tried to reconstruct the call sequence from ruby-prof you would end up with this incorrect result:
A K
| /
B
/ \
C D
So working with Hin, I rearchitected ruby-prof to keep track of full call sequences. Most likely you won't notice any difference - the changes will only affect you if you use ruby-prof's api to present results in a custom way. In that case, you'll have to update your code, which should only take a few minutes (to see the api in use, take a look at the various printer classes that ship with ruby-prof).
Enjoy, and all feedback is welcome.
Posted in ruby-prof | 3 comments | no trackbacks
Posted by Charlie
Tue, 11 Nov 2008 18:15:00 GMT
No doubt this post is two weeks past its prime, but better late than never, right? On Sunday, October 26th, Yue and I headed downtown to check out Barak Obama's campaign rally at Civic Center park in the heart of Denver.
By the time we arrived the place was packed. In fact, it turned out that over 100,000 of our closest friends were there, making it Obama's largest crowd in the United States up to that point. And I think the second largest crowed I've ever been in, surpassed only by watching fireworks on the 4th of July from the National Mall in Washington, DC).
Wanting to at least be able to see Obama, we managed to be the last two people allowed into the center of the park (versus around the periphery). Once inside, we squirreled our way about half way to the stage. As you can see in the pictures, that wasn't all that close, but close enough to catch a glimpse of Obama. The first picture is looking west towards Denver's City hall. If you're interested, click the picture to get a bigger version, then find the tree in the center of the stage under the Colorado flag, and look right 3.5 columns to see Obama working the crowd:
]
And here's the view looking back east, back towards the Colorado State Capital (supposedly Denver is the only city where the city hall faces the state Capital building, but I've never verified if that's true).
For the most part Obama stuck to his standard stump speech, but what struck me was its optimism and focus on working together. Nice words no doubt, but it was a nice change of pace from typical campaign bashing.
On the way out, there was a table for all the poor souls who lost their keys and cell phones that day:
And a couple pictures of Yue for good measure, that show what a beautiful day it was:
Update: If you can't see Obama, check out Paul's post. Paul also points out the snipers that are visible on top of City Hall. And they weren't the only ones, there were plenty more to the north where Denver's taller buildings are located.
no comments | no trackbacks
Posted by Charlie
Tue, 11 Nov 2008 03:24:00 GMT
Rafting down the Grand Canyon has been on my todo list for a long time. Over the years, I've rafted or canoed the James, Potomac, Rappahannock, Shenandoah, Arkansas, Taylor (well that's mostly a creek), Green and Colorado rivers. But never the Grand Canyon.
So this summer it was time. Seven of us - Haydon, Dave, Natasha, Brian, Lauren, Yue and myself - took the plunge and paddled down the upper part of the Grand Canyon from Marble Canyon to the Bright Angel Trail. We went with Outdoors Unlimited, which I highly recommend. They not only provided equipment, but also knowledgeable guides and great food.
Here's all of us by a grotto a few hundred feet above the Colorado River (from left to right is Dave, Haydon, Yue, myself, Brian, Natasha and Lauren - click the picture for a bigger version):
There are several different types of trips you can take down the canyon - we opted for a paddle trip. A paddle trip is just like it sounds - you get to paddle your way down the canyon using yellow, rubber boats, with six people per boat plus a guide. Depending on how much you like thrills, the best seats in the boat are the front two, where you get really wet from waves breaking over the bow when you hit a big rapid.
Yue, who isn't much of a camper, was a good sport about the whole thing once she discovered she could sleep in a tent versus sleeping under the stars. Here is our campground ffrom the third night, with yours truly sleeping outside:
It took five days and ninety five miles to get to our drop-off point - the deepest part of the canyon at the bottom of the Bright Angel Trail.. From there its an eight mile hike, and 4,380 feet up, to get to the visitor center on the South Rim. I had hiked the very top bit of the trail twenty years ago, but hadn't been back since.
Its an absolutely beautiful trail, surprisingly cool on the bottom half (well, we did start at 7am) as it climbs up along a small creek. Here is what it looks like once you've hiked about two miles and reached the top of the inner gorge - the picture is looking south with the Great Unconformity in the foreground and the towering south wall in the background:
Dave took the prize, hiking up in an amazing time of 2:45, followed by Lauren and Natasha at 3:15, and the rest of us at 3:45 (which by the way I was quite proud of).
Here the obligatory picture from the top:
And here's Lauren, Natasha, Haydon and Brian a enjoying some well-deserved ice cream.
And some of our better pictures:
&
2 comments | no trackbacks
