Hacking Go Interfaces

Introduction

Usually, in programming, interfaces precede implementation. We know what we want the pieces of our architecture to be able to do, how they'll articulate, and we only start banging out code once we're sure about this. Interfaces make it possible to reason "from the outside in", deciding the behavior of larger parts, before we break down their inner workings.

But often, we're "hacking" our way "from the inside out", building some parts we know are essential first, and putting them together or wrapping them in bigger parts later. I think there's a way to show why and how to use interfaces in Go from the inside out.

What should we hack?

I decided to hack a (very naive) logging framework. The idea is: everyone has an idea of what a logging framework should do, and that's kind of like having an interface (conceptually). Plus, I don't need to introduce any specific concepts that could distract us from what we're building. Finally, a logging framework is typically the kind of stuff we start hacking, wrap into some other part, and come back to later when we need to improve it.

So, without any prior design, let's start banging out a logging framework in Go. I commited each chapter into a GitLab repository so you can follow the progress in the code base along with the chapters. Each chapters links to the commit at that point in the reading.

Version 1 – Standard output

My very first version of the package will just have one package-level function, Log, that will output messages to standard output, preceded by the time the message was logged. (Go has a pretty fun way to format time to a string, much easier than the old strftime.)

Package:

// Package ezlog is a naive log implementation
// used as experiment and tutorial in learning Go
package ezlog

import (
    "fmt"
    "time"
)

// Log logs a message to standard output preceded
// by the time the message was emitted
func Log(msg string) {
    now := time.Now()
    fmt.Printf("[%s] %s\n", now.Format("2006-01-02 03:04:05"), msg)
}

Example:

package main

import "gitlab.com/loderunner/ezlog"

func main() {
    ezlog.Log("Hello World!")
}

$ go run examples/hello.go
[2017-07-25 06:20:55] Hello World!

It's nothing fancy, but it works. We can start logging to standard output using this package now. But of course, it's not nearly enough.

Version 2 – File logging

The next thing we're going to log to is a file. We'll need the client of the package to give the path of a file to log to, before they start calling Log. What this tells us is that our package now needs a step of initialization, before it can be used. Let's add some code.

We add an Open function to the package that opens a file and sets it to a package variable, if successful.

var logfile *os.File

// Open opens a file to append to, creating
// it if it doesn't exist
func Open(path string) error {
    f, err := os.OpenFile(
        path,
        os.O_WRONLY|os.O_APPEND|os.O_CREATE,
        0644,
    )
    if f != nil {
        logfile = f
    }
    return err
}

We then log to the file inside the Log function.

func Log(msg string) {
    // Format the output string
    now := time.Now()
    output := fmt.Sprintf("[%s] %s", now.Format("2006-01-02 03:04:05"), msg)

    fmt.Println(output)           // Log to stdout
    fmt.Fprintln(logfile, output) // Log to a file
}

We extend the test program to add the file initialization.

func main() {
    ezlog.Open("hello.log")
    ezlog.Log("Hello World!")
}

When we run this program, we find a new file hello.log in the directory. It contains the same output as we saw in the console in the console.

$ go run examples/hello.go
[2017-07-25 09:22:21] Hello World!
$ cat hello.log
[2017-07-25 09:22:21] Hello World!

"We can log to standard output and to a file and we still don't need interfaces!" Well, yes. But we're starting to see the limits of our architecture. What if we need to log to two files? What if we don't want to log to standard output? What happens if we want to log to syslog or over the network? Plus, the code is starting to look a little ugly.

Version 3 – Loggers

Loggers

The answers to the above questions are not: add package-level variables, initialization functions, and make Log a monolithic function. We want this to be modular. What we need is an arbitrary number of "loggers" that can we can configure and give to the package to do the work. Let's write two structs two encapsulate the two behaviors. One for standard output, one for files.

Standard output logger:

// StdoutLogger logs messages to stdout
type StdoutLogger struct{}

// NewStdoutLogger StdoutLogger constructor
func NewStdoutLogger() *StdoutLogger {
    return &StdoutLogger{}
}

// Log logs the msg to stdout
func (l *StdoutLogger) Log(msg string) {
    fmt.Println(msg)
}

File logger:

// FileLogger logs messages to a file
type FileLogger struct {
    f *os.File
}

// NewFileLogger opens a file to append to and
// returns a FileLogger ready to write to the file
func NewFileLogger(path string) (*FileLogger, error) {
    f, err := os.OpenFile(
        path,
        os.O_WRONLY|os.O_APPEND|os.O_CREATE,
        0644,
    )
    if err != nil {
        return nil, err
    }
    return &FileLogger{f}, nil
}

// Log logs a message to the file
func (l *FileLogger) Log(msg string) {
    fmt.Fprintln(l.f, msg)
}

We've isolated the loggers, how do we put them together in the package?

var Stdout *StdoutLogger
var File *FileLogger

// ... omitted code here ...

    if Stdout != nil {
        Stdout.Log(output) // Log to stdout
    }
    if File != nil {
        File.Log(output) // Log to a file
    }

Now this just looks silly. What if we want more files? An array of FileLoggers? And still no solution for other logger types that scales elegantly.

The interface

It's easy to see that the main package's Log function just prepares the output, then calls Log on each of the loggers. But the static typing in Go prevents us from just resolving the calls at runtime. The compiler needs to be sure that whatever we're giving it, it knows how to Log.

"Whatever this is, I need it to Log", is exactly what interfaces do in Go. When you ask for an interface type as an argument to a function, what your code is telling the compiler is: "this function takes a pointer to something, I don't care what it is, as long as it has all the methods from the interface". When returning an interface type from a function, you're saying: "don't ask what this is, all you need to know is that it does this". You can imagine an interface as a contract or requirements that the underlying type needs to fulfil.

Here, both of our loggers implement a Log method, so we can say they have a common interface. Let's hack it up.

type Logger interface {
    Log(string)
}

That's it. By writing these lines, we just defined a Logger interface. No need to change anything to StdoutLogger and FileLogger. The compiler will check if they have the Log method to determine if they uphold the interface, without any indication from our part. Anyone coming from C++ or Java will know how cool this is. And if we ever extend the interface to add new methods, it will still break at compile-time if we try to use a non-conforming type, since it won't implement the new methods.

We can now start using Logger as a type.

var loggers []Logger

// AddLogger adds a logger to the list
func AddLogger(l Logger) {
    loggers = append(loggers, l)
}

// Log logs a message to standard output preceded
// by the time the message was emitted
func Log(msg string) {
    // Format the output string
    now := time.Now()
    output := fmt.Sprintf("[%s] %s", now.Format("2006-01-02 03:04:05"), msg)

    // Log to all loggers
    for _, l := range loggers {
        l.Log(output)
    }
}

And that's it. It just works. By creating an interface that declares one method, that both of our loggers conform to, we can elegantly bring this all together in a few lines of code.

Let's make a more complex example to see what we can do now.

func main() {
    // Log to stdout
    ezlog.AddLogger(ezlog.NewStdoutLogger())

    for now := range time.Tick(1 * time.Second) {
        // The seconds of the current time ends with 5
        if (now.Second() % 5) == 0 {
            // Add a new file to log to
            filename := fmt.Sprintf("gopher-%s.log", now.Format("030405"))
            fileLogger, err := ezlog.NewFileLogger(filename)
            if err == nil {
                ezlog.AddLogger(fileLogger)
            } else {
                ezlog.Log("Couldn't open new file.")
            }
        }

        ezlog.Log("Gopher!")
    }
}

This example dynamically adds loggers to a new file every 5 seconds. Here's how it works.

What next?

Well, there's a lot to do.

This framework is by no means concurrency-safe. If several goroutines call AddLogger at the same time, we'll end up with a data race to the loggers array and could end up losing data. Heck, it's not even concurrent itself! We could probably optimize it by using goroutines and channels for different types of loggers. We could even use Go's built-in buffered channels to implement cheap spooling of logs.

There are many more loggers we might want to implement. In fact, I've already hacked together a network and a syslog logger (which was actually a fun experience in itself that I'll talk about in another post).

Here is a list of a few features I still want to add:

• Leveled logs
• Log formatting
• Named loggers
• Concurrency & optimization
• ... Removing loggers (trickier than it seems)

In the end, this package is also a fun playground to learn Go on. I'll intend to keep fiddling with it for a while, just to see what I can do. Check out the repository to see how it's progressing. Feel free to comment, suggest ideas, or even contribute to the package.