Making well-behaved programs in Go with cybozu-go/cmd

Go Programming

We at kintone.com are using Go for variety of tasks.

In early days when we started using Go, there were only few in-house rules to create commands. As a result, we faced several difficulties:

  • Some servers did not record access logs.
  • Some programs did not record command execution logs.
  • No common spec to handle SIGINT or SIGTERM.
  • Some programs did not reopen log files, making log rotation difficult.
  • Inconsistent log formats.

It would have been better if they handled signals nicely and recorded logs consistently. More specifically, we think a command well-behaved if it:

  • Stops gracefully after all running jobs completed upon SIGINT/SIGTERM.
  • Restarts gracefully (or reloads configs) on SIGHUP.
  • Re-opens log files on a signal, say SIGUSR1.
  • Records logs in a consistent, machine-readable format.
  • Records accesses to HTTP servers.
  • Records results of command executions.
  • Provides an option to change verbosity level of logging.
  • Records logs with ID to track activities of a goroutine.

Looks good? The last item is difficult to understand for people who are not familiar with Go, so let me explain. Go runs jobs concurrently in so-called goroutines. Goroutines are not OS processes nor threads, and do not have identifiers of themselves. Hence we need to add our own ID.

To get straight to the point, such well-behaved commands can be created by using github.com/cybozu-go/cmd (hereinafter called cmd).

How cmd works

cmd is built around context package that appears new in Go 1.7. context is an excellent solution for problems like:

  • Stop processing on a signal or a timeout whichever comes first.
  • Propagate request-scope values between function calls.

By using context properly, we can implement graceful stop and ID for goroutines.

The first thing cmd provides is a kind of barrier synchronizer that can signal its goroutines to interrupt processing at any time. cmd.Environment is it whose Cancel(err error) method cancels the internal context to signal goroutines started by its Go(func(ctx context.Context) error) method.

import (
    "context"
    "github.com/cybozu-go/cmd"
    "github.com/cybozu-go/log"
)

func main() {
    env := cmd.NewEnvironment(context.Background())

    // Go calls a function inside a goroutine.
    // If the function returns non-nil error, Cancel(err)
    // is called automatically.
    env.Go(func(ctx context.Context) error {
        for {
            select {
            case <-ctx.Done():
                // gracefully stop when context is canceled.
                return nil
            default:
            }
            doSomething()
        }
    })

    // more Go() calls...
    //env.Go()...
    env.Stop()

    // wait for all goroutines to return.
    err := env.Wait()
    if err != nil {
        log.ErrorExit(err)
    }
}

cmd offers a global cmd.Environment and installs a signal handler that calls Cancel of the global environment when it gets SIGINT or SIGTERM. By depending on contexts inherited from the global environment, you can manage all essential goroutines in your programs to stop them gracefully.

Of course, cmd already provides such implementations for network servers. For instance, cmd.HTTPServer is a wrapper for the standard http.Server that adds graceful stop, access log, and unique request IDs.

func main() {
    // The only thing you need to do is to wrap http.Sever
    // inside cmd.HTTPServer.
    s := &cmd.HTTPServer{
        Server: &http.Server{
            Handler: http.FileServer(http.Dir("/path/to/files")),
        },
    }

    // ListenAndServe is overridden to return soon after started
    // a goroutine with Go().
    err := s.ListenAndServe()
    if err != nil {
        log.ErrorExit(err)
    }

    // Wait returns when SIGINT or SIGTERM is got and all ongoing
    // HTTP requests complete.
    err = cmd.Wait()

    // IsSignaled returns true if err comes from the signal handler.
    if err != nil && !cmd.IsSignaled(err) {
        log.ErrorExit(err)
    }
}

Please visit the tutorial to learn more about cmd. There are plenty more useful things. You can read about the tricks used in cmd.HTTPServer in another article.

How log works

We have not mention about logging. It is provided by another package github.com/cybozu-go/log (hereinafter called log).

log provides so-called structured logging in which a log consists of key-value pairs.

Users can add their own key-value pairs to make logs better explain the situation:

log.Error("message", map[string]interface{}{
    "field1": []int{1, 2, 3},
    "field2": time.Now(),
})

Structured logs are often recorded in machine-readable formats. log provides three formatters: syslog-like "plain", logfmt, and JSON Lines.

With cmd, programs automatically implement command-line flags to specify:

  • log filename,
  • verbosity level of logging, and
  • log format.

Commands built on cmd

We already adopted cmd for all our open source Go products:

Summary and conclusion

github.com/cybozu-go/cmd provides tools to make well-behaved Go programs. Well-behaved here means programs can stop/restart gracefully and record useful logs.

All our open-source products already using cmd successfully. You can try it out now.