Build Events and RSpec - First steps with Honeycomb.io

I’ve been a big theoretical fan of Honeycomb.io for a long time now. The technology seems both timely and needed. The employees are prominent in our field and the people that start using it seem to very quickly become convinced of its worth. What’s made it theoretical for me is that I’ve just not had a reason to actually delve into it and have a play around. Or I hadn’t until I saw Observability in the SSC: Seeing Into Your Build System. Rather than focusing on another Spirograph micro service architecture this talk, which is well worth the time, presented a build system as the use case. And it was very convincing.

I use a number of SaaS providers to run unit tests and linters over the pull requests made to my GitHub repositories, so I decided to try and add buildevents and get some timing information out. buildevents is a small Golang binary you invoke in each job and at every step of your build process to capture what’s happening, a chunk of metadata and how long it’s taken. I scattered its calls around my TravisCI config file and once it runs it produces some quite pretty results.

Waterfall trace of a build job

The code to add buildevents to a .travis.yml file looks a little heavy but that’s mostly because my job itself is quite short.

---
env:
  global:
    - BUILD_START=$(date +%s)
    - PUPPET_GEM_VERSION="~> 6.16.0"

install:
  - STEP_START=$(date +%s)
  - STEP_SPAN_ID=$(echo install | sum | cut -f 1 -d \ )
  - curl -L -o buildevents https://github.com/honeycombio/buildevents/releases/download/v0.4.10/buildevents-linux-amd64
  - chmod 755 buildevents
  - ./buildevents step $TRAVIS_BUILD_ID $STEP_SPAN_ID $STEP_START install

language: ruby
rvm:
  - 2.5.0
bundler_args: --without development

script:
  - STEP_START=$(date +%s)
  - STEP_SPAN_ID=$(echo script | sum | cut -f 1 -d \ )
  - ./buildevents cmd $TRAVIS_BUILD_ID $STEP_SPAN_ID install-gems -- bundle install
  # the actual test step
  - ./buildevents cmd $TRAVIS_BUILD_ID $STEP_SPAN_ID spec-tests -- bundle exec rake spec SPEC_OPTS='--format documentation'
  - ./buildevents step $TRAVIS_BUILD_ID $STEP_SPAN_ID $STEP_START script

notifications:
  email: dean.wilson@gmail.com

after_failure:
  - ./buildevents build $TRAVIS_BUILD_ID $BUILD_START failure

after_success:
  - ./buildevents build $TRAVIS_BUILD_ID $BUILD_START success

The additional steps are pretty straight forward and once you’ve added your API key to the TravisCI web console a simple push to the repo and you’ll be able to start finding bottlenecks. I mentioned how much fun I was having with this on Twitter and David Schmitt kindly pointed me towards the RSpec Honeycomb Formatter that sends results and timings from your rspec test suites. The RSpec Honeycomb Formatter pull request was even shorter than buildevents. Adding a gem, the configuration to enable it and setting a few environment variables was all I needed to get my test runs into Honeycomb too.

Waterfall trace of an rspec run

It’s essentially day one for me using Honeycomb.io, and even then I’m only using it with my side projects. I can already see how the benefits stack up once you start using it, linking the rspec spans with the build system spans for example. The user interface is going to take a little getting used but I think if you’re looking for a starting point to learn this kind of tool before you end up all in with magnitudes of micro services then a build system is a good place to start and once that will hopefully show how you can start to save developer time and speed up your releases. And that’s very promising.