Automatically Printing Rake (or other Ruby) Variables

The FakeItEasy rakefile contains a vars target (brainchild of Adam Ralph) that can be used to print out the local variables defined in the script. Mostly these are static variables, such as the path to the NUnit command, but some, such as the upcoming FakeItEasy version, are computed. Logging these computed variables can help debug misbehaving builds.

If ever something goes wrong, we can check the TeamCity build log and see something like this:

assembly_info:     Source/CommonAssemblyInfo.cs
mspec_command:     Source/packages/Machine.Specifications.0.8.0/tools/mspec-clr4.exe
nuget_command:     Source/packages/NuGet.CommandLine.2.8.0/tools/NuGet.exe
nunit_command:     Source/packages/NUnit.Runners.2.6.3/tools/nunit-console.exe
nuspec:            Source/FakeItEasy.nuspec
output_folder:     Build
repo:              FakeItEasy/FakeItEasy
solution:          Source/FakeItEasy.sln
version:           1.21.0


  * **Changed**: _<description>_ - _#<issue number>_
  * **New**: _<description>_ - _#<issue number>_
  * **Fixed**: _<description>_ - _#<issue number>_

  With special thanks for contributions to this release from:

  * _<user's actual name>_ - _@<github_userid>_

  **Ready** when all other issues forming part of the release are **Done**.

  - [ ] run code analysis in VS in *Release* mode and address violations (send a regular PR which must be merged before continuing)
  - [ ] check build, update draft release in [GitHub UI](
         including release notes, mentioning non-owner contributors, if any

Originally, the vars task was hand-written, so whenever we added a new variable we had to update the task. Not too long ago, I added a new variable, and (surprisingly) remembered to update vars. However, Adam noticed that I had put the puts statement in the task in the wrong place, so the declaration order didn't match the printed order. A small thing, but the small things matter.

So, we had a chat about the best way to present the variables. Declaration order is attractive, but I pushed a different approach: first, separating the variables with short values, such as assembly_info, from variables with long values, such as release_body. This keeps the short values from becoming lost in the noise of the longer ones. Second: sort lexicographically within the groups, to aid scanning.

We came to an agreement, but as I started to make the change, I thought, "Why make humans worry about this? Computers are good at partitioning and sorting." So, after a quick search for something that would allow printing of local Ruby variables, I found local_variables, and rewrote the task:

desc "Print all variables"
task :vars do
  print_vars( { |name| [name.to_s, (eval name.to_s)] })  

def print_vars(variables)

  scalars = []
  vectors = []

  variables.each { |name, value|
    if value.respond_to?('each')
      vectors << [name, { |v| v.to_s }]
      string_value = value.to_s
      lines = string_value.lines
      if lines.length > 1
        vectors << [name, lines]
        scalars << [name, string_value]

  scalar_name_column_width = { |s| s[0].length }.max
  scalars.each { |name, value| 
    puts "#{name}:#{' ' * (scalar_name_column_width - name.length)} #{value}"

  vectors.each { |name, value| 
    puts "#{name}:"
    puts {|v| "  " + v }
    puts ""

Points of interest:

  1. The task delegates to a function right away, to avoid creating new variables that would be found by local_variables.
  2. The first thing the method does is partition variables into "scalars", to be rendered on the same line as the variable name, and "vectors", which have multiple elements or lines, and are rendered below the variable name.
  3. As a bonus, the scalar variable names padded so the values can all land on a "tab stop"

Best of all, now we can add rake variables willy-nilly, with nary a thought about printing them out. It just happens.