The Devver Blog

A Boulder startup improving the way developers work.

Archive for October 2009

Improving Code using Metric_fu

Often, when people see code metrics they think, “that is interesting, I don’t know what to do with it.” I think metrics are great, but when you can really use them to improve your project’s code, that makes them even more valuable. metric_fu provides a bunch of great metric information, which can be very useful. But if you don’t know what parts of it are actionable it’s merely interesting instead of useful.

One thing when looking at code metrics to keep in mind is that a single metric may not be as interesting. If you look at a metric trends over time it might help give you more meaningful information. Showing this trending information is one of our goals with Caliper. Metrics can be your friend watching over the project and like having a second set of eyes on how the code is progressing, alerting you to problem areas before they get out of control. Working with code over time, it can be hard to keep everything in your head (I know I can’t). As the size of the code base increases it can be difficult to keep track of all the places where duplication or complexity is building up in the code. Addressing the problem areas as they are revealed by code metrics can keep them from getting out of hand, making future additions to the code easier.

I want to show how metrics can drive changes and improve the code base by working on a real project. I figured there was no better place to look than pointing metric_fu at our own devver.net website source and fixing up some of the most notable problem areas. We have had our backend code under metric_fu for awhile, but hadn’t been following the metrics on our Merb code. This, along with some spiked features that ended up turning into Caliper, led to some areas getting a little out of control.

Flay Score before cleanup

When going through metric_fu the first thing I wanted to start to work on was making the code a bit more DRY. The team and I were starting to notice a bit more duplication in the code than we liked. I brought up the Flay results for code duplication and found that four databases models shared some of the same methods.

Flay highlighted the duplication. Since we are planning on making some changes to how we handle timestamps soon, it seemed like a good place to start cleaning up. Below are the methods that existed in all four models. A third method ‘update_time’ existed in two of the four models.

 def self.pad_num(number, max_digits = 15)
    "%%0%di" % max_digits % number.to_i
  end

  def get_time
      Time.at(self.time.to_i)
  end

Nearly all of our DB tables store time in a way that can be sorted with SimpleDB queries. We wanted to change our time to be stored as UTC in the ISO 8601 format. Before changing to the ISO format, it was easy to pull these methods into a helper module and include it in all the database models.

module TimeHelper

  module ClassMethods
    def pad_num(number, max_digits = 15)
      "%%0%di" % max_digits % number.to_i
    end
  end

  def get_time
      Time.at(self.time.to_i)
  end

  def update_time
    self.time = self.class.pad_num(Time.now.to_i)
  end

end

Besides reducing the duplication across the DB models, it also made it much easier to include another time method update_time, which was in two of the DB models. This consolidated all the DB time logic into one file, so changing the time format to UTC ISO 8601 will be a snap. While this is a trivial example of a obvious refactoring it is easy to see how helper methods can often end up duplicated across classes. Flay can come in really handy at pointing out duplication that over time that can occur.

Flog gives a score showing how complex the measured code is. The higher the score the greater the complexity. The more complex code is the harder it is to read and it likely contains higher defect density. After removing some duplication from the DB models I found our worst database model based on Flog scores was our MetricsData model. It included an incredibly bad high flog score of 149 for a single method.

File Total score Methods Average score Highest score
/lib/sdb/metrics_data.rb 327 12 27 149

The method in question was extract_data_from_yaml, and after a little refactoring it was easy to make extract_data_from_yaml drop from a score of 149 to a series of smaller methods with the largest score being extract_flog_data! (33.6). The method was doing too much work and was frequently being changed. The method was extracting the data from 6 different metric tools and creating summary of the data.

The method went from a sprawling 42 lines of code to a cleaner and smaller method of 10 lines and a collection of helper methods that look something like the below code:

  def self.extract_data_from_yaml(yml_metrics_data)
    metrics_data = Hash.new {|hash, key| hash[key] = {}}
    extract_flog_data!(metrics_data, yml_metrics_data)
    extract_flay_data!(metrics_data, yml_metrics_data)
    extract_reek_data!(metrics_data, yml_metrics_data)
    extract_roodi_data!(metrics_data, yml_metrics_data)
    extract_saikuro_data!(metrics_data, yml_metrics_data)
    extract_churn_data!(metrics_data, yml_metrics_data)
    metrics_data
  end

  def self.extract_flog_data!(metrics_data, yml_metrics_data)
    metrics_data[:flog][:description] = 'measures code complexity'
    metrics_data[:flog]["average method score"] = Devver::Maybe(yml_metrics_data)[:flog][:average].value(N_A)
    metrics_data[:flog]["total score"]   = Devver::Maybe(yml_metrics_data)[:flog][:total].value(N_A)
    metrics_data[:flog]["worst file"] = Devver::Maybe(yml_metrics_data)[:flog][:pages].first[:path].fmap {|x| Pathname.new(x)}.value(N_A)
  end

Churn gives you an idea of files that might be in need of a refactoring. Often if a file is changing a lot it means that the code is doing too much, and would be more stable and reliable if broken up into smaller components. Looking through our churn results, it looks like we might need another layout to accommodate some of the different styles on the site. Another thing that jumps out is that both the TestStats and Caliper controller have fairly high churn. The Caliper controller has been growing fairly large as it has been doing double duty for user facing features and admin features, which should be split up. TestStats is admin controller code that also has been growing in size and should be split up into more isolated cases.

churn results

Churn gave me an idea of where might be worth focusing my effort. Diving in to the other metrics made it clear that the Caliper controller needed some attention.

The Flog, Reek, and Roodi Scores for Caliper Controller:

File Total score Methods Average score Highest score
/app/controllers/caliper.rb 214 14 15 42

reek before cleanup

Roodi Report
app/controllers/caliper.rb:34 - Method name "index" has a cyclomatic complexity is 14.  It should be 8 or less.
app/controllers/caliper.rb:38 - Rescue block should not be empty.
app/controllers/caliper.rb:51 - Rescue block should not be empty.
app/controllers/caliper.rb:77 - Rescue block should not be empty.
app/controllers/caliper.rb:113 - Rescue block should not be empty.
app/controllers/caliper.rb:149 - Rescue block should not be empty.
app/controllers/caliper.rb:34 - Method name "index" has 36 lines.  It should have 20 or less.

Found 7 errors.

Roodi and Reek both tell you about design and readability problems in your code. The screenshot of our Reek ‘code smells’ in the Caliper controller should show how it had gotten out of hand. The code smells filled an entire browser page! Roodi similarly had many complaints about the Caliper controller. Flog was also showing the file was getting a bit more complex than it should be. After picking off some of the worst Roodi and Reek complaints and splitting up methods with high Flog scores, the code had become easily readable and understandable at a glance. In fact I nearly cut the Reek complaints in half for the controller.

Reek after cleanup

Refactoring one controller, which had been quickly hacked together and growing out of control, brought it from a dizzying 203 LOC to 138 LOC. The metrics drove me to refactor long methods (52 LOC => 3 methods the largest being 23 LOC), rename unclear variable names (s => stat, p => project), move some helpers methods out of the controller into the helper class where they belong. Yes, all these refactorings and good code designs can be done without metrics, but it can be easy to overlook bad code smells when they start small, metrics can give you an early warning that a section of code is becoming unmanageable and likely prone to higher defect rates. The smaller file was a huge improvement in terms of cyclomatic complexity, LOC, code duplication, and more importantly, readability.

Obviously I think code metrics are cool, and that your projects can be improved by paying attention to them as part of the development lifecycle. I wrote about metric_fu so that anyone can try these metrics out on their projects. I think metric_fu is awesome, and my interest in Ruby tools is part of what drove us to build Caliper, which is really the easiest way try out metrics for your project. Currently, you can think of it as hosted metric_fu, but we are hoping to go even further and make the metrics clearly actionable to users.

In the end, yep, this is a bit of a plug for a product I helped build, but it is really because I think code metrics can be a great tool to help anyone with their development. So submit your repo in and give Caliper hosted Ruby metrics a shot. We are trying to make metrics more actionable and useful for all Ruby developers out, so we would love to here from you with any ideas about how to improve Caliper, please contact us.

Advertisements

Written by DanM

October 27, 2009 at 10:30 pm

Beware of pipe duplication in subprocesses

I’ve been writing a lot lately about managing subprocesses in Ruby, and in that vein I thought I’d write up an interesting subprocess gotcha we encountered recently.

I won’t go into the details of how we discovered the issue, except to say that it manifested when using the Main and Servolux gems (both of which I highly recommend) together to start daemon processes. The problem can be boiled down to this brief snippet, distilled by Tim Pease:

ruby -e 'IO.popen("ruby -e \"STDOUT.dup; STDOUT.close; sleep\"").read

If you try to execute that line, the #read will hang indefinitely, even though STDOUT was closed in the child process. Why? Tim explains:

“…the parent script will block waiting for pipe to close in the child process. However, because there is a duplicate of the STDOUT file descriptor in the child, both must be closed or the parent will never unblock from the read. […] ALL file descriptors have to be closed before an EOF is sent through the pipe to the parent. Hence, the read will never return.”

The moral of this story: don’t try to read from a subprocess which duplicates STDOUT or STDERR handles. Or if you do, take precautions by using calls which don’t wait for an EOF – such as #readpartial – instead of #read.

I can take no credit for solving this one. All the honor goes to Ara T. Howard, who expended much mental energy and beer to get to the bottom of the problem; and Tim Pease, who neatly summarised the issue and explained it in terms that even I could understand. I’m documenting it here in case anyone else runs into it.

Written by avdi

October 22, 2009 at 6:00 am

A Dozen (or so) Ways to Start Subprocesses in Ruby: Part 3

In part 1 and part 2 of this series, we took a look at some of Ruby’s built-in ways to start subprocesses. In this article we’ll branch out a bit, and examine some of the tools available to us in Ruby’s Standard Library. In the process, we’ll demonstrate some lesser-known libraries.

Helpers

First, though, let’s recap some of our boilerplate code. Here’s the preamble code which is common to all of the demonstrations in this article:

require 'rbconfig'

$stdout.sync = true

def hello(source, expect_input)
  puts "[child] Hello from #{source}"
  if expect_input
    puts "[child] Standard input contains: \"#{$stdin.readline.chomp}\""
  else
    puts "[child] No stdin, or stdin is same as parent's"
  end
  $stderr.puts "[child] Hello, standard error"
  puts "[child] DONE"
end

THIS_FILE = File.expand_path(__FILE__)

RUBY = File.join(Config::CONFIG['bindir'], Config::CONFIG['ruby_install_name'])

#hello is the method which we will be calling in a Ruby subprocess. It reads some text from STDIN and writes to both STDOUT and STDERR.

THIS_FILE and RUBY contain full paths for the demo source file and the the Ruby interpreter, respectively.

Method #6: Open3

The Open3 library defines a single method, Open3#popen3(). #popen3() behaves similarly to the Kernel#popen() method we encountered in part 2. If you remember from that article, one drawback to the #popen() method was that it did not give us a way to capture the child process’ STDERR stream. "]Open3#popen3() addresses this deficiency.

Open3#popen3() is used very similarly to Kernel#popen() (or Kernel#open() with a ‘|’ argument). The difference is that in addition to STDIN and STDOUT handles, popen3() yields a STDERR handle as well.

puts "6. Open3"
require 'open3'
include Open3
popen3(RUBY, '-r', THIS_FILE, '-e', 'hello("Open3", true)') do
  |stdin, stdout, stderr|
  stdin.write("hello from parent")
  stdin.close_write
  stdout.read.split("\n").each do |line|
    puts "[parent] stdout: #{line}"
  end
  stderr.read.split("\n").each do |line|
    puts "[parent] stderr: #{line}"
  end
end
puts "---"

When we execute this code, the result shows that we have captured the subprocess’ STDERR output:

6. Open3
[parent] stdout: [child] Hello from Open3
[parent] stdout: [child] Standard input contains: "hello from parent"
[parent] stdout: [child] DONE
[parent] stderr: [child] Hello, standard error
---

Method #7: PTY

All of the methods we have considered up to this point have shared a common limitation: they are not very well-suited to interfacing with highly interactive subprocesses. They work well for “filter”-style commands, which read some input, produce some output, and then exit. But when used with interactive subprocesses which wait for input, produce some output, and then wait for more input (etc.), their use can result in deadlocks. In a typical deadlock scenario, the expected output is never produced because input is still stuck in the input buffer, and the program hangs forever as a result. This is why, in previous examples, we have been careful to call #close_write on subprocess input handles before reading any output.

Ruby ships with a little-known and poorly-documented standard library called “pty”. The pty library is an interface to BSD pty devices. What is a pty device? In BSD-influenced UNIXen, such as Linux or OS X, a pty is a “pseudoterminal”. In other words, it’s a terminal device that isn’t attached to a physical terminal. If you’ve used a terminal program in Linux or OS X, you’ve probably used a pty without realizing it. GUI Terminal emulators, such as xterm, GNOME Terminal, and Terminal.app often use a pty device behind the scenes to communicate with the OS.

What does this mean for us? It means if we’re running Ruby on UNIX, we have the ability to start our subprocesses inside a virtual terminal. We can then read from and write to that terminal as if our program were a user sitting in front of a terminal, typing in commands and reading responses.

Here’s how it’s used:

puts "7. PTY"
require 'pty'
PTY.spawn(RUBY, '-r', THIS_FILE, '-e', 'hello("PTY", true)') do
  |output, input, pid|
  input.write("hello from parent\n")
  buffer = ""
  output.readpartial(1024, buffer) until buffer =~ /DONE/
  buffer.split("\n").each do |line|
    puts "[parent] output: #{line}"
  end
end
puts "---"

And here is the output:

7. PTY
[parent] output: [child] Hello from PTY
[parent] output: hello from parent
[parent] output: [child] Standard input contains: "hello from parent"
[parent] output: [child] Hello, standard error
[parent] output: [child] DONE
---

There are a few of points to note about this code. First, we don’t need to call #close_write or #flush on the process input handle. However, the newline at the end of “Hello from parent” is essential. By default, UNIX terminal devices buffer input until they see a newline. If we left off the newline, the subprocess would never finish waiting for input.

Second, because the subprocess is running asynchronously and independently from the parent process, we have no way of knowing exactly when it has finished reading input and producing output of its own. We deal with this by buffering output until we see a marker (“DONE”).

Third, you may notice that “hello from parent” appears twice in the output – once as part of the parent process output, and once as part of the child output. That’s because another default behaviour for UNIX terminals is to echo any input they receive back to the user. This is what enables you to see what you’ve just typed when working at the command line.

You can alter these default terminal device behaviours using the Ruby “termios” gem.

Note that both STDOUT and STDERR were captured in the subprocess output. From the perspective of the pty user, standard output and standard error streams are indistinguishable – it’s all just output. That means using pty is probably the only way to run a subprocess and capture standard error and standard output interleaved in the same way we would see if we ran the process manually from a terminal window. Depending on the application, this may be a feature or a drawback.

You can execute PTY.spawn() without a block, in which case it returns an array of output, input, and PID. If you choose to experiment with this style of calling PTY.spawn(), be aware that you may need to rescue the PTY::ChildExited exception, which is thrown whenever the child process finally exits.

If you’re interested in reading more code which uses the pty library, the Standard Library also includes a library called “expect.rb”. expect.rb is a basic Ruby reimplementation of the classic “expect” utility written using pty.

Method #8: Shell

More obscure even than the pty library is Ruby’s Shell library. Shell is, to my knowledge, totally undocumented and rarely used. Which is a shame, because it implements some interesting ideas.

Shell is an attempt to emulate a basic UNIX-style shell environment as an internal DSL within Ruby. Shell commands become Ruby methods, command-line flags become method parameters, and IO redirection is accomplished via Ruby operators.

Here’s an invocation of our standard example subprocess using Shell:

puts "8. Shell"
require 'shell'
Shell.def_system_command :ruby, RUBY
shell = Shell.new
input  = 'Hello from parent'
process = shell.transact do
  echo(input) | ruby('-r', THIS_FILE, '-e', 'hello("shell.rb", true)')
end
output = process.to_s
output.split("\n").each do |line|
  puts "[parent] output: #{line}"
end
puts "---"

And here is the output:

8. Shell
[child] Hello, standard error
[parent] output: [child] Hello from shell.rb
[parent] output: [child] Standard input contains: "Hello from parent"
[parent] output: [child] DONE
---

We start by defining the Ruby executable as a shell command by calling Shell.def_system_command. Then we instantiate a new Shell object. We construct the subprocess within a Shell#transact block. To have the process read a string from the parent process, we set up a pipeline from the echo built-in command to the Ruby invocation. Finally, we ensure the process is finished and collect its output by calling #to_s on the transaction.

Note that the child process’ STDERR stream is shared with the parent, not captured as part of the process output.

There is a lot going on here, and it’s only a very basic example of Shell’s capabilities. The Shell library contains many Ruby-friendly reimplementations of common UNIX userspace commands, and a lot of machinery for coordinating pipelines of concurrent processes. If your interest is piqued I recommend reading over the Shell source code and experimenting within IRB. A word of caution, however: the Shell library isn’t maintained as far as I know, and I ran into a couple of outright bugs in the process of constructing the above example. It may not be suitable for use in production code.

Conclusion

In this article we’ve looked at three Ruby standard libraries for executing subprocesses. In the next and final article we’ll examine some publicly available Rubygems that provide even more powerful tools for starting, stopping, and interacting with subprocesses within Ruby.

Written by avdi

October 12, 2009 at 1:11 pm

Announcing Caliper

If you’re anything like us, you recognize the usefulness of code quality metrics. But configuring metrics tools and linking them to your Continuous Integration system is a chore you may not have found time for. Here at Devver we’re all about taking the pain out of common development chores. Which is why we’re pleased to announce a new Devver service: Caliper.

Caliper is the easy way to get code metrics – like cyclomatic complexity and code duplication – about your project. Just go to http://devver.net/caliper. Enter the public Git repository URL of a Ruby project. In a few moments, we’ll give you a full set of metrics, generated by the awesome metric_fu gem.

Try it out right here:

If your project is hosted on Github, we can even re-generate metrics automatically every time someone makes a commit. Just add the URL

http://api.devver.net/github

to your project’s Post-Receive Hooks.

Caliper is currently an Alpha product. We will be be rapidly adding features and refinements over the next few weeks. If you have a problem, a question, or a feature request, please let us know!

Written by avdi

October 9, 2009 at 8:44 am