adrift on a cosmic ocean

Writings on various topics (mostly technical) from Oliver Hookins and Angela Collins. We have lived in Berlin since 2009, have two kids, and have far too little time to really justify having a blog.

Making a 'complete' service

Posted by Oliver on the 18th of November, 2011 in category Tech
Tagged with: initloggingmonitoringrackrubysinatrathin

One of the things that is pushed here a lot is the necessity to make all new applications really production-ready before being deployed as a service. There is of course the adage "If it's not monitored, it doesn't exist" but beyond that there are a lot of other little fiddly details just to make something run. I'm talking about things like init scripts, logging etc.

It's very easy to get wrapped up writing code for some new idea you have or perhaps extending some existing codebase, and with most frameworks it is relatively easy to run your app from a terminal on your local workstation. What changes when you want to take it to a real server is generally (and I'm limiting this post to these topics):

  • packaging
  • service lifetime management
  • monitoring
  • logging

This is not an exhaustive list. When making these additions to my Sinagios app I felt more pain than expected, and suddenly it made sense why we tend to see a lot of applications that fall down so much in these areas - it's really boring and stupid work. Seriously. It's not fun, and so much of it could be automated away but sadly we don't live in that kind of a world.

Packaging is largely a non-issue thanks to such tools as FPM (although it has some minor issues still), and it is all too simple to add some basic monitoring to a Sinatra app:

# Health check for monitoring systems
get '/v1/health/?' do
  # Just try to verify the command and status files look ok, rescue the
  # exception and allow the message to propagate to the output with a
  # reasonable error code.
    nagios =
  rescue Exception => detail
    body detail.message
    status 500
    body 'OK'
    status 200

The next pain point was generating the init script. I'd really like to see a somewhat more specific framework than the one currently in place - shell script is ubiquitous but sometimes it is just annoying. Sadly most apps still don't fit into the generic functions available in /etc/init.d/functions and I found it took an hour or so to craft the file just right to get my app launching nicely with rackup. There should be some convention over placement and naming of entities like PID files, process names, what to do with standard in/out/error, run users, log/run/work directories etc etc. It could be so much easier, but it's a problem for smarter people than I.

Finally I hit logging and this was a really irritating one, not least because the Rubyforge website was down all day and I couldn't get to the documentation. In daemon mode, rackup will still output errors to STDERR so you have the option of either redirecting that at invocation time or in the file (and possibly later as well, I didn't bother to try). Standard output (which in interactive mode will accept the access logging) ceases to offer anything useful as Rack wraps up logging in its CommonLogger class.

There are a multitude of different ways to skin this cat but the simplest seems to be telling Rack (through Sinatra) which logging "middleware" to use, in our case just a simple instance of Logger (effectively just appending to a file, but it can also add timestamps, priorities, and take care of rotation). Sadly the basic example fails still:

logger ='/var/log/sinagios/access.log')
use Rack::CommonLogger, logger

This leads to:

!! Unexpected error while processing request: undefined method `write' for #<Logger:0x7f6f28d033d0>

But only if you are running non-daemonized!

That's right - if you add this code to your app it will just break it and not leave a trace in any logs anywhere. You will have to run it interactively again to figure out the problem, although fortunately it is staring us right in the face. Rack::CommonLogger expects the logger interface to support the write method, which Logger does not at the moment. Let's just alias it to the append operator:

Logger.class_eval { alias :write :'<<' }

This will have Logger just append the log entries without any additional formatting or timestamps as Rack::CommonLogger already adds these for us. I also added logrotate fragments to ensure the logs don't consume the entire disk (although connecting to Scribe would have been better, but is a project for another day). This work has been somewhat enlightening but not exactly thrilling - I can see why it is such a chore for developers and frequently left out altogether. Now it is done though, I can at least reuse it but it would be nice to see some better system frameworks for these common and boring tasks for getting the real stuff running in production.

© 2010-2018 Oliver Hookins and Angela Collins