Back in 2010, Nurullah Akkaya published his implementation of John McCarthy’s “Micro-manual for Lisp” paper. I thought it might be interesting to port this implementation into Go as a learning exercise. This is my first non-hello-world Go program, so inevitably there’ll be a fair bit of non-idiomatic code here. Bear with me; I’ll update it at some point in the future when I’ve got more Go under my belt.

I won’t go into too much detail; the full source is here.

Interfaces

The interesting part of this for me was being able to replace the idiomatic but, to me, ungainly enum-tagged structs and object * references with Go’s interfaces to be able to take advantage of Go’s more powerful type system.

Here’s the common interface for all the moving parts of my lisp:

1
2
3

type Object interface {
  String() string
}

The contents of the interface aren’t really important - I’m really using this to convince the type system that I know what I’m doing. I’m defining the String() function to make print() work, mainly so that I can just drop my Objects into fmt.Print* and have it Just Work. I did consider adding a function to print to a stream, but I don’t need that yet.

The four basic object types - atoms, cons cells, functions and lambdas - are implemented in the obvious way:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15

type AtomObject struct {
  name string
}

type ConsObject struct {
  car, cdr Object
}

type FuncObject struct {
  fn ObjFunc
}

type LambdaObject struct {
  args, sexp Object
}

ObjFunc, needed by FuncObject, will be our basic “callable” function type, taking two Objects and returning an Object:

1

type ObjFunc (func (Object, Object) Object)

LambdaObjects and FuncObjects both also implement the Evaler interface, which simplifies the implementation of eval() slightly:

1
2
3

type Evaler interface {
  Eval( sexp, env Object ) Object
}

Strings

One other major difference between Go and C is in string handling. Go’s creators have obviously learnt a lot about how to fix C’s shortcomings in that area. You can see this at work in my next_token() function:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36

func next_token( in io.RuneScanner ) Object {
  ch,_,err := in.ReadRune()

  for unicode.IsSpace( ch ) && err == nil {
      ch, _, err = in.ReadRune()
  }
  if err == io.EOF {
      os.Exit(0)
  }

  chstr := string( ch )

  if chstr == ")" {
      return atom(")")
  } else if chstr == "(" {
      return atom("(")
  }

  buffer := make( []rune, 128 )
  var i int

  for i = 0; !unicode.IsSpace(ch) && chstr != ")"; i++ {
      buffer[i] = ch
      ch,_,_ = in.ReadRune()
      chstr = string( ch )
  }

  if chstr == ")" {
      in.UnreadRune()
  }
  
  // The slice here is essential: go strings aren't null
  // terminated, so the full 128-rune length would be returned
  // if we didn't slice it.  This breaks string comparison.
  return atom( string( buffer[0:i] ) )
}

Everything here is done in terms of the rune type, which is completely distinct from the byte[] type, has different reader and writer functions, and is generally geared up for unicode input in a way that would have been more cumbersome - and crucially, easier to get wrong - in the original. Also note the gotcha in the comment at the end: if you don’t manage your string lengths explicitly, string comparisons break. I can understand why this was done, but it caught me completely off-guard and I spent a good couple of hours trying to find a mistake I’d made elsewhere.

Finished?

Obviously not. I think this was an excellent introduction to Go, and I’ll certainly be keeping an eye on the ecosystem to see how it evolves. I can certainly see Go becoming a tool in my daily toolbelt. My experience with the toolchain in getting this to work has been nothing but pleasant.

I’m going to keep working on this interpreter as well. There are many, many directions it could go in, but only so many hours in the day. Most importantly, if you’re reading this and you can see anything I can do to improve this code, have at it. Post a gist, and let me know.

Over the past few months, I’ve been thinking about when it might be correct to say rescue Exception instead of rescue StandardError, or a more specific exception class. This line of thought was first triggered by a particularly hairy debug session which was made extremely difficult because, unbeknownst to me, some library code did a rescue Exception at the top-level of a Thread, where I was expecting Thread.abort_on_exception to explicitly break and tell me what was happening. The actual exception class was a SystemStackError, being triggered by a faulty recursive method. The above experience lead me to the axiom: Never Rescue Exception.

This highlights the problem with a vanilla rescue Exception: it’s way too broad. For writing day-to-day code, it’s very unlikely that you want to rescue the Exception subclasses which are not StandardErrors.

Since then, putting a couple more projects into production has made me think harder about this particular piece of dogma, and I’ve refined it somewhat:

1. If you are writing a library, Never Rescue Exception.
2. If you are writing an application (that is, your code is responsible for the top-level process), then Rescue Exception At Most Once.

If you write rescue Exception, here’s what you are claiming about your rescue clause:

• You can handle running out of memory. (NoMemoryError)
• You can handle misconfiguration of $LOAD_PATH. (LoadError)
• Syntax errors don’t matter. (more ScriptError)
• You’re responsible for low-level signal handling. (SignalException)
• You control shutting down the process (SystemExit)
• …and yes, you know what to do when any rogue method blows the stack. (SystemStackError)

Any time you actually need to handle any of these situations, you’ll definitely know about it, and in most cases all you will want to do is log an error somehow and exit(1).

There’s only one situation I can think of where it’s reasonable for a library to handle any of these, and that’s where that library is responsible for laoding plugin code. If you want to evaluate that code in the main interpreter (and that’s not unreasonable), then you definitely want to isolate the rest of the application from misbehaving plugins so that you can track down the problem more easily. However, in that case the correct exception to be rescuing is ScriptError, not Exception, so the rule still applies.

Avdi Grimm has a post on using a shortcut ec script for emacsclient here. I used something like that for a few months, but got quickly frustrated with one peculiar quirk of my development setup.

I do the vast majority of my development in ruby, in a terminal window, and almost all of it is TDD using minitest/unit. Now, when I get a test failure, it looks something like this:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15

$ ruby -I. test_foo.rb 
Run options: --seed 41149

# Running tests:

F

Finished tests in 0.177699s, 5.6275 tests/s, 5.6275 assertions/s.

  1) Failure:
test_frobnication(TestFoo) [test_foo.rb:7]:
Expected: 23
  Actual: 42

1 tests, 1 assertions, 1 failures, 0 errors, 0 skips

The bit I’m most interested in is this line:

1

test_frobnication(TestFoo) [test_foo.rb:7]:

Specifically, if I want to take a look at the code around this failing assertion, this is the bit of information I want:

1

[test_foo.rb:7]

Now, I don’t know if it’s a quirk of my terminal or not, but when I double-click the filename, it selects the string test_foo.rb:7. The same sort of thing happens with exception backtraces, too. The workflow I want is: double-click the filename to copy, type “e c <space>”, middle-click to paste, hit enter. However, that pesky :7 screws everything up. It’s not part of the filename, so I’ve got to edit it out of the command before telling emacsclient to do its thing. This breaks the flow, because I actually have to think in the middle of the sequence.

Doing that also throws away useful information. What if, instead of just opening the file, I could have emacs navigate to the line as well? That would save me two manual operations and save me a little bit of mental effort.

Fortunately, emacsclient doesn’t just open files, it can also remotely run arbitrary elisp expressions. By a bit of trial and error, I found this set of calls would make emacs do what I want, given a separated filename filename and line number linenum:

1
2
3

(let ((buf (find-file filename)))
  (goto-line linenum buf)
  (select-frame-set-input-focus (window-frame (get-buffer-window buf))))

The only question then is, how best to pass this to emacs? Given that I was learning Haskell when I first tackled this, I thought it would be a suitable challenge for my new-found monad-wrangling skills for my first attempt to be called ec.hs:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31

#!/usr/bin/env runhaskell

import System.Environment (getArgs)
import System.Cmd (rawSystem)

splitIdentifier :: String -> (String, String)
splitIdentifier str =
    let
        cbrk = break (== ':')
        (filename, rest) = cbrk str
        linenum = case rest of
                    ':':stmt -> fst $ cbrk stmt
                    otherwise -> "1"
    in
      (filename, linenum)

buildCommand :: (String, String) -> (String, [String])
buildCommand (filename, linenum) =
    ("emacsclient", ["-ne", lisp])
    where
      lisp = "(let ((buf (find-file \"" ++ filename ++ "\")))" ++
             "(goto-line " ++ linenum ++ " buf)" ++
             "(select-frame-set-input-focus (window-frame (get-buffer-window buf))))"


run (exe, args) = rawSystem exe args

main = do
     identifier:_ <- getArgs
     exitCode <- run $ buildCommand $ splitIdentifier identifier
     putStrLn ""

To say that I am unimpressed with the verbosity of this code would be an understatement. I’d be happy for this to be golfed into oblivion. Nevertheless, it works.

Here’s a ruby version of the same:

1
2
3
4
5
6
7
8
9
10
11

#!/usr/bin/env ruby

filename, linenum = *ARGV.shift.split(":")
fail "Filename required" unless filename
linenum ||= 1

system "emacsclient", "-ne", <<-LISP
(let ((buf (find-file "#{filename}")))
  (goto-line #{linenum} buf)
  (select-frame-set-input-focus (window-frame (get-buffer-window buf))))
LISP

Naturally there’s a problem with both of these: filenames can contain colon characters, and both of these scripts will break if they’re given filenames like that. I’m happy enough with that; I don’t think I’ve ever seen a colon in a directory name, and I’ve certainly never written a ruby file with a colon in its name either.

There is, of course, another way to achieve all this, and that’s to make emacs do as much of the work as possible. Stick these in your init.el:

1
2
3
4
5
6
7
8
9
10
11

(defun backtrace-find-file (filename linenum)
  (let ((buf (find-file filename)))
    (goto-line linenum buf)
    (select-frame-set-input-focus
      (window-frame (get-buffer-window buf)))))

(defun backtrace-visit (ref)
  (let* ((matches (split-string ref ":"))
   (filename (car matches))
   (linenum (string-to-number (or (cadr matches) "1"))))
    (backtrace-find-file filename linenum)))

Now all we have to do is have emacsclient call backtrace-visit with the correct argument:

1
2
3

#!/bin/bash

emacsclient -ne "(backtrace-visit \"${1}\")"

This is probably the simplest thing that could possibly work.

Oh, I didn’t write tests for that. It’s too hard to test.

Heard that before? I’ve made this argument myself in the past, but it’s only recently that I’ve figured out precisely why it’s a stupid argument.

On the surface, and in context, it can seem reasonable. The code in question is often either interacting with the OS via system calls, or is involved in multi-process coordination, os else involves fiddly thread interaction. These can all be notoriously tricky to get right, and are often just hacked into shape until they “work”.

Nothing I’ve just said justifies not writing unit tests. Quite the reverse.

One of the benefits which proponents of TDD claim is that the code you end up with is less coupled, more clearly factored, and in general easier to understand than otherwise. In general, I’ve found this to be broadly true. I think this happens because TDD guides you towards teasing the problem apart into simple parts which are individually easy to reason about.

With this in mind, it’s clear that an argument for skipping tests when the interactions are complex is an argument to make code which is difficult to get right harder to understand. This does not strike me as a sane rationale.

If you look back at the situations where this argument raises its head, you’ll note that they all involve at least two separate issues: firstly discovering the state of “the system” (where the “system” is either the OS, a bundle of processes, or a bundle of threads), and secondly applying application logic to decide how to change that state. All the cases I’ve seen which provoke the “it’s too hard” response have, to borrow an expression from Rich Hickey, complected the interactions with the system with the decision logic behind the interactions.

Time for an example. In this code, which roughly paraphrases some production code I refactored recently, we’re connecting to a remote host with an SSH master socket, then giving the user a console over that socket. We need to do this so that we can distinguish between a failure to connect to the remote host causing a time-out, and the user successfully connecting and using the console.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46

class SshConsole

  def initialize( user, host )
    @user = user
    @host = host
  end


  def connect(timeout_time=Time.now+20)
    pid = fork{ exec "ssh -fMN -S/tmp/foo.sock #{@user}@#{@host}" }

    until Time.now > timeout_time
      done_pid, status = Process.waitpid2( pid, Process::WNOHANG )
      unless done_pid
        sleep 1
        next
      end

      # Still here? Then we're done, find out what happened

      # Return if the master socket process was killed:
      return false if status && !status.exited?
      # Return if there was a problem setting up the master socket
      return false unless status && status.exitstatus == 0

      # Still here? Then the master socket setup worked.
      begin
        # Launch the ssh console
        system "ssh -S/tmp/foo.sock #{@user}@{@host}"
      ensure
        # Kill the master socket when we're done
        system "ssh -NOexit -S/tmp/foo.sock #{@user}@#{@host}"
      end
      return true
    end

    # If we fall through to here, the master socket process failed to
    # connect before timeout_time.

    Process.kill("TERM", pid)
    Process.waitpid2( pid )
    return false
  end


end

Hopefully you can see how this is not code that would be simple to unit test. We have a fair amount of system interaction which would necessitate either a lot of messy, fragile mocking, or actual forking of SSH processes and faking of network failures to ensure coverage. Neither of these is ideal, and the reason this is hard is because the code above mixes up discovering the state of the system with acting on that state. I rewrote it to look like this:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74

class SshMasterProcess
  def initialize( user, host )
    @user = user
    @host = host
    @pid = nil
    @status=nil
  end

  def launch
    @pid = fork{ exec "ssh -fMN -S#{socket} #{@user}@#{@host}" }
  end

  def quit
    system "ssh -NOexit -S#{socket} #{@user}@#{@host}"
  end

  def finished?
    waited_pid, @status = Process.waitpid2( pid, Process::WNOHANG )
    !!waited_pid
  end

  def killed?
    @status && !@status.exited?
  end

  def succeeded?
    @status && @status.exitstatus == 0
  end

  def kill
    Process.kill(9, @pid)
    Process.waitpid2( @pid )
  end

  def socket
    "/tmp/foo.sock"
  end
end


class SshConsole

  def initialize( user, host, ps_builder=SshMasterProcess )
    @user = user
    @host = host
    @ps_builder = ps_builder
  end


  def connect( timeout_time = Time.now + 20 )
    master = @ps_builder.new( @user, @host )
    master.launch

    until Time.now > timeout_time
      unless master.finished?
        sleep 1
        next
      end

      return false if master.killed?
      return false unless master.succeeded?

      begin
        system "ssh -S#{master.socket} #{@user}@#{@host}"
      ensure
        master.quit
      end
      return true
    end

    master.kill
    return false
  end
end

In a way, this is a fairly typical refactoring: I’ve extracted behaviour into a class to enable dependency injection. The reason it’s interesting in this context is because I’ve isolated all the functionality related to identifying and modifying the state of the SSH master process away from the logic which drives that state. This means that the logic can be tested without going outside the test process. The structure of the logic hasn’t changed at all, but by adding a layer of indirection in the form of the SshMasterProcess class, the code has become simpler and much easier to test.

The take-away message from this is that when code looks hard to test, you should search for overlapping concerns, and keep an eye out for overlap between “system” state and modifications of that state.

Ruby’s Logger class, and the ruby logging ecosystem in general, has grown up with 5 standard log levels: FATAL, ERROR, WARN, INFO and DEBUG. There are no generally accepted guidelines for how these should be used, other than that those “high” on the list should be used in “more serious” situations than those lower down. This is not detailed enough for a useful policy. Better guidelines would mean that your logs would become more predictable and more useful.

I have been experimenting with a set of rules for using the different log levels over time which I think works well, and gives me confidence that logging at a given level will show only the information that I am actually interested in. Here’s what the different levels indicate:

• FATAL

  The process as a whole can no longer continue. Some fundamental assumption has been violated. We may want to keep track of what happens during the shutdown process, so it’s perfectly possible that the FATAL message is not the last message in the log. There’s no assumption that the next call after the log(:fatal, msg) call is an exit 1 or the like, but if you’re following the “fail early and hard” principle then it probably should be. Out of memory errors are a good example here.

• ERROR

  A single “request” or “operation” (however those terms are best defined in the context of the application) must terminate because something went wrong, or an assumption pertinent to the current operation has been violated in a way which can be contained. ERROR messages correspond roughly to exceptions in the classic sense: an unexpected event occurred which we cannot, or should not, handle within the main code body, and signal that while the process is safe, the current operation will be dropped on the floor. As with FATAL, this may not be the final log message generated by this operation.

• WARN

  The current operation has fallen off the happy path in an anticipated way, and we are guiding execution flow within the main body of the code to a failure response. An authentication failure, for instance, might be logged at WARN. The steps involved in handling that authentication failure, however, would not.

• INFO

  What we are doing, and, if relevant, to whom. INFO messages do not make distinction between whether we’re on a happy or sad code path. If they contain run-time data, it is only the minimum required to identify the entities involved in the operation. Since we expect to generate INFO-level messages frequently, they should be terse. An incoming HTTP request would be logged at INFO.

• DEBUG

  These describe how and why we are doing what we are doing. Like INFO, they do not make any distinction between whether we’re at an execution point corresponding to “good” or “bad” behaviour. On the assumption that INFO messages will also be present at the appropriate points, any run-time data which will be used in a conditional expression would be suitable for a DEBUG message.

You’ll note that INFO and DEBUG are closely related. This is not an accident: I’ll often have pairs of log commands looking like this:

1
2

log :info, "Reticulating splines"
log :debug, "Spline parameters: #{params.inspect}"

This set of rules means that I can set the log level to DEBUG for an execution trace, to INFO for a user activity log, and to WARN for a user problem log.

As a purely practical matter, I can’t envisage a situation where I’d raise the log level above WARN, and I’m unlikely ever to raise it above INFO unless I’m using separate appenders. ERROR and FATAL are most useful as locatable tags in a file with more context. That being said, if you don’t want to run your log gathering at a low level all the time, one option might be to dynamically alter the log level. You could lower the log level to INFO for the current operation when you hit a WARN situation, and lower it to DEBUG when you hit an ERROR or FATAL. I’ll be trying this on one project shortly and post when I’ve got a clear picture of how well this works.

The thought does occur to me that a hierarchy of levels isn’t the right way to represent what we try to do with logging, but that is a subject for a future post.

Octopress is a very fun little blogging platform. As you can see, it’s what I’m using here. It’s a static site generator with enough bells and whistles to keep me happy, but which doesn’t get in the way.

Anyway, that’s not the point. The point of this post was to demonstrate how I went about provisioning this server. It’s hard to imagine anything simpler.

First: I needed a server. I’ve been working on BigV, so it seemed appropriate to use a BigV vm as a host.

Here’s the top-to-bottom set of commands I used:

1
2
3
4
5
6

$ bigv group new blackkettle
$ bigv vm new diner.blackkettle \
  --vm-discs=25G \
  --vm-memory=1 \
  --vm-cores=1 \
  --vm-distribution=symbiosis

And that’s it. That gives me a machine with the hostname diner.blackkettle.alex.uk0.bigv.io, 25GiB of disc space, 1GiB of RAM and 1 core. Totally overkill for a static site, but the smallest it’s feasible to provision, and I’ve got a little headroom there if I want to get clever later.

Symbiosis is Bytemark’s Debian derivative which not only takes care of a lot of sensible defaults for web hosting, but also automates away boring configuration details by generating DNS and web server details based on directory names.

I connected to the VM’s serial console with bigv vm connect diner.blackkettle, logged in with the root password generated as part of the imaging process, created the folder /srv/blackkettle.org/public/htdocs, and put my public key in ~/.ssh/authorized_keys*.

At this point (given a following DNS wind), anything uploaded to that directory would be served at http://blackkettle.org/. Octopress needs the webroot to be set in its Rakefile. The relevant section for me looks like this:

1
2
3
4

ssh_user       = "admin@diner.blackkettle.org"
ssh_port       = "22"
document_root  = "/srv/blackkettle.org/public/htdocs"
deploy_default = "rsync"

Now, to publish the site in its as-before-you-seen-glory is to do:

1
2

$ rake generate
$ rake deploy

And that’s it. Request a VM, make a folder, upload content. Done.

* This shouldn’t have been necessary. The imaging process should have done this for me. It’s possible I have a bug to track down.

When writing a test, sometimes the only way to initially write the test is by duplicating the implementation code in the test to assert that the expected value is returned. This can happen for a number of reasons, but often arises because you are trying to test what is being performed, rather than how it’s being done, especially where the details of what’s being done are complicated and out of your control.

For a slightly contrived example, let’s say that you’re hashing a document to provide a checksum, and you want to check that a large file hashes correctly:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15

require 'test/unit'
require 'document'

class TestDocument < Test::Unit::TestCase
  def setup
    @file_content = File.read("test/fixtures/file-to-checksum.txt")
  end

  def test_large_file
    correct_checksum = Digest::SHA1.new.update(@file_content).digest
    doc = Document.new(@file_content)
    assert_not_nil doc.checksum
    assert_equal correct_checksum, doc.checksum
  end
end

Now, the implementation is almost trivial:

1
2
3
4
5
6
7
8
9
10
11

require 'digest/sha1'

class Document
  def initialize(content)
    @content = content
  end

  def checksum
    Digest::SHA1.new.update(content).digest
  end
end

This looks clumsy, and feels wrong when you write it, but it’s actually fine, and you shouldn’t worry about doing it.

It feels wrong because it seems that if you are simply duplicating the same code in two places, then you’re missing out on the benefit of a test: if you have the same code in two places, how can that possibly be a useful check on the correctness of that same code? It’s true, directly duplicated code like this doesn’t check that what it is doing is being done correctly. That’s not the only function of test code, though.

One of the functions of a good test suite is to give you confidence that a refactoring hasn’t broken anything. Tests which duplicate the implementation give you that confidence: you know that if you find a better implementation later, you can swap it in on the implementation side, and the test will tell you that you’ve done it correctly.

In our case, let’s say that for whatever reason, at some point in the future it makes sense to switch from Ruby’s Digest library to using OpenSSL directly. We can swap out the implementation code like so:

1
2
3
4
5
6
7
8
9
10
11

require 'digest/sha1'

class Document
  def initialize(content)
    @content = content
  end

  def checksum
    OpenSSL::Digest.digest("sha1", @content)
  end
end

The test still passes, so we know that our checksum is still valid.

In this specific case, rather than duplicate the code, I would probably choose to serialise the digest value in the test file. In general, though, the expected value you need to assert on won’t be easily serialisable, and this technique is particularly useful in those cases.

Tests aren’t just there to help you write correct code. They also help you keep code correct over time. As long as your duplicated-code test isn’t the only coverage of the relevant functionality, it’s not something to worry about in the first instance, and it certainly isn’t a reason to leave the test out.